DEVHIDE
Login Or Sign up

Python logging global variable in an imported library

52 Views Asked by At

Can someone explain the behavior of logging behavior in a library which is imported? The log contains a supposedly global variable called trace_id.

I have the following library:

my_library/
  __init__.py
  folder1/
    __init_.py
    helper.py

where helper.py looks like:

import logging

logger = logging.getLogger(__name__)
def helper():
    logger.info('LOG IN HELPER')

My main program, which imports this library, looks like this:

import logging

trace_id = 1

class CustomLogger(logging.Logger):

    def _log(self, level, msg, args, exc_info=None, extra=None):
        extra = {'trace_id': trace_id}
        super(CustomLogger, self)._log(level, msg, args, exc_info, extra)


logger = logging.getLogger(__name__)

def config_logger():
    helper_logger = logging.getLogger("folder1")

    formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s - %(trace_id)s')

    handler = logging.StreamHandler()
    handler.setFormatter(formatter)
    handler.setLevel(logging.INFO)
    helper_logger.addHandler(handler)
    helper_logger.setLevel(logging.INFO)

def program():
    logger.info('main start')

    # <--- SET LOGGER CLASS FIRST ---> #
    logging.setLoggerClass(CustomLogger)
    from folder1.helper import helper

    config_logger()
    helper()
    global trace_id
    trace_id += 1
    helper()
    logging.setLoggerClass(logging.Logger)
    logger.info('main end')

And my test_program.py looks like this:

import logging
import program

logger = logging.getLogger(__name__)

class TestProgram:

    def test_helper(self):
        logger.info('LOG IN TEST')
        program.program()

Here's my problem. If I set logger class first, test_program runs with the expected output:

-------------------------------- live log call ---------------------------------
INFO     test_program:test_program.py:9 LOG IN TEST
INFO     program:program.py:30 main start
2024-01-14 22:42:50,521 - folder1.helper - INFO - LOG IN HELPER - 1
INFO     folder1.helper:helper.py:5 LOG IN HELPER
2024-01-14 22:42:50,522 - folder1.helper - INFO - LOG IN HELPER - 2
INFO     folder1.helper:helper.py:5 LOG IN HELPER
INFO     program:program.py:40 main end

However, if I import first, as shown below:

...
    logger.info('main start')

    # <--- IMPORT FIRST ---> #
    from folder1.helper import helper
    logging.setLoggerClass(CustomLogger)

    config_logger()
...

it gives me an error:

-------------------------------- live log call ---------------------------------
INFO     test_program:test_program.py:9 LOG IN TEST
INFO     program:program.py:30 main start
--- Logging error ---
Traceback (most recent call last):
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 435, in format
    return self._format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 431, in _format
    return self._fmt % record.__dict__
KeyError: 'trace_id'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 1084, in emit
    msg = self.format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 928, in format
    return fmt.format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 666, in format
    s = self.formatMessage(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 635, in formatMessage
    return self._style.format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 437, in format
    raise ValueError('Formatting field not found in record: %s' % e)
ValueError: Formatting field not found in record: 'trace_id'
Call stack:
  File "/opt/bb/lib/python3.8/runpy.py", line 194, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/opt/bb/lib/python3.8/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/opt/bb/lib/python3.8/site-packages/pytest/__main__.py", line 5, in <module>
    raise SystemExit(pytest.console_main())
  File "/opt/bb/lib/python3.8/site-packages/_pytest/config/__init__.py", line 192, in console_main
    code = main()
  File "/opt/bb/lib/python3.8/site-packages/_pytest/config/__init__.py", line 169, in main
    ret: Union[ExitCode, int] = config.hook.pytest_cmdline_main(
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 318, in pytest_cmdline_main
    return wrap_session(config, _main)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 271, in wrap_session
    session.exitstatus = doit(config, session) or 0
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 325, in _main
    config.hook.pytest_runtestloop(session=session)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 350, in pytest_runtestloop
    item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 114, in pytest_runtest_protocol
    runtestprotocol(item, nextitem=nextitem)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 133, in runtestprotocol
    reports.append(call_and_report(item, "call", log))
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 222, in call_and_report
    call = call_runtest_hook(item, when, **kwds)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 261, in call_runtest_hook
    return CallInfo.from_call(
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 341, in from_call
    result: Optional[TResult] = func()
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 262, in <lambda>
    lambda: ihook(item=item, **kwds), when=when, reraise=reraise
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 169, in pytest_runtest_call
    item.runtest()
  File "/opt/bb/lib/python3.8/site-packages/_pytest/python.py", line 1792, in runtest
    self.ihook.pytest_pyfunc_call(pyfuncitem=self)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/python.py", line 194, in pytest_pyfunc_call
    result = testfunction(**testargs)
  File "/mnt/c/playground/tests/test_program.py", line 10, in test_helper
    program.program()
  File "/mnt/c/playground/program.py", line 35, in program
    helper()
  File "/mnt/c/my_library/folder1/helper.py", line 5, in helper
    logger.info('LOG IN HELPER')
Message: 'LOG IN HELPER'
Arguments: ()
self_logger class is <class 'logging.Logger'>
INFO     folder1.helper:helper.py:5 LOG IN HELPER
--- Logging error ---
Traceback (most recent call last):
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 435, in format
    return self._format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 431, in _format
    return self._fmt % record.__dict__
KeyError: 'trace_id'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 1084, in emit
    msg = self.format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 928, in format
    return fmt.format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 666, in format
    s = self.formatMessage(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 635, in formatMessage
    return self._style.format(record)
  File "/opt/bb/lib/python3.8/logging/__init__.py", line 437, in format
    raise ValueError('Formatting field not found in record: %s' % e)
ValueError: Formatting field not found in record: 'trace_id'
Call stack:
  File "/opt/bb/lib/python3.8/runpy.py", line 194, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/opt/bb/lib/python3.8/runpy.py", line 87, in _run_code
    exec(code, run_globals)
  File "/opt/bb/lib/python3.8/site-packages/pytest/__main__.py", line 5, in <module>
    raise SystemExit(pytest.console_main())
  File "/opt/bb/lib/python3.8/site-packages/_pytest/config/__init__.py", line 192, in console_main
    code = main()
  File "/opt/bb/lib/python3.8/site-packages/_pytest/config/__init__.py", line 169, in main
    ret: Union[ExitCode, int] = config.hook.pytest_cmdline_main(
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 318, in pytest_cmdline_main
    return wrap_session(config, _main)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 271, in wrap_session
    session.exitstatus = doit(config, session) or 0
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 325, in _main
    config.hook.pytest_runtestloop(session=session)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/main.py", line 350, in pytest_runtestloop
    item.config.hook.pytest_runtest_protocol(item=item, nextitem=nextitem)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 114, in pytest_runtest_protocol
    runtestprotocol(item, nextitem=nextitem)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 133, in runtestprotocol
    reports.append(call_and_report(item, "call", log))
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 222, in call_and_report
    call = call_runtest_hook(item, when, **kwds)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 261, in call_runtest_hook
    return CallInfo.from_call(
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 341, in from_call
    result: Optional[TResult] = func()
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 262, in <lambda>
    lambda: ihook(item=item, **kwds), when=when, reraise=reraise
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/runner.py", line 169, in pytest_runtest_call
    item.runtest()
  File "/opt/bb/lib/python3.8/site-packages/_pytest/python.py", line 1792, in runtest
    self.ihook.pytest_pyfunc_call(pyfuncitem=self)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_hooks.py", line 493, in __call__
    return self._hookexec(self.name, self._hookimpls, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_manager.py", line 115, in _hookexec
    return self._inner_hookexec(hook_name, methods, kwargs, firstresult)
  File "/opt/bb/lib/python3.8/site-packages/pluggy/_callers.py", line 77, in _multicall
    res = hook_impl.function(*args)
  File "/opt/bb/lib/python3.8/site-packages/_pytest/python.py", line 194, in pytest_pyfunc_call
    result = testfunction(**testargs)
  File "/mnt/c/playground/tests/test_program.py", line 10, in test_helper
    program.program()
  File "/mnt/c/playground/program.py", line 38, in program
    helper()
  File "/mnt/c/my_library/folder1/helper.py", line 5, in helper
    logger.info('LOG IN HELPER')
Message: 'LOG IN HELPER'
Arguments: ()
INFO     folder1.helper:helper.py:5 LOG IN HELPER
INFO     program:program.py:40 main end

I'm not sure if my gap in knowledge lies in the Python logging module, Python global variables, importing a library, or all of the above. Any help would be appreciated.

python logging import global
Original Q&A
1

There are 1 best solutions below

2
tdelaney On

setLoggerClass sets the class used by future getLogger calls. If you import helper.py before setting a custom class, its module level getLogger gets the default Logger class, not CustomLogger, so there is no trace_id. Your formatter assumes that trace_id exists and will fail for loggers gotten before the custom class is set.

The obvious solution is to make sure your script sets its custom logger before import, like your first example. But this doesn't cover all of the bases. Suppose other code decides it wants a different logger and instantiates it directly.

Another solution is to add defaults when you create the formatter

formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s - %(trace_id)s', 
    defaults={"trace_id":trace_id})

And you could create your own custom formatter if you want more control of the output.

If the only reason for the custom logger is to set a static trace_id, it isn't really necessary. The formatter can handle it.

Related Questions in PYTHON

Related Questions in LOGGING

Related Questions in IMPORT

Related Questions in GLOBAL

Trending Questions

Popular # Hahtags

javascript python java c# php android html jquery c++ css ios sql mysql r reactjs node.js arrays c asp.net json

Popular Questions

.

Copyright © 2021 Jogjafile Inc.