Major refactor of handlers

[emmuhamm]

Description

Fixes DUNE-DAQ/drunc#776
Fixes #48
Fixes #51

This is a long time coming

Superseeds #53 #49

Context

For some more comprehensive set of logic ideas, please refer to the attached slides

ers_refactor.pdf

During testing of drunc, it was identified that we should be able to configure the handlers of a logging instance based on the ERS config supplied. This posed a greater question of how we deal with configuring the initialisation of handlers for loggers in general. Keep in mind that so far the features of the LogHandlerConf are entirely used for filtering; this is completely separate compared to how the logging was initialised.

A couple of key points are identified:

• We need to be able to add the ERS handlers automatically to the logging instance, based on what handlers are used in the entirity of ERS
• There needs to be a way for the logger to remember what handlers it was initialised with, and only use those if no extra argument was used to choose which Handler to use
  • The problem is that adding handlers to the logger is easy, but by default a logger will use all available handlers when sending a message
  • When configuring ERS handlers, all these will be added to the logger. Any usual message will therefore be sent to all the handlers that exist, which is not what we want.
  • This should happen by default; we do not want to modify drunc and add in extra=HandlerType.Rich... in every message
  • There is functionality to filter on which handler to use on a per message level, and also functionality for the filter to default to a specific set of handlers when none are used
  • This needs to be further expanded on to deal with ERS

The changes here are meant to tackle the above.

Changes

Fallback Handlers

The concept of Fallback Handlers are introduced. These are basically the 'default case' for what happens when log message is put in.

Basically, when a user writes in log.info("msg"), the code will parse it as log.info("msg", extra={"handlers": fallback_handlers}. This happens at the filtering stage of each handler, so at each HandleIDFilter attached to every handler.

By default, the fallback handler for each handler is set to be itself, thereby following the default behaviour. Eg. the HandleIDFilter attached to the Rich handler will have the fallback handler to HandlerType.Rich, which will allow every message to pass.

The user experience is quite straight forward:

Test exceprt

    fallback_log: logging.Logger = get_daq_logger(
        logger_name="fallback_logger",
        log_level=log_level,
        stream_handlers=False,
        rich_handler=True, # Only rich has been added
    )

    # As rich has been added, only rich should be used
    fallback_log.info("Rich Only")
    
    # Adding a stdout handler as usual
    ### Importantly, by default the fallback_handler will use HandlerType.stdout (for this case)
    ### So that it will fire automatically by default if no extras are added
    add_stdout_handler(fallback_log, True)

    # Adding an stderr handler with a fallback_handler to Unknown
    ### This makes it so that if no extra exist, then the attached filter will default check if 
    ### stderr == unknown
    ### Basically, the code then does an equivalent of 
    ### log.warning("msg", extra={HandlerType.Unknown})
    ### Which obviously fails for the stderr case
    add_stderr_handler(fallback_log, True, {HandlerType.Unknown})


    ## Result is that both RICH and STDout pass, but stderr fails because it defaults to nonworking
    fallback_log.critical("Rich + stdout only")
    
    ## Ofcourse, the handler still exists.
    ## so if you manually call it using the extra feature, it will print
    fallback_log.critical(
        "Rich + stdout + stderr",
        extra={"handlers": [HandlerType.Rich, HandlerType.Stream]},
    )

All the details on how it works is in the annotated text above from a users perspective.
By default, it will set it to whatever the current handlertype is.

For example, add_rich_handler will make the default case a HandlerType.Rich.

Setup ERS Handlers

A new function called setup_daq_ers_logger has been implemented.

With everything set up, this is a relatively simple function. All it does is to get the oks configuration, gets a set of all HandlerTypes, and then passess it to add_handlers_from_types to get it added to the loggers.

Importantly, the fallback_handlers for this is set to HandlerType.Unknown. This means that none of the new handlers added by the function will not be called unless specifically requested for!

logging demonstrator

Of course, the logging demonstrator has been updated.

Change topic name in ERS

Oh yeah I also fixed the ability to choose which session name the ERS handler goes to now.

Major refactor of the code

See the previously linked set of slides for the description, but in general we have now new set of files:

• handlers.py -> where the handlers are defined
• handlerconf.py -> definition of LogHandlerConf and related
• rich_handler.py -> holds just the formattedrichhandler, helps for internal logging
• routing.py -> logic behind selecting which handlers are presented
• specs.py -> definition for specs to be used by handlers.py

The nicest new features are as follows:

• complete separation of logic between 'what handlers do i need to check' and actually checking if the handler is in the list of handlers being checked against. Means that installing new routing should be straightforward, in case they want to be changed
• Handers now defined by their handler spec, which contains the complete set of instructions on how to build and install a handler.
• This is stored in a handler registry, which maps a HandlerType to a handler spec
• Which then allows us to have a generalised add_handlers function, that will add a handler based on which handlertype you call it with.
• Handler building uses **kwargs, just like matplotlib, so its infinitely extendable

Better imports

With this change, I added a couple of the useful imports in the __init__.py file. This makes things much easier for users of daqpytools since they can just do from daqpytools.logging import x rather than having to know what each of the files do and stuff.

Type of change

• New feature or enhancement (non-breaking change which adds functionality)
• Optimization (non-breaking change that improves code/performance)

Testing checklist

• Unit tests pass (e.g. dbt-build --unittest)
• Minimal system quicktest passes (pytest -s minimal_system_quick_test.py)
• Full set of integration tests pass (dunedaq_integtest_bundle.sh)
• Python tests pass if applicable (e.g. python -m pytest)
• Pre-commit hooks run successfully if applicable (e.g. pre-commit run --all-files)

To test:

• Run the monster: daqpytools-logging-demonstrator -eh -hc -r -f log.log -ht -fh -s -ep emir-test -t or similar
  • Check that each message in the initial example displays as expected (1 rich + 1 stdout, with a +1 stderr on eerror and above)
  • Check that the colors still exist in the example displays
  • Check that throttling works as expected
  • Check handlerconf works as expected
  • Check that the expected ERS messages appear
  • Check fallback_loggers demonstrator works
  • Check ersconfig demonstrator works

These are vague ish instructions, but they should be relatively clear based on the messages in the demonstrator itself

Further checks

• Code is commented where needed, particularly in hard-to-understand areas
• Code style is correct (dbt-build --lint, and/or see https://dune-daq-sw.readthedocs.io/en/latest/packages/styleguide/)
• If applicable, new tests have been added or an issue has been opened to tackle that in the future.
  (Indicate issue here: # (issue))

[emmuhamm]

Avoid defaults as much as possible. Ideally, this should only be 'defaulted' at the get_daq_logger stage, and nowhere else.

Need to decide if we can remove defaults in ERSKafka as well. Preferrably yes, but im not sure if im gonna break anything as that might be used by other people already