Skip to content

Node/logs: enables daily logs on disk by default

Rémy El Sibaïe requested to merge remy@activate-info-default into master

Context

Following the ongoing work of improving node logs UX, we would like to strip some content of stdout logging when still keeping the ability to debug with only post mortem info.

For this, we mean to create by default two canals for logs (instead of one):

  • Stdout logs: clean, simple, not too verbose, only what matters and is understandable for the user (level Notice)
  • Disk stored logs: more events, more info, more data (level Info)

The current default configuration of the node enable lwt-log sink, which is an stdout logger with Notice level. In this MR, we add a second default configuration using a file-descriptor-sink stored in data-dir with a 7 days rotation. The configuration is equivalent to the following.

file-descriptor-path://<data-dir>/daily-logs/daily.log
  ?allow-create-dir=true
  &daily-logs=7
  &section-prefix=:
  &format=pp

Note that allow-create-dir is a new option introduced by this MR allow the node utilities to create the parents directories of the log file if it doesn't exist.

Execution statistics on file-descriptor-sinks

To ensure there is no regression, we provide some data during execution.

Memory usage

thanks to @ACoquereau

image

Above is the memory consumption of the node while using various level of file descriptor sinks.

  • Spikes appears when the log level is set to Debug. The node is stopped and restarted at both tops of the spikes. There is definitely a memory leak when using this level.
  • The constant part of the curve is a node executing with a file-descriptor-sink at level Info.

Time consumption

Here is a document with execution time of a node while boostraping (between chain level 1 to 10000 on limanet) using various level of log styles including file-descriptor-sink.

image

There is no difference to mention in terms of execution time between the various logging methods and in particular, a file-descriptor-sink in Info doesn't seem to be slower that using --log-output and the default lwt-log sink. This last logging method is interesting because it is the one depicted on opentezos in from sources paragraph, so it seem to be the one we advise to be used by our users.

image

Storage consumption

still thanks to @ACoquereau

Various level, various size:

  • Debug: ~16GB a day (We see you, p2p)
  • Info: ~40MB a day
  • Notice: ~10MB a day

40MB a day seem to be of reasonnable size to be kept on disk for 7 days (280MB).

Conclusion

There doesn't seem to be any obvious regression when using a file-descriptor-sink on level info and it should be safe to enable it by default on the node.

Manually testing the MR

Run any node up to date with this MR and check <data-dir>/daily-logs

Checklist

  • Document the interface of any function added or modified (see the coding guidelines)
  • Document any change to the user interface, including configuration parameters (see node configuration)
  • Provide automatic testing (see the testing guide).
  • For new features and bug fixes, add an item in the appropriate changelog (docs/protocols/alpha.rst for the protocol and the environment, CHANGES.rst at the root of the repository for everything else).
  • Select suitable reviewers using the Reviewers field below.
  • Select as Assignee the next person who should take action on that MR
Edited by Rémy El Sibaïe

Merge request reports