hyperledger
Logging improvements
Description
We want to improve the log file output to make it easier to understand for end users. I propose to clean up the INFO log level and make the target group for INFO the end user.
[ ] Remove thread and class name on the info log level. I think this does not provide any value to the end users
[ ] Show an informative configuration section at the beginning (including storage, sync mode). Take Geth as example
[ ] Move Refreshing DNS records with enrtree to debug or trace (in progress)
[ ] No sync target, checking current peers for usefulness is too spammy. It should be only logged in a fixed interval
[ ] Snap sync: I think for we should output just the download progress in percent in a regular interval (eg 30s). The other output can be moved to DEBUG. Geth prints an estimation how long it will take as well, which I find very useful
[ ] Snap sync: Once we are downloading blocks, it would be useful to print the the age of the latest block (eg 3y10m2d) to give a better sense how far we behind we are
[ ] Make the log message No sync target, checking current peers for usefulness messages clearer or downgrade it to debug/trace
[ ] Add context to message BackwardsSyncAlgorithm | Waiting for preconditions..
DEBUG and TRACE should not be changed for the time being, as the target group are mainly the Besu contributors. There are some extra logs that we should add:
[ ] Add why transactions have been rejected
Refer to protocol-misc # 486
I'd be cautious of only logging download progress at % intervals because you don't know how long it will take to progress and the user needs regular feedback so they don't think it's stalled.
I'd suggest a regular log line, say every 15 seconds, that gives a snapshot of the sync progress. Something like: Syncing - Blocks: 1,000,000/10,000,000 (10%), World state: 25%, Peer count: 25. They may not be the exact details and there would need to be variants when progress is paused waiting for peers or waiting for info from the CL etc but that's the general idea.
Then the logs about how the sync works could move down to debug level unless:
- they're something particularly notable (starting sync, switching between modes in sync etc)
- they're something unusual that the user should be aware of (a peer failing to respond is normal, an invalid block during long sync is probably unexpected and worth logging) or
- the user needs to take some action (out of disk space, no calls from the CL for too long etc)
This PR filters the DNS refresh messages (they come from tuweni) https://github.com/hyperledger/besu/pull/4155/files
Decided not to investigate log4j configuration issue further. Closing this issue.
