Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

logp: add an in-memory logger #191

Merged
merged 2 commits into from
Apr 11, 2024
Merged

logp: add an in-memory logger #191

merged 2 commits into from
Apr 11, 2024

Conversation

AndersonQ
Copy link
Member

What does this PR do?

It adds an in memory logger to the logp package. It's migrating elastic/elastic-agent#4485 to here

Why is it important?

An in-memory logger is useful on other places besides the install/uninstall code of the elastic-agent

Checklist

  • My code follows the style guidelines of this project
  • I have commented my code, particularly in hard-to-understand areas
  • [ ] I have made corresponding changes to the documentation
  • [ ] I have made corresponding change to the default configuration files
  • [ ] I have added tests that prove my fix is effective or that my feature works
  • [ ] I have added an entry in ./changelog/fragments using the changelog tool
  • [ ] I have added an integration test or an E2E test

How to test this PR locally

  • run the added tests OR
  • use the logger

Related issues

  • N/A

Logs

Comparing the in-memory logger with the zap observer during the Elastic Agent installation process:

  • with the new in-memory logger:
root@elastic-agent:~# ./elastic-agent-8.14.0-SNAPSHOT-linux-x86_64/elastic-agent install -nf --url=https://REDACTED.elastic-cloud.com:443 --enrollment-token=Wrong_token
Installing in non-interactive mode.
[   =] Service Started  [1m41s] Elastic Agent successfully installed, starting enrollment.
[=== ] Waiting For Enroll...  [1m42s] {"log.level":"info","@timestamp":"2024-03-27T08:50:35.927+0100","log.origin":{"file.name":"cmd/enroll_cmd.go","file.line":530},"message":"Starting enrollment to URL: https://580c77ac20b347779aaa3c7a63a97827.fleet.us-west2.gcp.elastic-cloud.com:443/","ecs.version":"1.6.0"}
[=== ] Waiting For Enroll...  [1m42s] {"log.level":"info","@timestamp":"2024-03-27T08:50:36.804+0100","log.origin":{"file.name":"cmd/enroll_cmd.go","file.line":539},"message":"1st enrollment attempt failed, retrying for 10m0s, every 1m0s enrolling to URL: https://580c77ac20b347779aaa3c7a63a97827.fleet.us-west2.gcp.elastic-cloud.com:443/","ecs.version":"1.6.0"}
Error: fail to enroll: fail to execute request to fleet-server: status code: 401, fleet-server returned an error: ErrInvalidToken, message: token not valid utf8
For help, please see our troubleshooting guide at https://www.elastic.co/guide/en/fleet/8.14/fleet-troubleshooting.html
[ ===] Uninstalled  [1m44s] Error uninstalling. Printing logs
2024-03-27T07:48:58.882Z	DEBUG	[install]	Loaded configuration from /root/elastic-agent-8.14.0-SNAPSHOT-linux-x86_64/elastic-agent.yml
2024-03-27T07:48:58.882Z	DEBUG	[install]	Merged configuration from /root/elastic-agent-8.14.0-SNAPSHOT-linux-x86_64/elastic-agent.yml into result
2024-03-27T07:48:58.882Z	DEBUG	[install]	Merged all configuration files from [/root/elastic-agent-8.14.0-SNAPSHOT-linux-x86_64/elastic-agent.yml], no external input files
2024-03-27T07:48:58.882Z	DEBUG	[install.composable]	Starting controller for composable inputs
2024-03-27T07:48:58.882Z	DEBUG	[install.composable]	Started controller for composable inputs
2024-03-27T07:48:58.882Z	DEBUG	[install.composable]	Variable state changed for composable inputs; debounce started
2024-03-27T07:48:58.883Z	DEBUG	[install.composable]	Kubernetes leaderelection provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:48:58.883Z	DEBUG	[install.composable.providers.kubernetes]	Kubernetes provider for resource pod skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:48:58.883Z	DEBUG	[install.composable]	kubernetes_secrets provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:48:58.883Z	DEBUG	[install.composable.providers.kubernetes]	Kubernetes provider for resource node skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:48:58.894Z	DEBUG	[install.composable.providers.docker]	Start docker containers scanner
2024-03-27T07:48:58.894Z	DEBUG	[install.composable.providers.docker]	List containers
2024-03-27T07:48:58.895Z	DEBUG	[install.composable.providers.docker]	Fetching events since 2024-03-27 08:48:58.895535555 +0100 CET m=+5.211006626
2024-03-27T07:48:58.983Z	DEBUG	[install.composable]	Computing new variable state for composable inputs
2024-03-27T07:48:58.983Z	DEBUG	[install.composable.providers.docker]	Watcher stopped
2024-03-27T07:48:58.983Z	DEBUG	[install.composable]	Stopping controller for composable inputs
2024-03-27T07:48:59.084Z	DEBUG	[install.composable]	Stopped controller for composable inputs
2024-03-27T07:50:37.398Z	DEBUG	[install]	Loaded configuration from /root/elastic-agent-8.14.0-SNAPSHOT-linux-x86_64/elastic-agent.yml
2024-03-27T07:50:37.398Z	DEBUG	[install]	Merged configuration from /root/elastic-agent-8.14.0-SNAPSHOT-linux-x86_64/elastic-agent.yml into result
2024-03-27T07:50:37.398Z	DEBUG	[install]	Merged all configuration files from [/root/elastic-agent-8.14.0-SNAPSHOT-linux-x86_64/elastic-agent.yml], no external input files
2024-03-27T07:50:37.399Z	DEBUG	[install.composable]	Starting controller for composable inputs
2024-03-27T07:50:37.399Z	DEBUG	[install.composable]	Started controller for composable inputs
2024-03-27T07:50:37.399Z	DEBUG	[install.composable]	Variable state changed for composable inputs; debounce started
2024-03-27T07:50:37.399Z	DEBUG	[install.composable.providers.kubernetes]	Kubernetes provider for resource pod skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:50:37.399Z	DEBUG	[install.composable.providers.kubernetes]	Kubernetes provider for resource node skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:50:37.399Z	DEBUG	[install.composable]	kubernetes_secrets provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:50:37.399Z	DEBUG	[install.composable]	Kubernetes leaderelection provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable
2024-03-27T07:50:37.405Z	DEBUG	[install.composable.providers.docker]	Start docker containers scanner
2024-03-27T07:50:37.405Z	DEBUG	[install.composable.providers.docker]	List containers
2024-03-27T07:50:37.406Z	DEBUG	[install.composable.providers.docker]	Fetching events since 2024-03-27 08:50:37.406110265 +0100 CET m=+103.721581291
2024-03-27T07:50:37.499Z	DEBUG	[install.composable]	Computing new variable state for composable inputs
2024-03-27T07:50:37.499Z	DEBUG	[install.composable]	Stopping controller for composable inputs
2024-03-27T07:50:37.500Z	DEBUG	[install.composable.providers.docker]	Watcher stopped
2024-03-27T07:50:37.600Z	DEBUG	[install.composable]	Stopped controller for composable inputs
Error: enroll command failed for unknown reason: exit status 1
For help, please see our troubleshooting guide at https://www.elastic.co/guide/en/fleet/8.14/fleet-troubleshooting.html
  • the zap logger observer:
root@elastic-agent:~# ./elastic-agent-8.12.2-linux-x86_64/elastic-agent  install -nf --url=https://580c77ac20b347779aaa3c7a63a97827.fleet.us-west2.gcp.elastic-cloud.com:443 --enrollment-token=REpuaGZvNEI4MmY0LUJCZzFySnM6TjZ2TEQ0bUFRN2lJSmRZOXo4TXFyUQ
Installing in non-interactive mode.
[   =] Service Started  [35s] Elastic Agent successfully installed, starting enrollment.
[==  ] Waiting For Enroll...  [36s] {"log.level":"info","@timestamp":"2024-03-27T08:53:39.751+0100","log.origin":{"file.name":"cmd/enroll_cmd.go","file.line":496},"message":"Starting enrollment to URL: https://580c77ac20b347779aaa3c7a63a97827.fleet.us-west2.gcp.elastic-cloud.com:443/","ecs.version":"1.6.0"}
[=   ] Waiting For Enroll...  [37s] {"log.level":"info","@timestamp":"2024-03-27T08:53:40.719+0100","log.origin":{"file.name":"cmd/enroll_cmd.go","file.line":505},"message":"1st enrollment attempt failed, retrying for 10m0s, every 1m0s enrolling to URL: https://580c77ac20b347779aaa3c7a63a97827.fleet.us-west2.gcp.elastic-cloud.com:443/","ecs.version":"1.6.0"}
Error: fail to enroll: fail to execute request to fleet-server: status code: 401, fleet-server returned an error: ErrInvalidToken, message: token not valid utf8
For help, please see our troubleshooting guide at https://www.elastic.co/guide/en/fleet/8.12/fleet-troubleshooting.html
[  ==] Uninstalled  [38s] Error uninstalling.  Printing logs
{debug 2024-03-27 08:53:40.957116065 +0100 CET m=+37.882332759 processes Error fetching PID info for 2, skipping: FillPidMetrics: error getting metadata for pid 2: error fetching exe from pid 2: readlink /proc/2/exe: no such file or directory github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:173 }
{debug 2024-03-27 08:53:40.957325274 +0100 CET m=+37.882541968 processes Error fetching PID info for 3, skipping: FillPidMetrics: error getting metadata for pid 3: error fetching exe from pid 3: readlink /proc/3/exe: no such file or directory github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:173 }

[...]

{debug 2024-03-27 08:53:40.972595852 +0100 CET m=+37.897812550 processes Error fetching PID info for 5582, skipping: FillPidMetrics: error getting metadata for pid 5582: error fetching exe from pid 5582: readlink /proc/5582/exe: no such file or directory github.com/elastic/elastic-agent-system-metrics@v0.9.1/metric/system/process/process.go:173 }
{debug 2024-03-27 08:53:40.987384521 +0100 CET m=+37.912601225  Loaded configuration from /root/elastic-agent-8.12.2-linux-x86_64/elastic-agent.yml github.com/elastic/elastic-agent/internal/pkg/config/loader.go:45 }
{debug 2024-03-27 08:53:40.987410892 +0100 CET m=+37.912627599  Merged configuration from /root/elastic-agent-8.12.2-linux-x86_64/elastic-agent.yml into result github.com/elastic/elastic-agent/internal/pkg/config/loader.go:57 }
{debug 2024-03-27 08:53:40.987427958 +0100 CET m=+37.912644664  Merged all configuration files from [/root/elastic-agent-8.12.2-linux-x86_64/elastic-agent.yml], no external input files github.com/elastic/elastic-agent/internal/pkg/config/loader.go:64 }
{debug 2024-03-27 08:53:40.987673866 +0100 CET m=+37.912890565 composable Starting controller for composable inputs github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:112 }
{debug 2024-03-27 08:53:40.98769278 +0100 CET m=+37.912909486 composable Started controller for composable inputs github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:155 }
{debug 2024-03-27 08:53:40.987734369 +0100 CET m=+37.912951054 composable Variable state changed for composable inputs; debounce started github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:191 }
{debug 2024-03-27 08:53:40.988254504 +0100 CET m=+37.913471211 composable.providers.kubernetes Kubernetes provider for resource pod skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetes/kubernetes.go:106 }
{debug 2024-03-27 08:53:40.988215108 +0100 CET m=+37.913431809 composable Kubernetes_secrets provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetessecrets/kubernetes_secrets.go:97 }
{debug 2024-03-27 08:53:40.988262372 +0100 CET m=+37.913479079 composable Kubernetes leaderelection provider skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetesleaderelection/kubernetes_leaderelection.go:53 }
{debug 2024-03-27 08:53:40.988525229 +0100 CET m=+37.913741942 composable.providers.kubernetes Kubernetes provider for resource node skipped, unable to connect: unable to build kube config due to error: invalid configuration: no configuration has been provided, try setting KUBERNETES_MASTER environment variable github.com/elastic/elastic-agent/internal/pkg/composable/providers/kubernetes/kubernetes.go:106 }
{debug 2024-03-27 08:53:40.988535588 +0100 CET m=+37.913752286 docker Docker client will negotiate the API version on the first request. github.com/elastic/elastic-agent-autodiscover@v0.6.6/docker/client.go:49 }
{debug 2024-03-27 08:53:40.995681656 +0100 CET m=+37.920898362 composable.providers.docker Start docker containers scanner github.com/elastic/elastic-agent-autodiscover@v0.6.6/docker/watcher.go:213 }
{debug 2024-03-27 08:53:40.995697137 +0100 CET m=+37.920913838 composable.providers.docker List containers github.com/elastic/elastic-agent-autodiscover@v0.6.6/docker/watcher.go:375 }
{debug 2024-03-27 08:53:40.996064703 +0100 CET m=+37.921281423 composable.providers.docker Fetching events since 2024-03-27 08:53:40.996020388 +0100 CET m=+37.921237078 github.com/elastic/elastic-agent-autodiscover@v0.6.6/docker/watcher.go:266 }
{debug 2024-03-27 08:53:41.088208428 +0100 CET m=+38.013425144 composable Computing new variable state for composable inputs github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:207 }
{debug 2024-03-27 08:53:41.088364541 +0100 CET m=+38.013581227 composable Stopping controller for composable inputs github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:159 }
{debug 2024-03-27 08:53:41.088415264 +0100 CET m=+38.013631997 composable.providers.docker Watcher stopped github.com/elastic/elastic-agent-autodiscover@v0.6.6/docker/watcher.go:313 }
{debug 2024-03-27 08:53:41.188806021 +0100 CET m=+38.114022705 composable Stopped controller for composable inputs github.com/elastic/elastic-agent/internal/pkg/composable/controller.go:188 }
Error: enroll command failed for unknown reason: exit status 1
For help, please see our troubleshooting guide at https://www.elastic.co/guide/en/fleet/8.12/fleet-troubleshooting.html

Questions to ask yourself

  • How are we going to support this in production?
  • How are we going to measure its adoption?
  • How are we going to debug this?
  • What are the metrics I should take care of?
  • ...

@AndersonQ AndersonQ added enhancement New feature or request Team:Elastic-Agent Label for the Agent team labels Apr 2, 2024
@AndersonQ AndersonQ self-assigned this Apr 2, 2024
@AndersonQ AndersonQ requested a review from a team as a code owner April 2, 2024 06:04
@AndersonQ AndersonQ requested review from ycombinator, faec and leehinman and removed request for a team and faec April 2, 2024 06:04
@AndersonQ AndersonQ mentioned this pull request Apr 2, 2024
Merged
2 tasks
@pierrehilbert pierrehilbert requested review from faec and removed request for ycombinator April 2, 2024 06:38
leehinman
leehinman reviewed Apr 2, 2024
View reviewed changes
logp/logger.go
// logs.
// encCfg configures the log format, use logp.ConsoleEncoderConfig for console
// format, logp.JSONEncoderConfig for JSON or any other valid zapcore.EncoderConfig.
func NewInMemory(selector string, encCfg zapcore.EncoderConfig) (*Logger, *bytes.Buffer) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

question on returning the pointer to the bytes.Buffer. It looks like zap uses it as a WriteSyncer, which does have a Lock function to make it safe for concurrent use. If someone has the pointer to the underlying Buffer they could get around that. Also is it a problem if someone does something like Reset on the Buffer?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It looks like zap uses it as a WriteSyncer, which does have a Lock function to make it safe for concurrent use.

Almost, it's a bit confusing, it has a writerWrapper which just adds a no-op Sync() to an io.Writer and also the Lock function, this adds a lock to a WriteSyncer, the interface, making it goroutinesafe.

I added the lock so it's safe to be used anywhere and an improved the docs

@elasticmachine
Copy link
Collaborator

💚 Build Succeeded

History

cc @AndersonQ

@AndersonQ AndersonQ requested a review from leehinman April 3, 2024 12:00
@AndersonQ AndersonQ merged commit ccbaaef into elastic:main Apr 11, 2024
6 checks passed
@AndersonQ AndersonQ deleted the in-memory-logger branch April 11, 2024 15:06
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@leehinman leehinman leehinman approved these changes

@faec faec Awaiting requested review from faec

Assignees

@AndersonQ AndersonQ

Labels
enhancement New feature or request Team:Elastic-Agent Label for the Agent team
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
3 participants
@AndersonQ @elasticmachine @leehinman