WL#11194: Harness - Add optional timestamp precision to log

Affects: Server-8.0   —   Status: Complete

Motivation

User use the Router's logfiles to track down problems. With the current "second" resolution timestamps and sub-second events a lot of information of when something happened is lost.

Goal

  • Allow optional sub-second timestamp precision for file/console-based logs
FR1
logger MUST output timestamps according to specified precision
FR2
logger MUST use the same default precision as before this WL
FR3
logger timestamp precision MUST allow seconds, milliseconds, microseconds and nanoseconds
FR4
logger timestamp precision MUST be user configurable using the router config file

Non Function Requirements

NFR1
timestamp precision only applies to logger-sinks which create their own timestamp (like "filelog" and "console").

Configuration file

The logger timestamp precision should be user configurable using the logger section of the configuration file:

[logger]
...
timestamp_precision = <precision>

where <precision> is one of either:

  • second, sec, s: 2019-05-10 12:10:25
  • millisecond, msec, ms: 2019-05-10 12:10:25.428
  • microsecond, usec, us: 2019-05-10 12:10:25.428754
  • nanosecond, nsec, ns: 2019-05-10 12:10:25.428754000

Currently limited by struct Record using a time_t member to track timestamps, which only provides second resolution. Suggest using std::chrono::time_point and std::chrono::system_clock::now() instead.

Extend the Handler, Registry and Logger interfaces with function to allow setting timestamp precision.

struct Record {
  LogLevel level;
  pid_t process_id;
  std::chrono::time_point created;
  std::string domain;
  std::string message;
};

Pseudo-code:

std::chrono::time_point now = std::chrono::system_clock::now();

std::shared_ptr<Handler> handler =
    g_registry->get_handler("TestStreamHandler");
// Set millisecond precision
handler->set_precison(milliseconds);

Record record{level, pid, now, "my_module", message};
logger.handle(record);

...