Using Logging in Multiple Modules

Using logging in multiple modules

Best practice is, in each module, to have a logger defined like this:

import logging
logger = logging.getLogger(__name__)

near the top of the module, and then in other code in the module do e.g.

logger.debug('My message with %s', 'variable data')

If you need to subdivide logging activity inside a module, use e.g.

loggerA = logging.getLogger(__name__ + '.A')
loggerB = logging.getLogger(__name__ + '.B')

and log to loggerA and loggerB as appropriate.

In your main program or programs, do e.g.:

def main():
    "your program code"

if __name__ == '__main__':
    import logging.config
    logging.config.fileConfig('/path/to/logging.conf')
    main()

or

def main():
    import logging.config
    logging.config.fileConfig('/path/to/logging.conf')
    # your program code

if __name__ == '__main__':
    main()

See here for logging from multiple modules, and here for logging configuration for code which will be used as a library module by other code.

Update: When calling fileConfig(), you may want to specify disable_existing_loggers=False if you're using Python 2.6 or later (see the docs for more information). The default value is True for backward compatibility, which causes all existing loggers to be disabled by fileConfig() unless they or their ancestor are explicitly named in the configuration. With the value set to False, existing loggers are left alone. If using Python 2.7/Python 3.2 or later, you may wish to consider the dictConfig() API which is better than fileConfig() as it gives more control over the configuration.

Using python logging from multiple modules with writing to a file and RotatingFileHandler

I believe you are getting your logging setup wrong. The recommended way to setup logging is to not define any handlers nor logging levels into the modules, but define all the configuration in the main file.

For example in module1.py:

import logging

logger = logging.getLogger(__name__)

# use logger.info/logger.debug etc.

In module2.py you put exactly the same code:

import logging

logger = logging.getLogger(__name__)

# use logger.info/logger.debug etc.

Note that __name__ is the module name, so it will be something like package.module1 or package.module2. Using dotted names automatically creates hierarchies of loggers, so that's why it's customary to just use the __name__ of the module to get the logger.

There is no need for module1 and module2 to contain anything else related to logging. They should not decide where the logging output goes or its level, because this is something that who launches the application should control. Hence it is best handled in the main executable.

Now in your main executable you define your handlers:

import logging, logging.handlers

fh = logging.handlers.RotatingFileHandler('log/pokerprogram.log', maxBytes=1000000, backupCount=10)
fh.setLevel(logging.DEBUG)
fh2 = logging.handlers.RotatingFileHandler('log/pokerprogram_info_only.log', maxBytes=1000000, backupCount=5)
fh2.setLevel(logging.INFO)
er = logging.handlers.RotatingFileHandler('log/errors.log', maxBytes=2000000, backupCount=2)
er.setLevel(logging.WARNING)
ch = logging.StreamHandler(sys.stdout)
ch.setLevel(1)
fh.setFormatter(logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s'))
fh2.setFormatter(logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s'))
er.setFormatter(logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s'))
ch.setFormatter(logging.Formatter('%(name)s - %(levelname)s - %(message)s'))

And finally you just add the handlers to the root logger and set the root logger's level to the lowest level among the handlers:

root = logging.getLogger()
root.setLevel(logging.DEBUG)
# alternatively:
# root.setLevel(min([fh.level, fh2.level, ch.level, er.level])

root.addHandler(fh)
root.addHandler(fh2)
root.addHandler(ch)
root.addHandler(er)

This works due to the hierarchical nature of loggers. When module1.logger.debug is called, if the logger has no handlers it will pass the log record to its parent logger, which will continue to do so up until the root logger, which finally uses its handlers to handle the log record.

It is necessary to also set the root logger level because it defaults to WARNING, while other loggers default to NOTSET (which causes the delegation mentioned before).

Alternatively you add the same handlers to both module loggers explicitly:

from <package> import module1, module2

module1.logger.setLevel(logging.DEBUG)
module2.logger.setLevel(logging.DEBUG)

module1.logger.addHandler(fh)
module2.logger.addHandler(fh)
module1.logger.addHandler(fh2)
module2.logger.addHandler(fh2)
module1.logger.addHandler(ch)
module2.logger.addHandler(ch)
module1.logger.addHandler(er)
module2.logger.addHandler(er)

There is no harm in adding the same handler object to multiple loggers. This makes sure that the handlers do not try to concurrently rotate the file.

Python logging - multiple modules

It is correct to configure logging only once for the whole project, as you first tried, not each package separately.

What you did wrong is you configured the logger for the current module only:

logger = logging.getLogger(__name__)

Instead of that, you want to configure the root logger:

root_logger = logging.getLogger()
root_logger.setLevel(logging.INFO)

# ...

root_logger.addHandler(logger_handler)
root_logger.addHandler(console_handler)

The configuration done for the root logger applies to every logger which does not explicitly override it.

Then you should use the specific logger when actually logging:

logger = logging.getLogger(__name__)

logger.warning("I am warning you about %s", something)

Python logging for multiple modules

As someone who has spent far too many hours learning how to do this the past few days, I think I'm finally there and will try to point you to what helped me.

This answer from the current logging maintainer explains how to implement with multiple modules very well: https://stackoverflow.com/a/15735146/2574074

And I found this answer very helpful as well:
https://stackoverflow.com/a/4150322/2574074

To your specific problem, essentially, if all of your loggers have the same configuration (as it appears they do), then I think the easiest way for you would be to establish and configure your root logger in your config as follows:

[loggers]
keys=root

[handlers]
keys=consoleHandler,rotatingFileHandler

[formatters]
keys=defaultFormatters

[logger_root]
level=DEBUG
handlers=consoleHandler,rotatingFileHandler

[handler_consoleHandler]
... your consoleHandler configuration ...

[handler_rotatingFileHandler]
... your rotatingFileHandler configuration ...

... 

You will not actually log to the root logger directly, however.

Instead, at the top of each of your modules, add this:

import logging
logger = logging.getLogger(__name__)

Or you could use whatever name you want:

import logging
logger = logging.getLogger(xx_utils)

This establishes a new logger for each module (i.e., no need to create a separate loggerUtils class) and because you are not setting level, each of these loggers will have level of NOTSET by default and so logs to these loggers will be passed to the parent logger(s), eventually reaching the root logger.

Important tip, which caused me trouble, is make sure you establish a logger for your main module in the same way as your other sub-modules, but be sure to do this after you've read in your config file and established/configured the root logger. Otherwise you'll automatically establish the root logger by calling logger = logging.getLogger(main) or logger = logging.getLogger(__name__) if running main.py as a script, but it will not have the configuration you want.

Logging from multiple modules to the same log file

In order for the loggers of imported1 and import2 to know the original logger you created, they need to be its children.

In python loggers are arranged by '.', so logger a.b.c is a child of logger a.b which is a child of a

You can achieve what you want this way:

In log_test.py

logger = logging.getLogger('my_logger')

In imported_1.py

logger = logging.getLogger('my_logger.' + __name__) # will be my_logger.imported_1

In imported_2.py

logger = logging.getLogger('my_logger.' + __name__) # will be my_logger.imported_2

You can check out more here
https://docs.python.org/3/howto/logging-cookbook.html#using-logging-in-multiple-modules

How to log from multiple modules python logging

The loggers are organised hierarchically by name. When a log message is logged, it will traverse the loggers looking for handlers, starting with the logger you logged the message at, moving up the hierarchy.
The hierarchy follows the names, so since you are naming your loggers by module names, a message logged to the module "x.y.z", will first try finding handlers attached to "x.y.z", then "x.y", "x" and finally the root logger, "".

So to log all messages (as you normally want to do), you need to add a handler to the root logger instead of the module logger.

LOG_FILENAME = 'check.log'
rootlogger = logging.getLogger() # No name here will return you the root logger
formatter =logging.Formatter("[%(asctime)s] %(levelname)s [ % (name)s.%(funcName)s:%(lineno)d] - %(message)s")
rootlogger.setLevel(logging.DEBUG)
handler = RotatingFileHandler(LOG_FILENAME, maxBytes=2000, backupCount=5)
handler.setFormatter(formatter)
rootlogger.addHandler(handler)

To manage your logging configuration, I would recommend you not set handlers and formatters manually, but instead use the logging.config module.

How to use logging.getLogger(__name__) in multiple modules

As pointed out by @shmee in this answer, the logger hierarchy must be defined explicitly in the logger name, using dot-notation. That is, if the logger name in main_module.py is e.g. 'a', then the logger name in auxiliary_module.py must be 'a.b' (not just 'b'), in order for it to inherit the configuration of logger 'a'. This is also mentioned in the getLogger() documentation.

However, this should be taken care of automatically when using __name__, as noted in the logging how-to:

This means that logger names track the package/module hierarchy, and it’s intuitively obvious where events are logged just from the logger name.

The thing is, for this to work, you need to use __name__ in the correct way, and I did not do that.

The problem in my example is in the organization of the files in the cookbook-example package folder:

Both the main module and the auxiliary module are at the same level (i.e. in the same folder). So, as explained here, the __name__ for the main module will then be '__main__' (as it is the top-level script), and the __name__ for the auxiliary module will be 'auxiliary_module' (i.e. the filename), NOT '__main__.auxiliary_module'.

As a result, the logger in the auxiliary module will be a child of the root logger, not a child of the '__main__' logger, and it will thus inherit the root logger configuration (which still has the default logging level WARNING) instead of the configuration specified in the main module.

So, to make the example work, we have several options:

1. Replace getLogger(__name__) in the main module by getLogger().
   This will apply the config to the root logger and therefore also to
   the auxiliary module logger, as suggested by @shmee.

2. Replace getLogger(__name__) in the auxiliary module by
   getLogger('__main__.' + __name__). The result will be equivalent
   to the original cookbook-example (except that the main logger is now called
   '__main__' instead of 'spam_application').

Logging multiple modules/functions with different formats in the simplest way

Instantiating from basicConfig is not as simple as
loggerFunc1 = logging.basicConfig(level=logging.WARNING)...
However it's possible to log by defining fh as FileHandler and passing it as a list's element to the handlers function like the following:

func1.py

# Should be added to each file (include main.py).
import logging
from pathlib import Path

# Gets the Absolute path of the main.log
LogFileAPath = Path('./main.log').resolve()
fh = logging.FileHandler(LogFileAPath, encoding='utf-8')
logging.basicConfig(
    level=logging.INFO,
    format=f"\n{''*50}\n%(asctime)s ⚠ #%(levelname)s %(message)s",
    datefmt='%Y-%m-%d %H:%M:%S',
    handlers=[fh]
    )
# use __name__ to automatically detect the module name, or any optional string.
logger = logging.getLogger(__name__)
# Stop getting duplicate logs from both functions
logger.propagate = False
#br>
def firstfunc(fpar):
    try:
        firstvar = secondfunc(sfunc)
    except Exception as e:
        logger.exception(e)
    ...

Or you should add logger in each file using only one basicConfig in main.py...

main.py

import logging

logging.basicConfig(
    level=logging.WARNING,
    filename='./main.log',
    filemode='a+',
    encoding='utf-8',
    format=f"\n{''*50}\n %(asctime)s ⚠ #%(levelname)s %(message)s",
    datefmt='%Y-%m-%d %H:%M:%S')

func1.py

# Should be added to each function file.
import logging
from pathlib import Path

# Gets the Absolute path of the main.log
LogFileAPath = Path('./main.log').resolve()
fh = logging.FileHandler(LogFileAPath, encoding='utf-8')
fh.setLevel(logging.INFO)
formatter = logging.Formatter(f"{''*50}\n⚠ #%(levelname)s %(message)s")
fh.setFormatter(formatter)
logger = logging.getLogger(__name__)
logger.addHandler(fh)
# Prevents getting duplicate logs
logger.propagate = False
#br>
def firstfunc(fpar):
    try:
        firstvar = secondfunc(sfunc)
    except Exception as e:
        logger.exception(e)
    ...

func2.py

import logging
from pathlib import Path

LogFileAPath = Path('./main.log').resolve()
fh = logging.FileHandler(LogFileAPath, encoding='utf-8')
fh.setLevel(logging.INFO)
formatter = logging.Formatter(f"{''*50}\n⚠ #%(levelname)s %(message)s")
fh.setFormatter(formatter)
logger = logging.getLogger(__name__)
logger.addHandler(fh)
logger.propagate = False

def secondfunc(spar):
    try:
        secondvar = thirdfunc(tfunc)
    except Exception as e:
        logger.exception(e)
    ...

⋮

⚠

Pay attention to the file directory, if your main.py is outside of the Handlers folder, you should use ./main.log in FileHandler, if you're defining the log file inside the Handlers folder, you should use ../main.log, (⭐: use Path().resolve()). otherwise you'll have two separate log files in two different directories.

Can't get my head around logging in multiple modules

• What am I doing wrong?

You're configuring one logger and using a different logger. When you call logger() in the main script, the returned logger is the __main__ because that is what __name__ evaluates to from the main script. When you call logging.getLogger() from log_module.py, you get a module named log_module.

• What should I be doing instead?

Either explicitly configure the log_module logger by calling a configure_logger function that accepts a logger instance as an argument, or configure the root logger (get the root logger by calling logging.getLogger() with no arguments). The root logger's configuration will be inherited by the others.

• Does this need to be this convoluted just to get logs from multiple modules?

Once you understand that loggers are a hierarchy, it's a little simpler conceptually. It works nicely when you have nested packages/modules.

• logging.getLogger() (root logger)
  
  • logging.getLogger('foo') (inherits configuration from root logger)
    
    • logging.getLogger('foo.bar') (inherits configuration from foo)
    • logging.getLogger('foo.baz') (inherits configuration from foo)

---

Related Topics