Per-object logging across multiple modules in Python

Question

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?

Kacperito · Accepted Answer · 2019-09-06 17:32:32Z

1

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

logger = logging.getLogger(name) inside my_object.py
_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":

logger = logging.getLogger("global")
_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

edited Sep 6, 2019 at 17:32

answered Sep 5, 2019 at 22:00

Kacperito

1,3771 gold badge14 silver badges30 bronze badges

Sign up to request clarification or add additional context in comments.

3 Comments

Arthur Over a year ago

This solution doesn't work if object1 and object2 are created together and obj1.do_something() and obj2.do_something() are called afterwards. In that case object1.log is empty and object2.log contains all the logs for both objects.

Kacperito Over a year ago

That's beacuse you are using the same logger object. You need to pass the loggers around - you should get / update logger reference in use_tool. I will update my answer to include a more robust solution when im home later.

Kacperito Over a year ago

@Arthur I have updated my answer with a solution following your exact example.

Collectives™ on Stack Overflow

Per-object logging across multiple modules in Python

1 Answer 1

3 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

3 Comments

Your Answer

Sign up or log in

Post as a guest

Related