Python logging not outputting anything

Question

In a python script I am writing, I am trying to log events using the logging module. I have the following code to configure my logger:

ERROR_FORMAT = "%(levelname)s at %(asctime)s in %(funcName)s in %(filename) at line %(lineno)d: %(message)s"
DEBUG_FORMAT = "%(lineno)d in %(filename)s at %(asctime)s: %(message)s"
LOG_CONFIG = {'version':1,
              'formatters':{'error':{'format':ERROR_FORMAT},
                            'debug':{'format':DEBUG_FORMAT}},
              'handlers':{'console':{'class':'logging.StreamHandler',
                                     'formatter':'debug',
                                     'level':logging.DEBUG},
                          'file':{'class':'logging.FileHandler',
                                  'filename':'/usr/local/logs/DatabaseUpdate.log',
                                  'formatter':'error',
                                  'level':logging.ERROR}},
              'root':{'handlers':('console', 'file')}}
logging.config.dictConfig(LOG_CONFIG)

When I try to run logging.debug("Some string"), I get no output to the console, even though this page in the docs says that logging.debug should have the root logger output the message. Why is my program not outputting anything, and how can I fix it?

Answer 1

Many years later there seems to still be a usability problem with the Python logger. Here's some explanations with examples:

import logging
# This sets the root logger to write to stdout (your console)
logging.basicConfig()

# By default the root logger is set to WARNING and all loggers you define
# inherit that value. Here we set the root logger to NOTSET. This logging
# level is automatically inherited by all existing and new sub-loggers
# that do not set a less verbose level.
logging.root.setLevel(logging.NOTSET)

# The following line sets the root logger level as well.
# It's equivalent to both previous statements combined:
logging.basicConfig(level=logging.NOTSET)


# You can either share the `logger` object between all your files or the
# name handle (here `my-app`) and call `logging.getLogger` with it.
# The result is the same.
handle = "my-app"
logger1 = logging.getLogger(handle)
logger2 = logging.getLogger(handle)
# logger1 and logger2 point to the same object:
# (logger1 is logger2) == True


# Convenient methods in order of verbosity from highest to lowest
logger.debug("this will get printed")
logger.info("this will get printed")
logger.warning("this will get printed")
logger.error("this will get printed")
logger.critical("this will get printed")


# In large applications where you would like more control over the logging,
# create sub-loggers from your main application logger.
component_logger = logger.getChild("component-a")
component_logger.info("this will get printed with the prefix `my-app.component-a`")

# If you wish to control the logging levels, you can set the level anywhere 
# in the hierarchy:
#
# - root
#   - my-app
#     - component-a
#

# Example for development:
logger.setLevel(logging.DEBUG)

# If that prints too much, enable debug printing only for your component:
component_logger.setLevel(logging.DEBUG)


# For production you rather want:
logger.setLevel(logging.WARNING)

---

A common source of confusion comes from a badly initialised root logger. Consider this:

import logging
log = logging.getLogger("myapp")
log.warning("woot")
logging.basicConfig()
log.warning("woot")

Output:

woot
WARNING:myapp:woot

Depending on your runtime environment and logging levels, the first log line (before basic config) might not show up anywhere.

Answer 2

For anyone here that wants a super-simple answer: just set the level you want displayed. At the top of all my scripts I just put:

import logging
logging.basicConfig(level = logging.INFO)

Then to display anything at or above that level:

logging.info("Hi you just set your fleeb to level plumbus")

It is a hierarchical set of five levels so that logs will display at the level you set, or higher. So if you want to display an error you could use logging.error("The plumbus is broken").

The levels, in increasing order of severity, are DEBUG, INFO, WARNING, ERROR, and CRITICAL. The default setting is WARNING.

This is a good article containing this information expressed better than my answer:
https://www.digitalocean.com/community/tutorials/how-to-use-logging-in-python-3

Answer 3

Maybe try this? It seems the problem is solved after remove all the handlers in my case.

for handler in logging.root.handlers[:]:
    logging.root.removeHandler(handler)

logging.basicConfig(filename='output.log', level=logging.INFO)

Answer 4

The default logging level is warning. Since you haven't changed the level, the root logger's level is still warning. That means that it will ignore any logging with a level that is lower than warning, including debug loggings.

This is explained in the tutorial:

import logging
logging.warning('Watch out!') # will print a message to the console
logging.info('I told you so') # will not print anything

The 'info' line doesn't print anything, because the level is higher than info.

To change the level, just set it in the root logger:

'root':{'handlers':('console', 'file'), 'level':'DEBUG'}

In other words, it's not enough to define a handler with level=DEBUG, the actual logging level must also be DEBUG in order to get it to output anything.