Python2.7 log level of logging doesn't work

Question

It seems recently there were some changes of python logging package. Some code work previously doesn't work now. And I am confused. My python version is Python 2.7.15.

The first example I don't understand is that below only prints "WARNING:root:hello from warn". If I understand correctly, "logging.info" actually calls the root logger, and root logger default to warn level. So the first "hello from info" is ignored, which is fine. But why the second "hello from info" is also not printed?

import logging 
logging.info("hello from info")
logging.warn("hello from warn")

logging.basicConfig(level=logging.INFO)
logging.info("hello from info")

The second question is the logging level of Handler versus logger. If we set the log level for both the handler and logger, which one is working? Or what if we just set level for Handler? Take the example as below. We already set the log level for StreamHandler, but the "hello from info" is not printed to stdout. Only the "hello from warn" (Besides, it is not "WARNING:t:hello from warn"). Why is that?

import logging
ch = logging.StreamHandler()
ch.setLevel(logging.INFO)
logger = logging.getLogger('t')
logger.addHandler(ch)
logger.info("hello from info")
logger.warn("hello from warn")

hoefling · Accepted Answer · 2018-08-18 11:55:00Z

4

But why the second "hello from info" is also not printed?

Because

logging.info / warn / error / debug call logging.basicConfig under the hood. Example:

def info(msg, *args, **kwargs):
    if len(root.handlers) == 0:
        basicConfig()
    root.info(msg, *args, **kwargs)

logging.basicConfig does not do anything if the root logger is already configured. Quote from the docs:

This function does nothing if the root logger already has handlers configured for it.

So, in your code, the root logger is configured with WARN level when logging.info("hello from info") is executed. The subsequent call of logging.basicConfig(level=logging.INFO) has no effect.

Rule of thumb: configure the loggers (no matter if manually or via logging.basicConfig()) as early as possible in your code.

If we set the log level for both the handler and logger, which one is working?

Both! Logger level and handler level are two different stages of filtering records. The logger level defines what records are actually passed to its handlers, while the handler level defines what records will be handled by the particular handler. Examples:

logger.setLevel(logging.INFO)
handler.setLevel(logging.ERROR)
logger.addHandler(handler)
logger.info('spam')

Since logger has level INFO, it will process spam record and pass it to its handlers. However, handler has level ERROR, so the record will not be processed by handler.

logger.setLevel(logging.WARN)
handler.setLevel(logging.DEBUG)
logger.addHandler(handler)
logger.info('spam')

Now the handler will process almost any record, including spam record since its level is INFO, thus greater than DEBUG. However, the handler will never receive spam to process because the logger will not process it, thus not passing spam to its handlers.

logger.setLevel(logging.INFO)
h1 = logging.StreamHandler()
h1.setLevel(logging.CRITICAL)
h2 = logging.FileHandler('some.log')
h2.setLevel(logging.DEBUG)
logger.addHandler(h1)
logger.addHandler(h2)
logger.info('spam')

Now the logger has two handlers, h1 printing records to terminal, h2 writing them to file. The logger will pass only records of level INFO or greater to its handlers. However, you will see only records with level CRITICAL in terminal, but all records in log file.

answered Aug 18, 2018 at 11:55

hoefling

67.8k15 gold badges182 silver badges228 bronze badges

Sign up to request clarification or add additional context in comments.

4 Comments

batilei Over a year ago

Thank you so much Hoefling. The answer is great!

hoefling Over a year ago

Glad I could help!

cryanbhu Over a year ago

i thought you won't see DEBUG logs in the file, since the logger won't even pass them to the FileHandler?

hoefling Over a year ago

@cryanbhu that's correct - the logger won't pass the debug log records to filehandler, so no writing them to file. What you are probably seeing are the old log records since FileHandler('some.log') will append to log file by default. Change it to FileHandler('some.log', mode='w') to verify.

Collectives™ on Stack Overflow

Python2.7 log level of logging doesn't work

1 Answer 1

4 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

4 Comments

Your Answer

Sign up or log in

Post as a guest

Related