python logging root logger does not show info even if I set the level to INFO

Question

I created the following script. Could any of you explain to me why the output is like what shows below

Source

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

print('debug', logger.isEnabledFor(logging.DEBUG))
print('info', logger.isEnabledFor(logging.INFO))
print('warning', logger.isEnabledFor(logging.WARNING))
print('error', logger.isEnabledFor(logging.ERROR))

logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')

logging.debug('debug')
logging.info('info')
logging.warning('warning')
logging.error('error')

Output

debug True
info True
warning True
error True
warning
error
DEBUG:root:debug
INFO:root:info
WARNING:root:warning
ERROR:root:error

Specifically

1. what is the difference between logger.info and logging.info here

2. how come that logger.isEnabledFor(logging.DEBUG) is True while logger.debug('debug') does not show anything

3. how come that logger.info has no output but logging.info has

Answer 1

A few things to clarify:

1. Default log level for root logger is WARNING

2. Root logger is not initialized if you do nothing, that is, without any handlers or formatter set up:

   >>> import logging
   >>> logging.root.handlers
   []
   

Okay, but you found out the problem: when logging level set to DEBUG, the root logger is not working as expected. Debug messages are ignored. With the same not configured root logger, warning messages output normally. Why is that?

Keep in mind we don't have any handler for root logger right now. But looking into the code, we do see:

    if (found == 0):
        if lastResort:
            if record.levelno >= lastResort.level:
                lastResort.handle(record)
        elif raiseExceptions and not self.manager.emittedNoHandlerWarning:
            sys.stderr.write("No handlers could be found for logger"
                             " \"%s\"\n" % self.name)
            self.manager.emittedNoHandlerWarning = True

Which means, we have a lastResort for backup if no handler is found. You can refer to the definition of lastResort, it is initialized with logging level WARNING. Meanwhile, debug messages don't have this backup so they are ignored when no handler is set.

For your questions:

1. These two loggers are identical, since the root logger is returned when getLogger() receives no arguments.
2. See below:

   Logger.isEnabledFor(lvl)

   Indicates if a message of severity lvl would be processed by this logger. This method checks first the module-level level set by logging.disable(lvl) and then the logger’s effective level as determined by getEffectiveLevel().

3. Calling any logging functions in logging module will initialize the root logger with basicConfig() which adds a default handler, so that the subsequent calls on logger will also work.

What you should do is, use logging.basicConfig() to set up a default handler for root logger and messages will be output according to the logger level and message level.

Answer 2

getLogger creates an instance of Logger class if argument name is added. Otherwise it returns root logger. So in this case the program is using the common logger as functions logging.debug, logging.info, logging.warning, logging.info