[Chore][libbeat] Replace global logger with single logger instance

[khushijain21]

Proposed commit message

See https://github.com/elastic/ingest-dev/issues/5251

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.next.asciidoc or CHANGELOG-developer.next.asciidoc.

How to test this PR locally

Run this test in x-pack/filebeat/fbreceiver

go test -run ^TestMultipleReceivers$ ./x-pack/filebeat/fbreceiver -v

Related issues

• Part of https://github.com/elastic/ingest-dev/issues/5202
• For https://github.com/elastic/ingest-dev/issues/5251
• Relates [Chore] Add functions required for single logger instance elastic-agent-libs#297

Checklist

✅ libbeat Directories Checklist

• libbeat/cmd except link
• libbeat/asset
• libbeat/beat
• libbeat/ecs
• libbeat/generator
• libbeat/version
• libbeat/api
• libbeat/feature
• libbeat/ebpf
• libbeat/monitoring/report
• libbeat/instrumentation
• libbeat/idxmgmt

[mergify]

This pull request does not have a backport label.
If this is a bug or security fix, could you label this PR @khushijain21? 🙏.
For such, you'll need to label your PR with:

• The upcoming major version of the Elastic Stack
• The upcoming minor version of the Elastic Stack (if you're not pushing a breaking change)

To fixup this pull request, you need to add the backport labels for the needed
branches, such as:

• backport-8./d is the label to automatically backport to the 8./d branch. /d is the digit
• backport-active-all is the label that automatically backports to all active branches.
• backport-active-8 is the label that automatically backports to all active minor branches for the 8 major.
• backport-active-9 is the label that automatically backports to all active minor branches for the 9 major.

[elasticmachine]

Pinging @elastic/elastic-agent-data-plane (Team:Elastic-Agent-Data-Plane)

[rdner]

A few comments / questions. The changes look good so far.

[mauri870]

This PR needs backport labels, at least 8.x and 9.0. It should be straightforward to backport to all 8 releases as well.

[rdner]

@mauri870 I would not be so sure. This is only the first PR to address the global logger problem. If we continue to refactor the rest of the code base it might cause conflicts between branches and with this kind of refactoring it's rather backport all or nothing.

Having this backport would not bring any benefit to our users from my standpoint.

[mauri870]

Having this backport would not bring any benefit to our users from my standpoint.

Good point! I'm mainly concerned about the receivers having data races which will make them untrustworthy for use in current versions. If that is ok then I'm fine with no backports.

[rdner]

@mauri870 the receivers are still in development and not released. I would not worry about it.

[mauri870]

Thanks!

[leehinman]

I still see some references to logp.L and logp.Warn etc in libbeat.

examples:

conditions/conditions.go: logp.L().Named(logName).Debugf("New condition %v", condition)
conditions/range.go: logp.L().Named(logName).Warnf(err.Error())
conditions/equals.go: logger := logp.L().Named(logName)
conditions/matcher.go: logp.L().Named(logName).Debugf("unexpected type %T in %v condition as it accepts only strings; value=%#v", value, c.name, value)
publisher/pipeline/module.go: log = logp.L()
template/template.go: logp.L().Infof("remote instance is serverless, number_of_shards and max_docvalue_fields_search will be skipped in index template")
idxmgmt/lifecycle/es_client_handler.go: logp.L().Warnf("setup.dsl.data_stream_pattern is %s, but setup.template.name is %s; under serverless, non-default template and DSL pattern names should be the same. Additional updates & overwrites to this config will not work.", name, cfg.TemplateName)
idxmgmt/lifecycle/file_client_handler.go: logp.L().Infof("No lifecycle config has been explicitly enabled, defauling to ILM")
autodiscover/providers/kubernetes/config.go: logp.L().Warnf("can not set scope to node when using resource %s. resetting scope to cluster", c.Resource)
autodiscover/providers/kubernetes/config.go: logp.L().Warnf("can only set unique when scope is cluster")
statestore/backend/memlog/store.go: logp.Info("Finished loading transaction log file for '%v'. Active transaction id=%v", home, txid)
statestore/backend/memlog/store.go: logp.Warn("Incomplete or corrupted log file in %v. Continue with last known complete and consistent state. Reason: %v", home, err)

Pretty sure we have to address the ones in conditions, publisher, statestore, autodiscover (all used in filebeat/metricbeat). But I don't think we have to worry about idxmgmt right now.

[belimawr]

LGMT, but I agree with @leehinman there are still some instances that should be addressed.

[khushijain21]

I aimed to keep this PR short for easy review. There are many places that still need to be fixed - the follow up PR's will take care

[leehinman]

Do we have verification that "normal" beats logs are exactly the same before and after this commit?

[khushijain21]

Do we have verification that "normal" beats logs are exactly the same before and after this commit?

Only the existing tests that rely on log assertions. That should do I believe

[kruskall]

Is there any plan to backport this to 8.x ?

[leehinman]

Do we have verification that "normal" beats logs are exactly the same before and after this commit?

Only the existing tests that rely on log assertions. That should do I believe

Being paranoid, I ran an experiment and I am seeing differences.

Before:

{"ecs.version":"1.6.0","log.level":"debug","log.logger":"beat","log.origin":{"file.line":1204,"file.name":"instance/beat.go","function":"github.com/elastic/beats/v7/libbeat/cmd/instance.(*Beat).loadMeta"},"message":"Beat metadata path: /Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64/data/meta.json","service.name":"filebeat"}

After:

{"ecs.version":"1.6.0","log.level":"debug","log.origin":{"file.line":1210,"file.name":"instance/beat.go","function":"github.com/elastic/beats/v7/libbeat/cmd/instance.(*Beat).loadMeta"},"message":"beat%!(EXTRA string=Beat metadata path: %v, string=/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64/data/meta.json)","service.name":"filebeat"}

notice "EXTRA string" part

Also, it looks like the level changed on this one from warn to info?:

before:

{"ecs.version":"1.6.0","log.level":"warn","log.origin":{"file.line":1103,"file.name":"instance/beat.go","function":"github.com/elastic/beats/v7/libbeat/cmd/instance.(*Beat).configure"},"message":"unable to lookup FQDN: could not get FQDN, all methods failed: failed looking up CNAME: lookup elastic2 on 172.16.1.1:53: no such host: failed looking up IP: lookup elastic2: no such host, using hostname = elastic2 as FQDN","service.name":"filebeat"}

after:

{"ecs.version":"1.6.0","log.level":"info","log.origin":{"file.line":1109,"file.name":"instance/beat.go","function":"github.com/elastic/beats/v7/libbeat/cmd/instance.(*Beat).configure"},"message":"unable to lookup FQDN: could not get FQDN, all methods failed: failed looking up CNAME: lookup elastic2 on 172.16.1.1:53: no such host: failed looking up IP: lookup elastic2: no such host, using hostname = elastic2 as FQDN","service.name":"filebeat"}

This one had a 'log.logger' field before the change:

before:

{"log.level":"info","log.logger":"beat","log.origin":{"file.line":1641,"file.name":"instance/beat.go","function":"github.com/elastic/beats/v7/libbeat/cmd/instance.(*Beat).logSystemInfo"},"message":"Beat info","service.name":"filebeat","system_info":{"beat":{"path":{"config":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64","data":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64/data","home":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64","logs":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64/logs"},"type":"filebeat","uuid":"e2f4757e-534d-416e-9955-657c1ff394a8"},"ecs.version":"1.6.0"}}

after:

{"log.level":"info","log.origin":{"file.line":1648,"file.name":"instance/beat.go","function":"github.com/elastic/beats/v7/libbeat/cmd/instance.(*Beat).logSystemInfo"},"message":"Beat info","service.name":"filebeat","system_info":{"beat":{"path":{"config":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64","data":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64/data","home":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64","logs":"/Users/hinman/tmp/filebeat-9.1.0-darwin-aarch64/logs"},"type":"filebeat","uuid":"e3121ca4-99d2-4272-a45a-cd6477943eb3"},"ecs.version":"1.6.0"}}

There may be others, this is just what I spotted with a minimal filebeat config. @khushijain21 can you open up an issue to fix these and develop a method for comparing the logs before and after. What I did was very crude, have filebeat ingest a file, then use jq to remove the @timestamp from the logs as well as sort the keys. That allowed for a diff, but it wasn't very clean and could be improved.