Python logging to multiple handlers, at different log levels?

Question

Folks,

I'm scratching my head on a python logging config that I can't get right.

Let's say I have the following package installed:

mypackage/    data/mypackage.logging.conf    module1.py    module2.py    scripts/main.py 

As the script can be used interactively or run from a crontab, I have the following requirements:

1. no print statements, everything goes through logging;

2. log using a timedRotatingFileHandler, always at DEBUG level;

3. log using a mailinglogger.SummarisingLogger, always at INFO level;

4. log to console, with level set by default to INFO or overridden through a command-line option.

Problem is, I can change the log level through the command-line and the console log level is changed accordingly, but the other handlers are also changed, which I don't want... :-/

In a logging config file, I'm not sure I understand the precedence between the root logger's level, other loggers' level and handlers' level settings.

Here is some sample code. Any clues will be appreciated :-)

# mypackage/data/mypackage.logging.conf [loggers] root,mypackage  [handlers] keys=consoleHandler,timedRotatingFileHandler,summarisingHandler  [formatters] keys=simpleFormatter,consoleFormatter,mypackageFormatter  [logger_root] #level=INFO handlers=consoleHandler  [logger_mypackage] #level=INFO handlers=timedRotatingFileHandler,summarisingHandler qualname=mypackage  [handler_consoleHandler] class=StreamHandler #level=INFO formatter=consoleFormatter args=(sys.stdout,)  [handler_timedRotatingFileHandler] class=logging.handlers.TimedRotatingFileHandler level=DEBUG formatter=mypackageFormatter args=('mypackage.log', 'M', 1, 5)  [handler_summarisingHandler] class=mailinglogger.SummarisingLogger level=INFO formatter=mypackageFormatter args=('[email protected]', ('[email protected]',), 'relay.somewhere.com') 

---

#mypackage/scripts/main.py: import logging import logging.config import os import sys  import mypackage.module1 import mypackage.module2  logging.config.fileConfig('data/mypackage.logging.conf') log = logging.getLogger(__name__)  if __name__ == '__main__':     loglevel = 'INFO'     if len(sys.argv) > 1:         loglevel = sys.argv[1].upper()      logging.getLogger('').setLevel(getattr(logging, loglevel))     # or logging.getLogger('mypackage').setLevel(getattr(logging, loglevel)) ?      mypackage.module1.do_something()     mypackage.module2.do_something_else() 

---

#mypackage/module1.py: import logging  log = logging.getLogger(__name__) log.addHandler(NullHandler())  def do_something():     log.debug("some debug message from:" + __name__)     log.info("some info message from:" + __name__)     log.error("some error message from:" + __name__) 

---

#mypackage/module2.py: import logging  log = logging.getLogger(__name__) log.addHandler(NullHandler())  def do_something_else():     log.debug("some debug message from:" + __name__)     log.info("some info message from:" + __name__)     log.error("some error message from:" + __name__) 

---

UPDATE 1

In the meantime, I discovered this answer and successfully modified my code this way:

#mypackage/scripts/main.py: import logging import logging.config import os import sys import mailinglogger  import mypackage.module1 import mypackage.module2  def main():     # get the console log level from the command-line     loglevel = 'INFO'     if len(sys.argv) > 1:         loglevel = sys.argv[1].upper()      # create formatters     simple_formatter = logging.Formatter("%(name)s:%(levelname)s: %(message)s")     detailed_formatter = logging.Formatter("%(asctime)s %(name)s[%(process)d]: %(levelname)s - %(message)s")      # get a top-level "mypackage" logger,     # set its log level to DEBUG,     # BUT PREVENT IT from propagating messages to the root logger     #     log = logging.getLogger('mypackage')     log.setLevel(logging.DEBUG)     log.propagate = 0      # create a console handler     # and set its log level to the command-line option      #      console_handler = logging.StreamHandler(sys.stdout)     console_handler.setLevel(getattr(logging, loglevel))     console_handler.setFormatter(simple_formatter)      # create a file handler     # and set its log level to DEBUG     #     file_handler = logging.handlers.TimedRotatingFileHandler('mypackage.log', 'M', 1, 5)     file_handler.setLevel(logging.DEBUG)     file_handler.setFormatter(detailed_formatter)      # create a mail handler     # and set its log level to INFO     #     mail_handler = mailinglogger.SummarisingLogger(         '[email protected]', ('[email protected]',), 'relay.somewhere.com')     mail_handler.setLevel(logging.INFO)     mail_handler.setFormatter(detailed_formatter)      # add handlers to the "mypackage" logger     #     log.addHandler(console_handler)     log.addHandler(file_handler)     log.addHandler(mail_handler)      # let the modules do their stuff      # and log to the "mypackage.module1" and "mypackage.module2" loggers     #     mypackage.module1.do_something()     mypackage.module2.do_something_else()   if __name__ == '__main__':     main() 

Now, I'll try to translate this in a logging.config file...

---

UPDATE 2

Here is the best logging config and code combination I found.

In the mypackage.logging.conf file, the "mypackage" logger is:

• set up only with the file and email handlers;
• its propagate is set to false;
• its level is set to DEBUG;
• while the file and email handlers are respectively set to INFO and DEBUG.

---

#mypackage/data/mypackage.logging.conf [loggers] keys=root,mypackage  [handlers] keys=consoleHandler,timedRotatingFileHandler,summarisingHandler  [formatters] keys=simpleFormatter,consoleFormatter,mypackageFormatter  [logger_root] #level=INFO handlers=consoleHandler  [logger_mypackage] level=DEBUG handlers=timedRotatingFileHandler,summarisingHandler qualname=mypackage propagate=0  [handler_consoleHandler] class=StreamHandler #level=INFO formatter=consoleFormatter args=(sys.stdout,)  [handler_timedRotatingFileHandler] class=logging.handlers.TimedRotatingFileHandler level=DEBUG formatter=mypackageFormatter args=('mypackage.log', 'M', 1, 5)  [handler_summarisingHandler] class=mailinglogger.SummarisingLogger level=INFO formatter=mypackageFormatter args=('[email protected]', ('[email protected]',), 'relay.somewhere.com')  [formatter_consoleFormatter] format=%(levelname)s: %(message)s datefmt=  [formatter_mypackageFormatter] format=%(asctime)s %(name)s[%(process)d]: %(levelname)s - %(message)s datefmt= 

---

In the script:

1. the logging config is read;

2. a console_formatter is (re-)created;

3. a console handler is created with the log level from the command-line option, then added to the "mypackage" logger.

---

import logging import logging.config import os import sys  import mypackage.module1 import mypackage.module2  def setup_logging(loglevel):     #     # load logging config from file     #     logging.config.fileConfig('data/mypackage.logging.conf')      # (re-)create formatter     console_formatter = logging.Formatter("%(name)s:%(levelname)s: %(message)s")      # create a console handler     # and set its log level to the command-line option      #      console_handler = logging.StreamHandler(sys.stdout)     console_handler.setFormatter(console_formatter)     console_handler.setLevel(getattr(logging, loglevel))      # add console handler to the pre-configured "mypackage" logger     #     logger = logging.getLogger('mypackage')     logger.addHandler(console_handler)   def main():     # get the console log level from the command-line     loglevel = 'INFO'     if len(sys.argv) > 1:         loglevel = sys.argv[1].upper()      # load logging config and setup console handler     #     setup_logging(loglevel)      # log from the script to the "mypackage.scripts.main" logger     #     log = logging.getLogger(__name__)     log.debug("some debug message from:" + __name__)     log.info("some info message from:" + __name__)     log.error("some error message from:" + __name__)      # let the modules do their stuff      # and log to the "mypackage.module1" and "mypackage.module2" loggers     #     mypackage.module1.do_something()     mypackage.module2.do_something_else()  if __name__== '__main__':     main() 

---

Things would be simpler if the handlers were "addressable" by name when loaded from a config file.

Then, we could have the mypackage console handler set up in the config file and its log level changed in the code like this:

def setup_logging(loglevel):     logging.config.fileConfig('data/mypackage.logging.conf')      logger = logging.getLogger('mypackage')     console_handler = logger.getHandler('consoleHandler')     console_handler.setLevel(getattr(logging, loglevel)) 

There would no need to re-create a formatter either...

(last update: yes, I'm aware of https://docs.python.org/3/library/logging.config.html#incremental-configuration, but in this case, I'm stuck with Python 2.6... :-)

Answer 1

Use dictConfig. Here is an example of logging to multiple files with separate handles in dictConfig. This isn't exactly what you are looking for, but you could modify this example and simply change the level of each handler that you are looking to use.

import os, logging from logging.config import dictConfig  FORMAT = "%(asctime)s {app} [%(thread)d] %(levelname)-5s %(name)s - %(message)s. [file=%(filename)s:%(lineno)d]" DATE_FORMAT = None   def setup_logging(name, level="INFO", fmt=FORMAT):     formatted = fmt.format(app=name)     log_dir = r'C:/log_directory'     if not os.path.exists(log_dir):         os.makedirs(log_dir)      logging_config = {         "version": 1,         'disable_existing_loggers': False,         "formatters": {             'standard': {                 'format': formatted             }         },         "handlers": {             'default': {                 'class': 'logging.StreamHandler',                 'formatter': 'standard',                 'level': level,                 'stream': 'ext://sys.stdout'             },             'file': {                 'class': 'logging.handlers.TimedRotatingFileHandler',                 'when': 'midnight',                 'utc': True,                 'backupCount': 5,                 'level': level,                 'filename': '{}/log1.log'.format(log_dir),                 'formatter': 'standard',             },             'file2': {                 'class': 'logging.handlers.TimedRotatingFileHandler',                 'when': 'midnight',                 'utc': True,                 'backupCount': 5,                 'level': level,                 'filename': '{}/log2.log'.format(log_dir),                 'formatter': 'standard',             }         },         "loggers": {             "": {                 'handlers': ['default', 'file'],                 'level': level             },             "second_log": {                 'handlers': ['default', 'file2'],                 'level': level             }         }     }      dictConfig(logging_config)  log.setup_logging(name="log-name", level=LEVEL logger = logging.getLogger(__name__) second_logger = logging.getLogger('second_log') second_logger.propagate = False