logging.basicConfig in Python won't work if calling logging.info() before declaring

Question

Based on this answer, Easier way to enable verbose logging

Let's take this Python script.

import argparse
import logging


def main():
    import argparse
    import logging

    parser = argparse.ArgumentParser(
        description='A test script for http://stackoverflow.com/q/14097061/78845'
    )
    parser.add_argument("-v", "--verbose", help="increase output verbosity",
                        action="store_true")

    args = parser.parse_args()
    if args.verbose:
        logging.basicConfig(level=logging.DEBUG)

    logging.info('Shown in debug and info mode')
    logging.debug('Only shown in debug mode')


if __name__ == "__main__":
    logging.info('Starting script!')
    main()

Running this script from terminal as python -m verbose -v won't print anything.

If you comment the line logging.info('Starting script!') from the file as in

if __name__ == "__main__":
    #logging.info('Starting script!')
    main()

then logging works as expected.

It looks like an attempt to call a logging.info() before basicConfig is defined will fully disable any logging.

Is it a bug in logging or a common gotcha and why does this happen?

I am on Python 3.6.7.

score 8 · Accepted Answer · answered May 30 '19 at 13:16

8

From the logging documentation: (Emphasis mine)

 logging.basicConfig(**kwargs)
Does basic configuration for the logging system by creating a StreamHandler with a default Formatter and adding it to the root logger.

The functions debug(), info(), warning(), error() and critical() will call basicConfig() automatically if no handlers are defined for the root logger.

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

So basically your first call to logging.info made some automatic configuration. Your later configuration attempt silently failed because of the automatic configuration that already happend.

answered May 30 '19 at 13:16

dgw

13,418
11
56
54

This makes sense, thank you. Cannot say that suppressing the failed attempt to initialize `basicConfig` again is helpful. I've tested adding `logging.warning('Warning')` in the function and it was printed. I assume that the default configuration will log anything more severe than `warning`? Made some tests and printed `error` and `critical` as well. Is it (what would be this default configuration) documented? – Alex Tereshenkov May 30 '19 at 14:00
1

Can the `force=True` argument be used to go around this? – PatrickT May 15 '20 at 02:16
ok, this explains why it does not work in GCP functions! – confiq Jul 29 '20 at 07:42

score 5 · Answer 2 · answered May 30 '19 at 15:18

5

Don't use basicConfig to change the level. Use logging.getLogger().setLevel(logging.DEBUG) to change the level on the root logger. One can do this on any logger or handler as well.

answered May 30 '19 at 15:18

Dan D.

73,243
15
104
123

logging.basicConfig in Python won't work if calling logging.info() before declaring

2 Answers2