Univention Bugzilla – Bug 55324
[univention.debug]: add python-logging interface for univention-debug
Last modified: 2024-02-05 15:08:48 CET
In Bug #55186 as request ID has been added to the UDM REST API. The request ID is logged but not in the underlying UDM log messages. UDM could use python-logging with a special backwards compatible univention.debug handler. A python-logging filter could insert the request ID. The UDM REST API should store a global context variable so that asynchronous operations log the correct request ID. https://peps.python.org/pep-0567/ https://docs.python.org/3/library/contextvars.html +++ This bug was initially created as a clone of Bug #55186 +++
In MR https://git.knut.univention.de/univention/ucs/-/merge_requests/572/ we start to add the basis for this: a loggigng handler for univention.debug.
(In reply to Florian Best from comment #0) > In Bug #55186 as request ID has been added to the UDM REST API. > The request ID is logged but not in the underlying UDM log messages. This has been outsourced into Bug #56970. > UDM could use python-logging with a special backwards compatible > univention.debug handler. A python-logging filter could insert the request > ID. A python-logging interface for univention.debug has been implemented. It provides a: * logging.Logger which can also handle the univention.debug init()ialization. * logging.Handler which forwards log messages to univention.debug * logging.Formatter which allows e.g. to add the process ID (and in the future the Request-ID) as prefix to log messages (as univention.debug is not capable of this) and UMC and UDM REST API requires this in multiprocessing mode * a basicConfig() function, similar to the one from stdlib, to make the initilization * etc. It was designed that the API conforms to the logging module and users of it only seem to use python-logging: > import logging > logging.getLogger('MAIN').error('Error %s', 'details') This design decision is an important aspect, as it will allow use in the future to replace univention.debug and univention.logging completely. It also allows that e.g. when running the component in a docker container we don't necessarily init the univention.debug log but just use the regular logging (e.g. via a switch in the code or by replacing univention.logging in the container). I am especially thinking about UDM here. The only thing required it that once `univention.logging` is imported somwhere. It also doesn't matter in which order the import is: >>> import logging >>> m = logging.getLogger('MAIN') >>> m <Logger MAIN (WARNING)> >>> import univention.logging >>> m <univention.logging.Logger MAIN (NOTSET)> A logger for each univention-debug category is created at import time of `univention.logging`. It's also possible to extend a existing logger to use the univention.debug functionality, e.g. via: >>> import logging >>> m = logging.getLogger('tornado.access') >>> m <Logger tornado.access (WARNING)> >>> import univention.logging >>> m <Logger tornado.access (WARNING)> >>> univention.logging.extendLogger('tornado.access', univention_debug_category='MAIN') >>> m <univention.logging.Logger tornado.access (WARNING)> >>> import tornado.log >>> tornado.log.access_log <univention.logging.Logger tornado.access (WARNING)> The UMC log.py wrapper have been adjusted so that they use univention.logging interface now, which will allow using nice logging features in UMC modules. univention-management-console.yaml 26d43c382371 | refactor(umc): use univention.logging instead of univention.debug directly univention-management-console (12.0.32-5) 26d43c382371 | refactor(umc): use univention.logging instead of univention.debug directly univention-directory-manager-rest.yaml 7cfd8fd623af | feat(udm-rest): initialize logging via univention.logging univention-directory-manager-rest (10.0.7-4) 7cfd8fd623af | feat(udm-rest): initialize logging via univention.logging 03eae90e789c | feat(udm): initialize logging via univention.logging univention-directory-manager-modules.yaml 03eae90e789c | feat(udm): initialize logging via univention.logging univention-directory-manager-modules (15.0.25-2) 8c067625c519 | refactor(udm): replace ud wrapper with univention.logging 03eae90e789c | feat(udm): initialize logging via univention.logging univention-directory-manager-module-example (9.0.2-1) 03eae90e789c | feat(udm): initialize logging via univention.logging univention-debug-python.yaml f9376106e03b | feat(logging): add univention.logging as univention.debug handler with the python-logging interface univention-debug-python (12.0.3-1) f9376106e03b | feat(logging): add univention.logging as univention.debug handler with the python-logging interface univention-appcenter.yaml 26d43c382371 | refactor(umc): use univention.logging instead of univention.debug directly univention-appcenter (9.0.10-1) 26d43c382371 | refactor(umc): use univention.logging instead of univention.debug directly ucs-test (10.0.20-13) 03eae90e789c | feat(udm): initialize logging via univention.logging
Some additional fine tuning and fixes: univention-debug-python (12.0.3-4) bec0e9097345 | test(univention-debug): fix unittest a8a6e0388cd2 | fix(univention.debug): fix univention.debug2 not sharing same handlers with univention.logging 1693ca799a2a | fix(univention.debug): use logger.propagate = False instead of NullHandler e6c04bf62a96 | feat(univention.debug): add pid explicit to log format 4416f8d503db | fix(univention.debug): use default fallback when loglevel is unknown QA: python3 -c "import univention.logging, logging; univention.logging.basicConfig(filename='stderr'); logging.basicConfig(); logging.error('non-ud'); logging.getLogger('MAIN').error('ud-inited')" python3 -c "import logging; logging.basicConfig(); logging.error('non-ud'); import univention.logging; logging.getLogger('MAIN').error('ud'); univention.logging.basicConfig(filename='stderr'); logging.getLogger('MAIN').error('ud-inited')" python3 -i -c "import univention.debug2 as ud, univention.logging, logging; ud.init('stdout'); univention.logging.basicConfig(filename='stderr'); logging.getLogger('MAIN').error('ud1'); logging.getLogger('foo').getChild('bar').error('foo'); ud.debug(ud.MAIN, ud.ERROR, 'ud2')" python3 -i -c "import univention.debug2 as ud, univention.logging, logging; univention.logging.basicConfig(filename='stderr'); ud.init('stdout'); logging.getLogger('MAIN').error('ud1'); logging.getLogger('foo').getChild('bar').error('foo'); ud.debug(ud.MAIN, ud.ERROR, 'ud2')"
code review: ok yaml: ok logging unit tests: ok jenkins tests: ok log messages of various components are equivalent to before (UMC, UDM, s4connector): ok importing, initalizing and logging from `univention.logging`, `univention.debug2` and `logging` in a variety of orders produces expected log messages to the expected locations: ok extending an vanilla `logging.Logger` into an `univention.logging.Logger`: ok
<https://errata.software-univention.de/#/?erratum=5.0x924> <https://errata.software-univention.de/#/?erratum=5.0x925> <https://errata.software-univention.de/#/?erratum=5.0x926> <https://errata.software-univention.de/#/?erratum=5.0x927> <https://errata.software-univention.de/#/?erratum=5.0x928>