From 70526423505f8dbac4ec40da631e5601d5413ba3 Mon Sep 17 00:00:00 2001 From: Yaroslav Halchenko Date: Tue, 24 Oct 2023 16:22:47 -0400 Subject: [PATCH] Remove custom datalad log handlers while enable library mode MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ATM, if there is a root level logger set by Python application, which is a logical thing to do for an application, then datalad log messages end up duplicated -- once they are provided by the root level log handler and then by our very own one. E.g. this script import logging ## The simplest and documented way to enable logging for a Python app logging.basicConfig(level=logging.INFO, format='%(name)s : %(asctime)s - %(levelname)s - %(message)s') # Alternative way to enable some root level logging # which surprised me #logging.info('This is an info message') import datalad.support.gitrepo as r r.lgr.info("datalad logger talking") datalad_lgr = logging.getLogger("datalad") print(f"logging has handlers: {logging.getLogger().handlers}") print(f"DataLad has handlers: {datalad_lgr.handlers}" would produce following output: ❯ python simplest_app2.py [INFO ] datalad logger talking datalad.gitrepo : 2023-10-24 16:27:02,703 - INFO - datalad logger talking logging has handlers: [ (NOTSET)>] DataLad has handlers: [] so you see our log line duplicated! With the proposed change, we will explicitly remove all assigned handlers when enabling library mode, and if we add to above script the datalad.enable_librarymode() we get ❯ python simplest_app2.py datalad.gitrepo : 2023-10-24 16:29:25,478 - INFO - datalad logger talking logging has handlers: [ (NOTSET)>] DataLad has handlers: [] We also have to respect config variable so we could handle properly the DATALAD_RUNTIME_LIBRARYMODE environment variable. --- datalad/__init__.py | 7 +++++++ datalad/log.py | 4 ++++ 2 files changed, 11 insertions(+) diff --git a/datalad/__init__.py b/datalad/__init__.py index a8dd881958..15ef22ddb2 100644 --- a/datalad/__init__.py +++ b/datalad/__init__.py @@ -81,6 +81,13 @@ def enable_librarymode(): # export into the environment for child processes to inherit os.environ['DATALAD_RUNTIME_LIBRARYMODE'] = '1' + # disable custom datalad logging handler + lgr_handlers = lgr.handlers + if lgr_handlers: # were not removed yet! + for h in lgr_handlers: + lgr.debug("Enabling library mode: removing datala:wd specific handler %s", h) + lgr.removeHandler(h) + # For reproducible demos/tests _seed = os.environ.get('DATALAD_SEED', None) diff --git a/datalad/log.py b/datalad/log.py index 646b9cdeb7..b55010878e 100644 --- a/datalad/log.py +++ b/datalad/log.py @@ -621,6 +621,10 @@ def get_initialized_logger(self, logtarget=None): ------- logging.Logger """ + import datalad + if 'datalad.runtime.librarymode' in datalad.cfg: + return self.lgr + if not logtarget: logtarget = self._get_config('target', 'stderr')