Introduce SLF4J for logging #3285

diega · 2022-01-16T23:07:07Z

PR description

Given the latest events regarding Log4J2 security issues and the advent of Besu modularization, it would be interesting to introduce an abstraction layer for logging so we don't force any implementation for future adopters.

This PR replaces every org.apache.logging.log4j.Logger instance with its analog org.slf4j.Logger but still respects every hard dependency on Log4J2 (now more easily identifiable). Also, a new helper was introduced to deal with situations where a org.apache.logging.log4j.core.LoggerContext was created outside the scope of SLF4J.

This is quite large to review so I kept different commits for the different decisions being made

4d7d1e4: just adds the slf4j API
909a195: this is the biggest one. 90% of it is just replacing the Logger instances, but there are also some other minor changes for respecting the same behavior of Log4J2 in SLF4j, e.g. wrap in an if (LOG.isXxxxEnabled) values that would have been resolved through lambdas in Log4J2.
e2cf796: changes an specific Logger from Log4J2 for a regular one. If this a really wanted feature, we can add it into the logging definition and attach that appender to the enclosing class.
04e62d2: changes the default value for logging of the retesteth subcommand
eea6494: mimics Log4J2 Configurator behavior but resolving the logging context through SLF4j
ed79b73: deprecates FATAL value option and maps it to ERROR
22e2256 and 4ad2493: fixes Sonar issues
8536a95: add a changelog entry

Changelog

I thought about the changelog and included a changelog update if required.

garyschulte

Thanks 🙏

I haven't gotten through the whole PR but a couple questions.

Also did you miss
./acceptance-tests/dsl/src/main/java/org/hyperledger/besu/tests/acceptance/dsl/node/BesuNode.java:84 ?

config/src/main/java/org/hyperledger/besu/config/Log4j2ConfiguratorUtil.java

besu/src/main/java/org/hyperledger/besu/cli/subcommands/RetestethSubCommand.java

diega · 2022-01-21T03:09:51Z

@garyschulte I completely missed org.hyperledger.besu.tests.acceptance.dsl.node.BesuNode. As a first approach I used a SLF4J migrator which actually only changed the LOG declarations (it didn't fixed the imports) but evidently missed at least this one. I'll double check. Thanks for catching it.

macfarla

I checked about 50% of the files and managed to find one typo :)

...er/besu/ethereum/api/jsonrpc/internal/privacy/methods/priv/PrivDistributeRawTransaction.java

gezero · 2022-01-21T09:31:52Z

What is your opinion on also including slf4j-lambda as another facade on top the SLF4J? They support the nice lambda syntax from log4j2. See

https://stackoverflow.com/a/48725206/550859
https://github.com/kwon37xi/slf4j-lambda

Personally, I would like us to wait with this change until SLF4J 2.0.0 gets out of alpha. The 1.x version has to support Java 6 and as such cannot support lambdas. The 2.0.0 is in alpha already for years, however, and they have more PRs open than closed, it seems.

I feel like the new ways of writing code, like for instance the lambda syntax when logging, reduces the cognitive load on people, so I would be unhappy to lose it.

diega · 2022-01-21T13:48:34Z

@gezero I think it would be easier to move to slf4j 2.x, when it's ready, starting from this PR than without it. In this PR there were 17 lambdas replaced with the is*Enabled pattern which we can get back pretty easily when the new API arrives.
Disclaimer: I'm not a big fan of adding dependencies 🙃

gezero · 2022-01-21T14:24:37Z

@diega I agree that the migration to SLF4J 2.0 might be easier from 1.x than from log4j2. What I find a concern is that SLF4J 2.0 release is nowhere near in sight. Therefore, we might be stuck on 1.x for an undefined amount of time. I suggest for consideration that the supplier pattern is superior to the previous pattern to the extent that it might not be worth migrating to 1.x at all. I am guessing the pattern is not used much, mostly because people are not aware of it.

In any case, I want to avoid blocking this effort. I can only imagine how much work it took to do all these changes. That is why I suggested to also include the slf4j-lambda.

garyschulte

I am 👍 for this PR, just waiting for consensus about if/what we should do for FATAL.

Will using FATAL simply map to ERROR if we do nothing?

diega · 2022-01-22T01:06:42Z

@garyschulte FATAL is still a valid org.apache.logging.log4j.Level value, so if it's set as a CLI param it will be resolved properly and set through o.h.b.u.Log4j2ConfiguratorUtil#setAllLevels, even if we don't mention it in the description of the option. The behavioral change comes at the actual logging output b/c through the SLF4J API it's not possible to log to that level so it will be no output for that case. Here's the class mapping SLF4J levels and Log4J2 levels

shemnon · 2022-01-24T16:04:52Z

I'm generally 👍 for this, but before we commit given the size and scope I would want sonar to read zero bugs, vulnerabilities, security, and code smells, all ideally fix with code and without any overrides. If some of the rules are bogus for how we work we should disable them in the scan itself rather than using code annotations.

diega · 2022-01-24T16:33:49Z

@shemnon sure, that makes perfect sense. I'll fix them and I'll come up with a discussion if there is some that couldn't be fixed

diega · 2022-01-25T04:22:09Z

I addressed most of the Sonar issues in 22e2256 and 4ad2493.
The missing code smell is about an usage of System.out in a place where the logging system isn't initialized yet, so I followed the decision made in BesuCommand.java:1490. Also, the 3 remaining Security Hotspots are pending for review within Sonar but I don't have enough permissions to do it. I think our use case for setting the logging level programmatically is safe (and the main intention of having a --logging CLI option) so we should approve those usages.

shemnon · 2022-01-25T18:05:19Z

Reviewed and waived the outstanding issues

one instance of System.out.println - appropriate for logging config errors.
Three instances of the logger being re-initialized. These calls are always tagged by sonar as low risk. There is no other way to do it.

If the merge doesn't add any other sonar issues I am +1 to merge.

Signed-off-by: Diego López León <dieguitoll@gmail.com>

This is for keeping compatibility with SLF4J. If neccesary, a specific formatter can be created for the RlpBlockImporter class Signed-off-by: Diego López León <dieguitoll@gmail.com>

This is because it's not possible to resolve the root logger level into a Log4J2 field Signed-off-by: Diego López León <dieguitoll@gmail.com>

org.hyperledger.besu.cli.BesuCommand#setAllLevels was taken from https://github.com/apache/logging-log4j2/blob/rel%2F2.17.1/log4j-core/src/main/java/org/apache/logging/log4j/core/config/Configurator.java#L309 Signed-off-by: Diego López León <dieguitoll@gmail.com>

Signed-off-by: Diego López León <dieguitoll@gmail.com>

Exceptions should be either logged or rethrown but not both Signed-off-by: Diego López León <dieguitoll@gmail.com>

Printf-style format strings should be used correctly Signed-off-by: Diego López León <dieguitoll@gmail.com>

Signed-off-by: Diego López León <dieguitoll@gmail.com>

sonarqubecloud · 2022-01-25T18:51:26Z

Kudos, SonarCloud Quality Gate passed!

0 Bugs
0 Vulnerabilities
0 Security Hotspots
0 Code Smells

84.0% Coverage
1.4% Duplication

garyschulte

Thank you @diega for all your hard work on this. 🚢

macfarla · 2022-01-25T21:19:45Z

CHANGELOG.md

@@ -25,6 +25,7 @@
 - Re-order external services (e.g JsonRpcHttpService) to start before blocks start processing [#3118](https://github.com/hyperledger/besu/pull/3118)
 - Stream JSON RPC responses to avoid creating big JSON strings in memory [#3076](https://github.com/hyperledger/besu/pull/3076)
 - Ethereum Classic Mystique Hard Fork [#3256](https://github.com/hyperledger/besu/pull/3256)
+- Move into SLF4J as logging facade [#3285](https://github.com/hyperledger/besu/pull/3285)


nit: this change will be in RC3 not RC2

macfarla

the only thing is the changelog entry should be in RC3 not RC2

* Bump SLF4J version Signed-off-by: Diego López León <dieguitoll@gmail.com> * Replace log4j2 API with SLF4j API Signed-off-by: Diego López León <dieguitoll@gmail.com> * Replace usage of LogManager#getFormatterLogger This is for keeping compatibility with SLF4J. If neccesary, a specific formatter can be created for the RlpBlockImporter class Signed-off-by: Diego López León <dieguitoll@gmail.com> * Unset the default logging value for the retesteth This is because it's not possible to resolve the root logger level into a Log4J2 field Signed-off-by: Diego López León <dieguitoll@gmail.com> * Prevent creation of Logger context outside SLF4J org.hyperledger.besu.cli.BesuCommand#setAllLevels was taken from https://github.com/apache/logging-log4j2/blob/rel%2F2.17.1/log4j-core/src/main/java/org/apache/logging/log4j/core/config/Configurator.java#L309 Signed-off-by: Diego López León <dieguitoll@gmail.com> * Add FATAL level deprecation message Signed-off-by: Diego López León <dieguitoll@gmail.com> * [Sonar] Fix java:S2139 Exceptions should be either logged or rethrown but not both Signed-off-by: Diego López León <dieguitoll@gmail.com> * [Sonar] Fix java:S3457 Printf-style format strings should be used correctly Signed-off-by: Diego López León <dieguitoll@gmail.com> * Add changelog Signed-off-by: Diego López León <dieguitoll@gmail.com>

diega force-pushed the slf4j branch 3 times, most recently from 66e19dc to cd9b7e0 Compare January 20, 2022 14:50

garyschulte reviewed Jan 21, 2022

View reviewed changes

config/src/main/java/org/hyperledger/besu/config/Log4j2ConfiguratorUtil.java Outdated Show resolved Hide resolved

besu/src/main/java/org/hyperledger/besu/cli/subcommands/RetestethSubCommand.java Outdated Show resolved Hide resolved

macfarla reviewed Jan 21, 2022

View reviewed changes

...er/besu/ethereum/api/jsonrpc/internal/privacy/methods/priv/PrivDistributeRawTransaction.java Outdated Show resolved Hide resolved

diega force-pushed the slf4j branch 2 times, most recently from cb341fe to 60d4bce Compare January 21, 2022 15:29

garyschulte reviewed Jan 22, 2022

View reviewed changes

diega force-pushed the slf4j branch 2 times, most recently from b0c783f to 7febfec Compare January 24, 2022 11:16

diega force-pushed the slf4j branch 10 times, most recently from 2f677bb to f35aad0 Compare January 25, 2022 03:53

Bump SLF4J version

4d7d1e4

Signed-off-by: Diego López León <dieguitoll@gmail.com>

diega added 8 commits January 25, 2022 15:31

Replace log4j2 API with SLF4j API

909a195

Signed-off-by: Diego López León <dieguitoll@gmail.com>

Replace usage of LogManager#getFormatterLogger

e2cf796

This is for keeping compatibility with SLF4J. If neccesary, a specific formatter can be created for the RlpBlockImporter class Signed-off-by: Diego López León <dieguitoll@gmail.com>

Unset the default logging value for the retesteth

04e62d2

This is because it's not possible to resolve the root logger level into a Log4J2 field Signed-off-by: Diego López León <dieguitoll@gmail.com>

Add FATAL level deprecation message

ed79b73

Signed-off-by: Diego López León <dieguitoll@gmail.com>

[Sonar] Fix java:S2139

22e2256

Exceptions should be either logged or rethrown but not both Signed-off-by: Diego López León <dieguitoll@gmail.com>

[Sonar] Fix java:S3457

4ad2493

Printf-style format strings should be used correctly Signed-off-by: Diego López León <dieguitoll@gmail.com>

Add changelog

8536a95

Signed-off-by: Diego López León <dieguitoll@gmail.com>

diega force-pushed the slf4j branch from 7eddd3b to 8536a95 Compare January 25, 2022 18:33

shemnon approved these changes Jan 25, 2022

View reviewed changes

garyschulte approved these changes Jan 25, 2022

View reviewed changes

macfarla reviewed Jan 25, 2022

View reviewed changes

macfarla approved these changes Jan 25, 2022

View reviewed changes

diega merged commit ed1329c into hyperledger:main Jan 25, 2022

diega deleted the slf4j branch January 25, 2022 23:15

diega mentioned this pull request Feb 14, 2022

Replace Log4j2 with Logback #3425

Closed

2 tasks

diega mentioned this pull request Apr 25, 2022

Add errorprone to prevent Log4j direct usage #3759

Merged

2 tasks

diega added the mainnet label May 29, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Introduce SLF4J for logging #3285

Introduce SLF4J for logging #3285

diega commented Jan 16, 2022 •

edited

Loading

garyschulte left a comment

diega commented Jan 21, 2022

macfarla left a comment

gezero commented Jan 21, 2022 •

edited

Loading

diega commented Jan 21, 2022

gezero commented Jan 21, 2022 •

edited

Loading

garyschulte left a comment

diega commented Jan 22, 2022

shemnon commented Jan 24, 2022 •

edited

Loading

diega commented Jan 24, 2022 •

edited

Loading

diega commented Jan 25, 2022 •

edited

Loading

shemnon commented Jan 25, 2022

sonarqubecloud bot commented Jan 25, 2022

garyschulte left a comment

macfarla Jan 25, 2022

macfarla left a comment

Introduce SLF4J for logging #3285

Introduce SLF4J for logging #3285

Conversation

diega commented Jan 16, 2022 • edited Loading

PR description

Changelog

garyschulte left a comment

Choose a reason for hiding this comment

diega commented Jan 21, 2022

macfarla left a comment

Choose a reason for hiding this comment

gezero commented Jan 21, 2022 • edited Loading

diega commented Jan 21, 2022

gezero commented Jan 21, 2022 • edited Loading

garyschulte left a comment

Choose a reason for hiding this comment

diega commented Jan 22, 2022

shemnon commented Jan 24, 2022 • edited Loading

diega commented Jan 24, 2022 • edited Loading

diega commented Jan 25, 2022 • edited Loading

shemnon commented Jan 25, 2022

sonarqubecloud bot commented Jan 25, 2022

garyschulte left a comment

Choose a reason for hiding this comment

macfarla Jan 25, 2022

Choose a reason for hiding this comment

macfarla left a comment

Choose a reason for hiding this comment

diega commented Jan 16, 2022 •

edited

Loading

gezero commented Jan 21, 2022 •

edited

Loading

gezero commented Jan 21, 2022 •

edited

Loading

shemnon commented Jan 24, 2022 •

edited

Loading

diega commented Jan 24, 2022 •

edited

Loading

diega commented Jan 25, 2022 •

edited

Loading