I’m using Python logging, and for some reason, all of my messages are appearing twice.

I have a module to configure logging:

# BUG: It's outputting logging messages twice - not sure why - it's not the propagate setting.
def configure_logging(self, logging_file):
    self.logger = logging.getLogger("my_logger")
    self.logger.setLevel(logging.DEBUG)
    self.logger.propagate = 0
    # Format for our loglines
    formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
    # Setup console logging
    ch = logging.StreamHandler()
    ch.setLevel(logging.DEBUG)
    ch.setFormatter(formatter)
    self.logger.addHandler(ch)
    # Setup file logging as well
    fh = logging.FileHandler(LOG_FILENAME)
    fh.setLevel(logging.DEBUG)
    fh.setFormatter(formatter)
    self.logger.addHandler(fh)

Later on, I call this method to configure logging:

if __name__ == '__main__':
    tom = Boy()
    tom.configure_logging(LOG_FILENAME)
    tom.buy_ham()

And then within say, the buy_ham module, I’d call:

self.logger.info('Successfully able to write to %s' % path)

And for some reason, all the messages are appearing twice. I commented out one of the stream handlers, still the same thing. Bit of a weird one, not sure why this is happening…lol. Assuming I’ve missed something obvious.

Cheers, Victor

You are calling configure_logging twice (maybe in the __init__ method of Boy) : getLogger will return the same object, but addHandler does not check if a similar handler has already been added to the logger.

Try tracing calls to that method and eliminating one of these. Or set up a flag logging_initialized initialized to False in the __init__ method of Boy and change configure_logging to do nothing if logging_initialized is True, and to set it to True after you’ve initialized the logger.

If your program creates several Boy instances, you’ll have to change the way you do things with a global configure_logging function adding the handlers, and the Boy.configure_logging method only initializing the self.logger attribute.

Another way of solving this is by checking the handlers attribute of your logger:

logger = logging.getLogger('my_logger')
if not logger.handlers:
    # create the handlers and call logger.addHandler(logging_handler)

If you are seeing this problem and you’re not adding the handler twice then see abarnert’s answer here

From the docs:

Note: If you attach a handler to a logger and one or more of its ancestors, it may emit the same record multiple times. In general, you should not need to attach a handler to more than one logger – if you just attach it to the appropriate logger which is highest in the logger hierarchy, then it will see all events logged by all descendant loggers, provided that their propagate setting is left set to True. A common scenario is to attach handlers only to the root logger, and to let propagation take care of the rest.

So, if you want a custom handler on “test”, and you don’t want its messages also going to the root handler, the answer is simple: turn off its propagate flag:

logger.propagate = False

The handler is added each time you call from outside. Try Removeing the Handler after you finish your job:

self.logger.removeHandler(ch)

I’m a python newbie, but this seemed to work for me (Python 2.7)

while logger.handlers:
     logger.handlers.pop()

In my case I’d to set logger.propagate = False to prevent double printing.

In below code if you remove logger.propagate = False then you will see double printing.

import logging
from typing import Optional

_logger: Optional[logging.Logger] = None

def get_logger() -> logging.Logger:
    global _logger
    if _logger is None:
        raise RuntimeError('get_logger call made before logger was setup!')
    return _logger

def set_logger(name:str, level=logging.DEBUG) -> None:
    global _logger
    if _logger is not None:
        raise RuntimeError('_logger is already setup!')
    _logger = logging.getLogger(name)
    _logger.handlers.clear()
    _logger.setLevel(level)
    ch = logging.StreamHandler()
    ch.setLevel(level)
    # warnings.filterwarnings("ignore", "(Possibly )?corrupt EXIF data", UserWarning)
    ch.setFormatter(_get_formatter())
    _logger.addHandler(ch)
    _logger.propagate = False # otherwise root logger prints things again


def _get_formatter() -> logging.Formatter:
    return logging.Formatter(
        '[%(asctime)s] [%(name)s] [%(levelname)s] %(message)s')

A call to logging.debug() calls logging.basicConfig() if there are no root handlers installed. That was happening for me in a test framework where I couldn’t control the order that test cases fired. My initialization code was installing the second one. The default uses logging.BASIC_FORMAT that I didn’t want.

It seems that if you output something to the logger (accidentally) then configure it, it is too late. For example, in my code I had

logging.warning("look out)"

...
ch = logging.StreamHandler(sys.stdout)
root = logging.getLogger()
root.addHandler(ch)

root.info("hello")

I would get something like (ignoring the format options)

look out
hello
hello

and everything was written to stdout twice. I believe this is because the first call to logging.warning creates a new handler automatically, and then I explicitly added another handler. The problem went away when I removed the accidental first logging.warning call.

I was getting a strange situation where console logs were doubled but my file logs were not. After a ton of digging I figured it out.

Please be aware that third party packages can register loggers. This is something to watch out for (and in some cases can’t be prevented). In many cases third party code checks to see if there are any existing root logger handlers; and if there isn’t–they register a new console handler.

My solution to this was to register my console logger at the root level:

rootLogger = logging.getLogger()  # note no text passed in--that's how we grab the root logger
if not rootLogger.handlers:
        ch = logging.StreamHandler()
        ch.setLevel(logging.INFO)
        ch.setFormatter(logging.Formatter('%(process)s|%(levelname)s] %(message)s'))
        rootLogger.addHandler(ch)

I’m using the Python logging module, and would like to disable log messages printed by the third party modules that I import. For example, I’m using something like the following:

logger = logging.getLogger()
logger.setLevel(level=logging.DEBUG)
fh = logging.StreamHandler()
fh_formatter = logging.Formatter('%(asctime)s %(levelname)s %(lineno)d:%(filename)s(%(process)d) - %(message)s')
fh.setFormatter(fh_formatter)
logger.addHandler(fh)

This prints out my debug messages when I do a logger.debug(“my message!”), but it also prints out the debug messages from any module I import (such as requests, and a number of other things).

I’d like to see only the log messages from modules I’m interested in. Is it possible to make the logging module do this?

Ideally, I’d like to be able tell the logger to print messages from “ModuleX, ModuleY” and ignore all others.

I looked at the following, but I don’t want to have to disable/enable logging before every call to an imported function: logging – how to ignore imported module logs?

The problem is that calling getLogger without arguments returns the root logger so when you set the level to logging.DEBUG you are also setting the level for other modules that use that logger.

You can solve this by simply not using the root logger. To do this just pass a name as argument, for example the name of your module:

logger = logging.getLogger('my_module_name')
# as before

this will create a new logger and thus it wont inadvertently change logging level for other modules.

Obviously you have to use logger.debug instead of logging.debug since the latter is a convenience function that calls the debug method of the root logger.

This is mentioned in the Advanced Logging Tutorial. It also allows you to know which module triggered the log message in a simple way.

If you’re going to use the python logging package, it’s a common convention to define a logger in every module that uses it.

logger = logging.getLogger(__name__)

Many popular python packages do this, including requests. If a package uses this convention, it’s easy to enable/disable logging for it, because the logger name will be the same name as the package (or will be a child of that logger). You can even log it to the same file as your other loggers.

logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)

requests_logger = logging.getLogger('requests')
requests_logger.setLevel(logging.DEBUG)

handler = logging.StreamHandler()
handler.setLevel(logging.DEBUG)
logger.addHandler(handler)
requests_logger.addHandler(handler)

Not sure if this is appropriate to post, but I was stuck for a long time & wanted to help out anyone with the same issue, as I hadn’t found it anywhere else!

I was getting debug logs from matplotlib despite following the pretty straightforward documentation at the logging advanced tutorial and the troubleshooting. I was initiating my logger in main() of one file and importing a function to create a plot from another file (where I had imported matplotlib).

What worked for me was setting the level of matplotlib before importing it, rather than after as I had for other modules in my main file. This seemed counterintuitive to me so if anyone has insight into how you can set the config for a logger that hasn’t been imported yet I’d be curious to find out how this works. Thanks!

In my main file:

import logging
import requests
logger = logging.getLogger(__name__)
logger.setLevel(logging.DEBUG)
logging.getLogger('requests').setLevel(logging.DEBUG)

def main():
  ...

In my plot.py file:

import logging
logging.getLogger('matplotlib').setLevel(logging.WARNING)
import matplotlib.pyplot as plt

def generatePlot():
  ...

@Bakuriu quite elegantly explains the function. Conversely, you can use the getLogger() method to retrieve and reconfigure/disable the unwanted loggers.

I also wanted to add the logging.fileConfig() method accepts a parameter called disable_existing_loggers which will disable any loggers previously defined (i.e., in imported modules).

This disables all existing loggers, such as those created by imported modules, while still using the root logger (and without having to load an external file).

logging.config.dictConfig({
    'version': 1,
    'disable_existing_loggers': True,
})

Note that you need to import all modules you don’t want logged first! Otherwise those won’t be considered as “existing loggers”. It will then disable all loggers from those modules. This might lead you to also miss out on important errors!

For more detailed examples using related options for configuration, see https://gist.github.com/st4lk/6287746, and here is a (partially working) example using YAML for config with the coloredlog library.

You could use something like:

logging.getLogger("imported_module").setLevel(logging.WARNING)
logging.getLogger("my_own_logger_name").setLevel(logging.DEBUG)

This will set my own module’s log level to DEBUG, while preventing the imported module from using the same level.

Note: "imported_module" can be replaced with imported_module.__name__ (without quotes), and "my_own_logger_name" can be replaced by __name__ if that’s the way you prefer to do it.

I had the same problem. I have a logging_config.py file which I import in all other py files. In logging_config.py file I set root logger logging level to ERROR (by default its warning):

logging.basicConfig(
    handlers=[
        RotatingFileHandler('logs.log',maxBytes=1000, backupCount=2),
        logging.StreamHandler(), #print to console
    ],
    level=logging.ERROR
)

In other modules I import logging_config.py and declare a new logger and set its level to debug:

log = logging.getLogger(__name__)
log.setLevel(logging.DEBUG)

This way everything I log in my py files is logged, but stuff logged at debug and info level by imported modules like urllib, request,boto3 etc is not logged. If there is some error in those import module then its logged, since I set root loggers level to ERROR.

Another thing to consider is the propagate property of the Logger class.

For example, py-suds library for handling soap calls, even put to ERROR

logging.getLogger('suds.client').setLevel(logging.ERROR)
logging.getLogger('suds.transport').setLevel(logging.ERROR)
logging.getLogger('suds.xsdschema').setLevel(logging.ERROR)
logging.getLogger('suds.wsdl').setLevel(logging.ERROR)

logs logs about a module called sxbasics.py creationg a huge amount of logs

that because the propagation of the logs is True by default, setting to False, instead, i recovered 514MB of logs.

import logging
logging.getLogger("suds").propagate = False
logging.getLogger('suds.client').setLevel(logging.ERROR)
logging.getLogger('suds.transport').setLevel(logging.ERROR)
logging.getLogger('suds.xsdschema').setLevel(logging.ERROR)
logging.getLogger('suds.wsdl').setLevel(logging.ERROR)