Logging: Add configuration variables to set various formats

[dumbbell]

In addition to the existing configuration variables to configure logging, the following variables were added to extend the settings.

• log.*.formatter = plaintext | json

  Selects between the plain text (default) and JSON formatters.

• log.*.formatter.time_format = rfc3339_space | rfc3339_T | epoch_usecs | epoch_secs | lager_default
  Configures how the timestamp should be formatted. It has several values to get RFC3339 date & time, Epoch-based integers and Lager default format.

• log.*.formatter.level_format = lc | uc | lc3 | uc3 | lc4 | uc4

  Configures how to format the level. Things like uppercase vs. lowercase, full vs. truncated.

  Examples:

  lc: debug
  uc: DEBUG
  lc3: dbg
  uc3: DBG
  lw4: dbug
  uc4: DBUG
  

• log.*.formatter.single_line = on | off
  Indicates if multi-line messages should be reformatted as a single-line message. A multi-line message is converted to a single-line message by joining all lines and separating them with ", ".

• log.*.formatter.plaintext.format

  Set to a pattern to indicate the format of the entire message. The format pattern is a string with $-based variables. Each variable corresponds to a field in the log event. Here is a non-exhaustive list of common fields:

  • time
  • level
  • msg
  • pid
  • file
  • line

  Example:

  $time [$level] $pid $msg
  

• log.*.formatter.json.field_map

  Indicates if fields should be renamed or removed, and the ordering which they should appear in the final JSON object. The order is set by the order of fields in that coniguration variable.

  Example:

  time:ts level msg *:-
  

  In this example, time is renamed to ts. *:- tells to remove all fields not mentionned in the list. In the end the JSON object will contain the fields in the following order: ts, level, msg.

• log.*.formatter.json.verbosity_map

  Indicates if a verbosity field should be added and how it should be derived from the level. If the verbosity map is not set, no verbosity field is added to the JSON object.

  Example:

  debug:2 info:1 notice:1 *:0
  

  In this example, debug verbosity is 2, info and notice verbosity is 1, other levels have a verbosity of 0.

All of them work with the console, exchange, file and syslog outputs.

The console output has specific variables too:

• log.console.stdio = stdout | stderr

  Indicates if stdout or stderr should be used. The default is stdout.

• log.console.use_colors = on | off

  Indicates if colors should be used in log messages. The default depends on the environment.

• log.console.color_esc_seqs.*

  Indicates how each level is mapped to a color. The value can be any string but the idea is to use an ANSI escape sequence.

  Example:

  log.console.color_esc_seqs.error = \033[1;31m
  

V2: A custom time format pattern was introduced, first using variables, then a reference date & time (e.g. "Mon 2 Jan 2006"), thanks to @ansd. However, we decided to remove it for now until we have a better implementation of the reference date & time parser.

V3: The testsuite was extended to cover new settings as well as the syslog output. To test it, a fake syslogd server was added (Erlang process, part of the testsuite).

V4: The dependency to cuttlefish is moved to rabbitmq_prelaunch which actually uses the library. The version is updated to 3.0.1 because we need Kyorai/cuttlefish#25.

[dumbbell]

Note that with this pull request, it is possible to configure logging to be compatible with the messages formatted by Lager.

Here are log message from RabbitMQ 3.8.14:

2021-03-25 15:51:34.837 [info] <0.735.0> started TCP listener on [::]:5672
2021-03-25 15:51:34.838 [info] <0.750.0> started TCP listener on 0.0.0.0:5672
2021-03-25 15:51:34.838 [notice] <0.280.0> Changed loghwm of /tmp/rabbitmq_server-3.8.14/var/log/rabbitmq/rabbit@cassini.log to 5000
2021-03-25 15:51:35.024 [info] <0.720.0> Server startup complete; 0 plugins started.

With the following configuration:

log.file.formatter.time_format = lager_default

Here are the same messages with this branch:

2021-03-25 15:51:54.714 [info] <0.466.0> started TCP listener on [::]:5672
2021-03-25 15:51:54.717 [info] <0.484.0> started TCP listener on 0.0.0.0:5672
2021-03-25 15:51:54.729 [info] <0.448.0> Server startup complete; 0 plugins started.

The missing message about loghwm is Lager-specific.

The remaining incompatibility is how multi-line messages are handled: we prefix them in master, but Lager didn't. How multi-line messages are handled could be a new configuration setting if we want.

[dumbbell]

A bug in Cuttlefish was identified around an undocumented feature to take a value from a text file. The parsing of that syntax is approximate at best. We will work on a fix and submit it upstream. Meanwhile, we can't fully test this branch.

[ansd]

Cuttlefish PR: Kyorai/cuttlefish#25

[dumbbell]

The pull request was updated with the Cuttlefish update (we need Kyorai/cuttlefish#25).