CODEWITHSUNDEEP
pythonlogging
Arthur
Arthur

Reputation: 117

Per-object logging across multiple modules in Python

I have a Python code that implements a class used to process independent data sets. For each dataset I instantiate an object from the class, which processes the data set. I would like to implement a logging feature that displays the log messages both in the console and in a log file that is stored with each data set.

I have implemented a root logger at the module level and a specific logger with a FileHandler when each of the objects is created. It works to log some of the information for what is happening inside of the class but I am also using another toolbox module and what happens there is only logged in the console but not in the log files.

To illustrate the issue I have implemented a demonstration module:

├──log
│  ├── __init__.py
│  ├── my_object.py
│  ├── toolbox.py

Content of __init__.py:

import logging

logging.basicConfig(format='%(name)12s - %(levelname)5s - %(message)s')
_log = logging.getLogger(__name__)
_log.setLevel(logging.DEBUG)

Content of my_object.py:

import logging
from . import toolbox

class MyObject():
    def __init__(self, name):
        self._name = name

        # configure logging
        logger = logging.getLogger(name)
        logger.setLevel(logging.DEBUG)
        if logger.hasHandlers():
            for hdlr in logger.handlers:
                logger.removeHandler(hdlr)

        handler = logging.FileHandler('/home/user/Desktop/test/{}.log'.format(name), mode='w', encoding='utf-8')
        formatter = logging.Formatter('%(name)12s - %(levelname)5s - %(message)s')
        handler.setFormatter(formatter)
        logger.addHandler(handler)

        self._logger = logger


    def do_something(self):
        self._logger.info('{} is doing something'.format(self._name))

        toolbox.use_tool(self._name)

Content of toolbox.py:

import logging

_log = logging.getLogger(__name__)


def use_tool(name):
    _log.info('Using some tool for {}'.format(name))

Then, I run this:

import log
from log.my_object import MyObject

obj = MyObject('object1')
obj.do_something()

And here is what I get in the console:

     object1 -  INFO - object1 is doing something
 log.toolbox -  INFO - Using some tool for object1

And here is what I get in the /home/user/Desktop/test/object1.log file:

     object1 -  INFO - object1 is doing something

How do I get the log.toolbox to also show up in the object1.log file?

Upvotes: 0

Views: 1182

Answers (1)

Kacperito
Kacperito

Reputation: 1367

The culprit is in how you call the getLogger function. There are two times you do it:

  1. logger = logging.getLogger(name) inside my_object.py
  2. _log = logging.getLogger(__name__) inside toolbox.py

If you compare the objects returned by those calls, these are 2 separate objects (you can print their addresses via print(id(obj))). This is why logger never calls the line inside the toolbox - there is a different logger (_log) in there!

To fix your error, simply give your loggers the same name - for example "global":

  1. logger = logging.getLogger("global")
  2. _log = logging.getLogger("global")

The output of the file is now as follows:

global -  INFO - object1 is doing something
global -  INFO - Using some tool for object1

In your specific example, you could adjust the code in toolbox.py to:

import logging


def use_tool(name):
    _log = logging.getLogger(name)
    _log.info('Using some tool for {}'.format(name))

and leave the logger inside my_object.py as it is (logger = logging.getLogger(name)). If you then do the following in main.py:

obj = MyObject('object1')
obj2 = MyObject('object2')
obj.do_something()
obj2.do_something()

you will end up with 2 logging files:

object1.log

object1 -  INFO - object1 is doing something
object1 -  INFO - Using some tool for object1

object2.log

object2 -  INFO - object2 is doing something
object2 -  INFO - Using some tool for object2

Upvotes: 1

Related Questions