Make logging levels compliant to APM spec

[jlvoiseux]

Motivation / Summary

This PR aims to resolve #170. The spec'd log level are now mapped on the default Logrus levels. This PR is still in draft, as I need to figure out a way to replace the fatal log level by critical in the output logs.

Right now ELASTIC_APM_LOG_LEVEL=critical is supported but will map to fatal, which will result in outputs such as the one shown below:

{"@timestamp":"2022-04-01T12:22:43.425+0200","ecs.version":"1.6.0","event.dataset":"apm-lambda-extension","log.level":"fatal","message":"Could not wait for the execution of make : exit status 2"}

That is not ideal in terms of UX: a user who sets the log level to critical might want to see "log.level":"critical" for the relevant logs. This PR is in draft while I figure out a way to implement the aforementioned behavior.

[ghost]

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

• Start Time: 2022-04-13T10:29:09.558+0000

• Duration: 8 min 45 sec

Test stats 🧪

Test	Results
Failed	0
Passed	184
Skipped	4
Total	188

🤖 GitHub comments

To re-run your PR in the CI, just comment with:

• /test : Re-trigger the build.

• run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

[jlvoiseux]

Custom Zap-based Level Logger

The technical possibilities to modify the log.level field value without defining our own level system being inexistent, I decided to implement a new logger based on zap (the other Go logger for which an ECS formatter is available). Zap has the following advantages :

• It is actively maintained, whereas Logrus is in maintenance mode
• It is faster than Logrus
• It made the implementation of this PR straightforward by offering a large set of configuration options.

Changes

• The logger is now wrapped in a struct containing its level and its config
• Functions corresponding to the APM Log Levels (Trace(), Debug(), Info(), Warn(), Error(), Critical()) are mapped with Zap levels as shown below:

Zap Levels              APM Levels
DebugLevel              trace, debug
InfoLevel               info
WarnLevel               warn(ing)
ErrorLevel              error
DPanicLevel             /
PanicLevel              /
FatalLevel              critical

• An Off level was implemented.

[axw]

The technical possibilities to modify the log.level field value without defining our own level system being inexistent

I may be mistaken, but I don't think this is necessary. Are you aware of a spec that requires that log.level match the values specified in ELASTIC_APM_LOG_LEVEL? My understanding is that ELASTIC_APM_LOG_LEVEL is only for configuration, and the log.level field should continue to be native to whatever logger is used.

With that in mind, can we simplify this PR a bit? Can we just translate ELASTIC_APM_LOG_LEVEL to zapcore.Level, and then use zap with ecszap directly, without wrapping it?

[jlvoiseux]

@axw Thanks for taking a look! I believe that the reasoning behind having the same values for ELASTIC_APM_LOG_LEVEL across the extension and the agent is that the env variable actually affects both the agent and the extension (ie with a Node Lambda function, we will see also debug logs from the Node agent if ELASTIC_APM_LOG_LEVEL=debug is set) hence the incentive to follow the spec.

However I agree with you, the PR could be simplified by a lot if we decide that this incentive is not worth having a 1:1 mapping.

[axw]

@jlvoiseux ELASTIC_APM_LOG_LEVEL should accept the same values regardless of agent. What I meant is that I don't think we need the additional extension.LevelLogger type, or to explicitly set log.level.

If we use zap directly, and configure it with ecszap and the level parsed from ELASTIC_APM_LOG_LEVEL and translated to Zap's levels, then log.level will be added to log records. They won't match what is defined in ELASTIC_APM_LOG_LEVEL; they will use the native Zap levels.

[jlvoiseux]

@axw I have implemented your recommendations. Zap is now used natively. The mapping is now as follows:

Zap Levels              APM Levels
DebugLevel              trace, debug
InfoLevel               info
WarnLevel               warn(ing)
ErrorLevel              error
DPanicLevel             /
PanicLevel              critical
FatalLevel              off

Mapping off to FatalLevel simplifies the code a lot, but that is an arbitrary choice. What do you think?

[axw]

Thanks for the changes, it looks a lot more straightforward to me now.

The mapping looks good except for critical and off - I think off should really mean off.

[axw]

LGTM, thanks for the changes!