Python logging is printed twice (1 formatted, 1 not formatted) when calling other python packages

Question

I have my own logging setup:

def init_logger(level, name):
    """
    Create logger and its handlers, and set them to the given level
    """
    from logging.handlers import RotatingFileHandler
    logger = logging.getLogger(name)

    # set level of logger
    logger.setLevel(level)

    # define custom formats
    formatterFile = logging.Formatter('  * [%(asctime)s]:[%(levelname)s] %(message)s', '%Y-%m-%d %H:%M:%S')
    formatterStream = logging.Formatter('  * [%(asctime)s] %(message)s', '%Y-%m-%d %H:%M:%S')

    # Create handler writing to 'logfile'.
    logfile_handler = RotatingFileHandler("mylog-file.log", 'w', 10000000, 5)
    logfile_handler.setLevel(logging.INFO)
    logfile_handler.setFormatter(formatterFile)
    logger.addHandler(logfile_handler)

    # Add handler for stdout
    stream_handler = logging.StreamHandler(sys.stdout)
    stream_handler.setLevel(logging.DEBUG)  
    stream_handler.setFormatter(formatterStream)
    logger.addHandler(stream_handler)

I'm initializing this logger in my main function, with the name "myname". Then I call it to print some information. In my main script I also call for submodules. Each of these submodules have:

#submodule1.py
import logging
logger = logging.getLogger("myname.mod1")
def function():
    logger.warning("warning !!")

So, in my main script, I have:

#myscript.py

import logging
import submodule1

def main():
    init_logger(logging.DEBUG, 'myname')
    logger = logging.getLogger('myname')
    logger.info("some information")
    submodule1.function()

With that, I have the expected lines in stdout, with expected format, and I also have a file called "mylog-file.log", containing the same information with its expected format. So, until here, everything works perfectly.

Then, I import another python package (from pip install known_package), and I call one of its functions. This other package is using import logging and then logging.error("message") (or any other level). When I call it from my script, the information given by this other tool are not printed (because they don't have a subparser of mine), so this is OK.

BUT, when I recall my logger after this call to known_package, I get, in stdout, every log information twice: first with my own format, and then with the default format (the one used in known_package).

To sum-up, here is my main script:

#myscript.py

import logging
import submodule1
import knownpackage

def main():
    init_logger(logging.DEBUG, 'myname')
    logger = logging.getLogger('myname')
    logger.info("some information")
    submodule1.function()

    knowpackage.say_something("smt") # where there is a line like `logging.info("smt")`

    logger.info("more info")
    logger.warning("more warning")
    submodule1.function()

And here is the output:

Writes:
* [2018-07-25 14:41:23] some information 
* [2018-07-25 14:41:23] warning!!
* [2018-07-25 14:41:23] more info
INFO:myname:more info
* [2018-07-25 14:41:23] more warning
WARNING:myname:more warning
* [2018-07-25 14:41:23] warning!!
WARNING:myname.mod1: warning !!

And, in my logfile, I have what I expect:

* [2018-07-25 14:41:23]: INFO some information 
* [2018-07-25 14:41:23]: WARNING warning!!
* [2018-07-25 14:41:23]: INFO more info
* [2018-07-25 14:41:23]: WARNING more warning
* [2018-07-25 14:41:23]: WARNING warning!!

Anybody has an idea why it duplicates my outputs in stdout with the other format while calling an external package?

Thank you!

Python logging is printed twice (1 formatted, 1 not formatted) when calling other python packages

0 Answers0