Issue1051

Title new logger interface and structured log records
Priority wish Status chatting
Superseder Nosy List jendrik, malte, silvan, simon
Assigned To Keywords
Optional summary

Created on 2022-03-09.20:40:32 by malte, last changed by malte.

Messages
msg11588 (view) Author: malte Date: 2024-02-24.03:33:03
Here is a video that talks about many of the things that this touches on, including logging a sequence of JSON records: https://www.youtube.com/watch?v=9L77QExPmI0.

It's for Python, not C++, but I think it could be useful anyway as a starting point for our further discussion.
msg10654 (view) Author: malte Date: 2022-03-09.20:40:32
While working on issue921, we discussed the next evolution(s) of the new logging interface. We like the idea of replacing the stream-based interface with a function call interface and associating every log entry with a log level, as in other logging frameworks (e.g. Python's). For example:

    if (log.is_at_least_normal()) {
        log << "Found concrete solution during refinement." << endl;
    }

could become

    log.message("Found concrete solution during refinement.");

where "message" includes "at least normal" priority and other methods would indicate different priorities. Python uses such an interface with these methods: debug, info, warning, error, critical.

When we want to log multiple elements, we could use multiple arguments, for example using variadic templates:

    log.debug("pruning algorithm pruned ", x, " out of ", y, " variables");
    log.info("variables: ", num_variables);
    log.info("time for parsing: ", parsing_timer);

We would still use a guard like "is_at_least_normal" in cases where computing the arguments is expensive.

Every call to log.info and friends would produce a self-contained logging record consisting of the log level (e.g. info, debug etc.), the time and memory information that we already emit, the identity of the logger used, and the output string. This could then be filtered/processed in different ways by configuring the loggers, like e.g. in Python's logging framework.

As a following step, we could do structured logging of statistics in a way that can be nicely integrated with lab, like this:

     log.statistics("expanded_states", expanded_states);

This could produce a log entry on stdout and/or a JSON entry to be processed by lab in a separate output file, again controllable by options to the logger. Making this convenient probably requires some kind of logger hierarchy, again as in Python, so that we don't need to configure all component loggers separately.

We already have a related issue for this latter point of structured logging for statistics to be parsed by lab: issue589. My suggestion is to abandon the old issue, but salvage the relevant parts of the discussion. I'm marking that issue as resolved now, but there is still relevant info in its discussion that we should consider when we work on this issue.


I would view log.info, log.debug and friends as the first step and the hierarchical loggers and structured statistics as a second step for a separate issue. But I suggest to keep the discussion in this one issue until we start implementing this. We can always split off parts that we want to do later when we begin actively working on this.
History
Date User Action Args
2024-02-24 03:33:03maltesetstatus: unread -> chatting
messages: + msg11588
2022-03-09 20:40:32maltecreate