CODEWITHSUNDEEP
pythonlogging
llevar
llevar

Reputation: 785

Why is my configured logger not being used?

Reading the logging HOWTO (https://docs.python.org/3/howto/logging.html) I came away under the impression that if I configured a logger, then I could subsequently request my logger from the factory via logging.getLogger() and python would know how to get the right logger (the one I configured) and everything would just auto-work, i.e. I wouldn't need to pass the configured logger instance around my code, I could just ask for it wherever I needed it. Instead, I'm observing something different.

File log_tester.py:

from util.logging_custom import SetupLogger
import logging
import datetime

def test():
    logger = logging.getLogger()
    logger.debug("In test()")

def main():
    logger = SetupLogger("logger_test")
    logger.setLevel(logging.DEBUG)
    logger.info(f"now is {datetime.datetime.now()}", )
    logger.debug("In main()")
    test()


if __name__ == '__main__':
    main()

File util/logging_custom.py:

import os
import time
import logging
from logging.handlers import RotatingFileHandler

def SetupLogger(name_prefix):
    if not os.path.exists("log"):
        os.makedirs("log")

    recfmt = logging.Formatter('%(asctime)s.%(msecs)03d %(levelname)s %(message)s')

    handler = RotatingFileHandler(time.strftime(f"log/{name_prefix}.log"),maxBytes=5000000, backupCount=10)
    handler.setFormatter(recfmt)
    handler.setLevel(logging.DEBUG)

    logger = logging.getLogger(f"{name_prefix} {__name__}")
    logger.addHandler(handler)

    return logger

When I run this code only the debug statement that is in main() ends up in the log file. The debug statement from test() ends up I'm not sure where exactly.

Contents of log/logger_test.log:

2019-02-07 09:14:39,906.906 INFO now is 2019-02-07 09:14:39.906848
2019-02-07 09:14:39,906.906 DEBUG In main()

My expectation was that In test() would also show up in my log file. Have I made some assumptions about how python logging works that are untrue? How do I make it so that all of the logging in my program (which has many classes and modules) goes to the same configured logger? Is that possible without passing around a logger instance everywhere, after it's created in main()?

Thanks.

Upvotes: 0

Views: 483

Answers (2)

olinox14
olinox14

Reputation: 6643

The getLogger function will return a the logger by its name (kind of a singleton):

  • if it doesn't exist, it creates it
  • If it already exist, it returns it

Then what you could do is:

util/logging_custom.py

def SetupLogger(logger_name, level=logging.INFO):
    if not os.path.exists("log"):
        os.makedirs("log")

    recfmt = logging.Formatter('%(asctime)s.%(msecs)03d %(levelname)s %(message)s')
    handler = RotatingFileHandler(time.strftime(f"log/{logger_name}.log"),maxBytes=5000000, backupCount=10)
    handler.setFormatter(recfmt)
    handler.setLevel(level)

    logger = logging.getLogger(logger_name)
    logger.addHandler(handler)

    # no need to return the logger, I would even advice not to do so

log_tester.py

from util.logging_custom import SetupLogger
import logging
import datetime

logger = SetupLogger("logger_test", logging.DEBUG)  # you only need to run this once, in your main script.
logger = logging.getLogger("logger_test")

def test():
    logger.debug("In test()")

def main():
    logger.info(f"now is {datetime.datetime.now()}", )
    logger.debug("In main()")
    test()

if __name__ == '__main__':
    main()

any_other.py

import logging
logger = logging.getLogger("logger_test")  # this will return the logger you already instantiate in log_tester.py

logger.info("that works!")

Update

To set the level and the handling of the root logger instead of the one you setted up, use logging.getLogger() without passing any name:

root_logger = logging.getLogger()
root_logger.addHandler(your_handler)
root_logger.setLevel(logging.DEBUG)

root_logger.info("hello world")

Upvotes: 2

HarryClifton
HarryClifton

Reputation: 139

From the docs:

Multiple calls to getLogger() with the same name will return a reference to the same logger object.

Your assumptions are quite correct. The problem here is the way you are calling getLogger() in test(). You should be passing the name you used in SetupLogger()'s getLogger() i.e. logger = logging.getLogger(f"{name_prefix} {__name__}").

Upvotes: 1

Related Questions