The Basic Interface

Here’s the easiest way to use Python’s logging module:

import logging
logging.warning('Look out!')

Save this in a script and run it, and you’ll see this printed out:

WARNING:root:Look out!

You can do useful logging right away, by calling functions in the logging module itself. You invoked logging.warning(), and the output line started with WARNING. You can also call logging.error(), which gives a different prefix:

ERROR:root:Look out!

logging.debug("Small detail. Useful for troubleshooting.")
logging.info("This is informative.")
logging.warning("This is a warning message.")
logging.error("Uh oh. Something went wrong.")
logging.critical("We have a big problem!")

WARNING:root:This is a warning message.
ERROR:root:Uh oh. Something went wrong.
CRITICAL:root:We have a big problem!

logging.basicConfig(level=logging.INFO)
logging.info("This is informative.")
logging.error("Uh oh. Something went wrong.")

INFO:root:This is informative.
ERROR:root:Uh oh. Something went wrong.

logging.log(logging.DEBUG,
    "Small detail. Useful for troubleshooting.")
logging.log(logging.INFO, "This is informative.")
logging.log(logging.WARNING, "This is a warning message.")
logging.log(logging.ERROR, "Uh oh. Something went wrong.")
logging.log(logging.CRITICAL, "We have a big problem!")

def log_results(message, level=logging.INFO):
    logging.log(level, "Results: " + message)

Configuring the Basic Interface

You can change the log-level threshold by calling a function called basicConfig():

logging.basicConfig(level=logging.INFO)
logging.debug("You won't see this message!")
logging.error("But you will see this one.")

If you use it at all, basicConfig() must be called exactly once,​² and it must happen before the first logging event. (Meaning, before the first call to debug(), or warning(), etc.) Additionally, if your program has several threads, basicConfig() must be called from the main thread—and only the main thread.​³

You’ve already met one of the configuration options: level. Some of the other options include:

filename

Write log messages to the given file, rather than stderr.

filemode

Set to "a" to append to the log file (the default), or "w" to overwrite.

format

The format of log records.

By default, log messages are written to standard error. You can also write them to a file—one per line—to be easily read later. Do this by setting filename to the log file path. By default it appends log messages, meaning that it will only add to the end of the file if it isn’t empty. If you’d rather the file be emptied before the first log message, set filemode to "w". Be careful about doing that, of course, because you can easily lose old log messages if the application restarts:

# Wipes out previous log entries when program restarts
logging.basicConfig(filename="log.txt", filemode="w")
logging.error("oops")

The other value you can pick is "a", for append—that’s the default, and it will probably serve you better in production. "w" is generally better during development, though. I have wasted many hours of my life wondering why I was seeing a message indicating a bug in the log file, only to realize it came from two edits ago, before I had fixed the bug. Now, I set up my development environment to wipe the logs with every run.

format defines what chunks of information the final log record will include, and how they are laid out. These chunks are called attributes in the logging module docs. One of these attributes is the actual log message—the string you pass when you call logging.warning(), and so on. Often you will want to include other attributes as well. Consider the kind of log record we saw above:

WARNING:root:Collision imminent

This record has three attributes, separated by colons. First is the log level name, and the last is the actual string message you pass when you call logging.warning(). In the middle is the name of the underlying logger object. basicConfig() uses a logger called “root”; we’ll learn more about that later.

You specify the layout you want by setting format to a string that defines certain named fields, according to percent-style formatting. Three of them are levelname, the log level; message, the message string passed to the logging function; and name, the name of the underlying logger. Here’s an example:

logging.basicConfig(
    format="Log level: %(levelname)s, msg: %(message)s")
logging.warning("Collision imminent")

If you run this as a program, you get the following output:

Log level: WARNING, msg: Collision imminent

The default formatting string is:

%(levelname)s:%(name)s:%(message)s

You indicate named fields in percent-formatting by %(FIELDNAME)X, where “X” is a type code: s for string, d for integer (decimal), and f for floating-point.

Many other attributes are provided, if you want to include them. Table 9-1 shows a select few from the full list.⁴

You might be wondering why log record format strings use Python 2’s ancient percent-formatting style, even in modern Python. As it turns out, backward-compatibility reasons made percent-formatting the only practical choice for the logging module, even after the Python 3 reboot.

If you want to use the newer string formatting anyway, it is certainly possible.⁵ But doing so is complicated enough, and has enough landmines, that it may not be worth the effort. I recommend you simply use percent-formatting with your Python logging.

Passing Arguments

You’ll often want to include some kind of runtime data in the logged message. Specify the final log message like this:

num_fruits = 14
fruit_name = "oranges"
logging.info(
    "We ate %d of your %s. Thanks!",
    num_fruits, fruit_name)

The output:

INFO:root:We ate 14 of your oranges. Thanks!

We call info() with three parameters. First is the format string; the second and third are arguments. The general form is:

logging.info(format, *args)

You can pass zero or more arguments, so long as each has a field in the format string:

# Do it like this:
logging.info("%s, %s, %s, %s, %s, %s and %s",
    "Doc", "Happy", "Sneezy", "Bashful",
    "Dopey", "Sleepy", "Grumpy")

You must resist the obvious temptation to format the string fully, and pass that to the logging function:

num_fruits = 14
fruit_name = "oranges"
logging.warning(
    "Don't do this: %d %s" % (num_fruits, fruit_name))
logging.warning(
    "Or this: {} {}".format(
    num_fruits, fruit_name))
logging.warning(
    f"And definitely not this: {num_fruits} {fruit_name}")

All of these work, in the sense that you will get correct log messages. But each surrenders important performance benefits logging normally provides. Remember: when the line of code with the log message is executed, it may not actually trigger a log event. If the log level threshold is higher than the message itself, the line does nothing. In that case, there is no reason to format the string.

In the “do it like this” form, the string is formatted if and only if a log event actually happens, so that’s fine. But if you format the string yourself, it’s always formatted. That takes up system memory and CPU cycles even if no logging takes place. If the code path with the logging call is only executed occasionally, that’s not a big deal. But it impairs the program when a debug message is logged in the middle of a tight loop. When you originally code the line, you never really know where it might migrate in the future, or who will call your function in ways you never imagined. So I recommend you always use the recommended form in your logging calls.

There is another point to make about f-strings. Realize that f-strings are Python syntax for constructing string literals. When you use an f-string, the final string is rendered at the expression level. There is no way to delay that calculation or make it “lazy”. This makes it impossible to use the deferred string rendering the logging functions are designed for.

So just use the supported form, where the first argument is the format string, and subsequent arguments are the parameters for it. You can also use named fields, by passing a dictionary as the second argument—though you must use the percent-formatting named-field format:

fruit_info = {"count": 14, "name": "oranges"}
logging.info(
    "We ate %(count)d of your %(name)s. Thanks!",
    fruit_info)

Beyond Basic: Loggers

The basic interface is simple and easy to set up. It works well in single-file scripts. Larger Python applications tend to have different logging needs, however. logging meets these needs through a richer interface, called logger objects—or simply, loggers.

Actually, you have been using a logger object all along: when you call logging.​warn⁠ing() (or the other log functions), they convey messages through what is called the root logger—the primary, default logger object. This is why the word “root” shows in some example output.

logger.basicConfig() operates on this root logger. You can fetch the actual root logger object by calling logging.getLogger():

>>> logger = logging.getLogger()
>>> logger.name
'root'

As you can see, it knows its name is “root”. Logger objects have all the same functions (methods, actually) that the logging module itself has:

import logging
logger = logging.getLogger()
logger.debug("Small detail. Useful for troubleshooting.")
logger.info("This is informative.")
logger.warning("This is a warning message.")
logger.error("Uh oh. Something went wrong.")
logger.critical("We have a big problem!")

Save this in a file and run it, and you’ll see the following output:

This is a warning message.
Uh oh. Something went wrong.
We have a big problem!

This is different from what we saw with basicConfig(), which printed out this:

WARNING:root:This is a warning message.
ERROR:root:Uh oh. Something went wrong.
CRITICAL:root:We have a big problem!

This is a step backward compared to basicConfig(). The log message does not display the log level, or any other useful information. The log level threshold is hard-coded to logging.WARNING, with no way to change it. The logging output will be written to standard error and nowhere else, regardless of where you actually need it to go.

Let’s take inventory of what we want to control here. We want to choose our log record format, control the log level threshold, and write messages to different streams and destinations. You do all this with a tool called a handler.

Log Destinations: Handlers and Streams

By default, loggers write to standard error. It is possible to select a different destination—or even several destinations—for each log record:

• You can write log records to a file. This is very common.

• You can write records to a file, and also parrot it to stderr.

• Or you can write to stdout, or both.

• You can simultaneously log messages to two different files.

• You can log (say) INFO and higher messages to one file, and ERROR and higher to another.

• You can write records to a remote log server through an API.

• You can set a different, custom log format for each destination.

This is all managed through what are called handlers. In Python logging, a handler’s job is to take a log record, and make sure it gets recorded in the appropriate destination. That destination can be a file; a stream like stderr or stdout; or something more abstract, like inserting into a queue, or transmitting via an RPC or HTTP call.

By default, logger objects don’t have any handlers. You can verify this using the hasHandlers() method:

>>> logger = logging.getLogger()
>>> logger.hasHandlers()
False

With no handler, a logger has the following behavior:

• Messages are written to stderr.

• Only the message is written, nothing else. There’s no way to add fields or otherwise modify it.

• The log level threshold is logging.WARNING. There is no way to change that.

To change this behavior, your first step is to create a handler. Nearly all logger objects you ever use will have custom handlers. Let’s see how to create a simple handler that writes messages to a file, called log.txt.

import logging
logger = logging.getLogger()
log_file_handler = logging.FileHandler("log.txt")
logger.addHandler(log_file_handler)
logger.debug("A little detail")
logger.warning("Boo!")

The logging module provides a class called FileHandler. It takes a file path argument, and will write log records into that file, one per line. When you run this code, log.txt will be created (if it doesn’t already exist), and will contain the string “Boo!” followed by a newline. (If log.txt did exist already, the logged message would be appended to the end of the file.)

“A little detail” is not written, because it’s below the default logger threshold of WARNING. You can change that by calling a method named setLevel() on the logger object:

import logging
logger = logging.getLogger()
logger.setLevel(logging.DEBUG)
log_file_handler = logging.FileHandler("log.txt")
logger.addHandler(log_file_handler)
logger.debug("A little detail")
logger.warning("Boo!")

This writes the following in log.txt:

A little detail
Boo!

Confusingly, you can call setLevel() on a logger with no handlers, but it has no effect:

# Doing it wrong:
import logging
logger = logging.getLogger()
logger.setLevel(logging.DEBUG) # No effect.
logger.debug("This won't work :(")

To change the threshold from the default of logging.WARNING, you must both add a handler, and change the logger’s level.

What if you want to log to stdout? Do that with a StreamHandler:

import logging
import sys
logger = logging.getLogger()
out_handler = logging.StreamHandler(sys.stdout)
logger.addHandler(out_handler)
logger.warning("Boo!")

If you save this in a file and run it, you’ll get “Boo!” on standard output. Notice that logging.StreamHandler takes sys.stdout as its argument. You can create a StreamHandler without an argument too, in which case it will write its records to standard error:

import logging
logger = logging.getLogger()
# Same as StreamHandler(sys.stderr)
stderr_handler = logging.StreamHandler()
logger.addHandler(stderr_handler)
logger.warning("This goes to standard error")

In fact, you can pass any file-like object; The object just needs to define compatible write and flush methods. Theoretically, you could even log to a file by creating a handler like StreamHandler(open("log.txt", "a"))—but in that case, it’s better to use a FileHandler so that it can manage opening and closing the file.

Most of the handlers you might need are provided for you in the logging module. The most common handlers you use will probably be StreamHandler and File​Han⁠dler. Others include:

• WatchedFileHandler and RotatingFileHandler, for logging to rotated log files

• SocketHandler and DatagramHandler for logging over network sockets

• HTTPHandler for logging over an HTTP REST interface

• QueueHandler and QueueListener for queuing log records across thread and process boundaries

See the official docs​⁶ for details. At times, you may need to create a custom handler, by subclassing logging.Handler. This lets you log to any destination you need to.

Logging to Multiple Destinations

Suppose you want your long-running application to log all messages to a file, including debug-level records. At the same time, you want warnings, errors, and criticals logged to the console. How do you do this?

We’ve given you part of the answer already. A single logger object can have multiple handlers: all you have to do is call addHandler() multiple times, passing a different handler object for each. For example, here is how you parrot all log messages to the console (via standard error) and also to a file:

import logging
logger = logging.getLogger()
# Remember, StreamHandler defaults to using sys.stderr
console_handler = logging.StreamHandler()
logger.addHandler(console_handler)
# Now the file handler:
logfile_handler = logging.FileHandler("log.txt")
logger.addHandler(logfile_handler)
logger.warning(
    "This goes to both the console, AND log.txt.")

This combines what we learned above. We create two handlers—a StreamHandler named console_handler, and a FileHandler named logfile_handler—and add both to the same logger (via addHandler). That’s all you need to log to multiple destinations in parallel. Sure enough, if you save the above in a script and run it, you’ll find the messages are both written into log.txt, as well as printed on the console (through standard error).

How do we make it so every record is written in the log file, but only those of logging.WARNING or higher get sent to the console screen? Do this by setting log level thresholds for both the logger object and the individual handlers. Both logger objects and handlers have a method called setLevel(), which take a log level threshold as an argument:

my_logger.setLevel(logging.DEBUG)
my_handler.setLevel(logging.INFO)

If you set the level for a logger, but not its handlers, the handlers inherit from the logger:

my_logger.setLevel(logging.ERROR)
my_logger.addHandler(my_handler)
my_logger.error("This message is emitted by my_handler.")
my_logger.debug("But this message will not.")

You can override that at the handler level. Here, I create two handlers. One handler inherits its threshold from the logger, while the other does its own thing:

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

verbose_handler = logging.FileHandler("verbose.txt")
logger.addHandler(verbose_handler)

terse_handler = logging.FileHandler("terse.txt")
terse_handler.setLevel(logging.WARNING)
logger.addHandler(terse_handler)

logger.debug("This message appears in verbose.txt ONLY.")
logger.warning("And this message appears in both files.")

There’s a caveat, though: a handler can only make itself more selective than its logger, not less. If the logger chooses a threshold of logger.DEBUG, its handler can choose a threshold of logger.INFO, or logger.ERROR, and so on. But if the logger defines a strict threshold—say, logger.INFO—an individual handler cannot choose a lower one, like logger.DEBUG. So something like this won’t work:

# This doesn't quite work...
import logging
my_logger = logging.getLogger()
my_logger.setLevel(logging.INFO)
my_handler = logging.StreamHandler()
my_handler.setLevel(logging.DEBUG) # FAIL!
my_logger.addHandler(my_handler)
my_logger.debug("No one will ever see this message :(")

There’s a subtle corollary of this. By default, a logger object’s threshold is set to logger.WARNING. So if you don’t set the logger object’s log level at all, it implicitly censors all handlers:

import logging
my_logger = logging.getLogger()
my_handler = logging.StreamHandler()
my_handler.setLevel(logging.DEBUG) # FAIL!
my_logger.addHandler(my_handler)
# No one will see this message either.
my_logger.debug("Because anything under WARNING gets filtered.")

The logger object’s default log level is not always permissive enough for all handlers you might want to define. So you will generally want to start by setting the logger object to the lowest threshold needed by any log-record destination, and tighten that threshold for each handler as needed.

Bringing this all together, we can now accomplish what we originally wanted—to verbosely log everything into a log file, while duplicating only the more interesting messages onto the console:

import logging
logger = logging.getLogger()
logger.setLevel(logging.DEBUG)
# Warnings and higher only on the console.
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.WARNING)
logger.addHandler(console_handler)
# But allow everything to go into the log file.
logfile_handler = logging.FileHandler("log.txt")
logger.addHandler(logfile_handler)

logger.warning("This goes to both the console, AND into log.txt.")
logger.debug("While this only goes to the file.")

Add as many handlers as you want. Each can have different log levels. You can log to many different destinations, using the different built-in handler types mentioned above. If those don’t do what you need, implement your own subclass of logging.​Han⁠dler and use that.

Record Layout with Formatters

So far, we’ve only shown you how to create logger objects that will write just the log message and nothing else. At the very least, you probably want to annotate that with the log level. You may also want to insert the time and other information. How do you do that?

The answer is to use a formatter. A formatter converts a log record into something that is recorded in the handler’s destination. That’s an abstract way of saying it; more simply, a typical formatter just converts the record into a usefully formatted string that contains the actual log message, as well as the other fields you care about.

The procedure is to create a Formatter object, then associate it with a handler (using the latter’s setFormatter() method). Creating a formatter is easy—it normally takes just one argument, the format string:

import logging
my_handler = logging.StreamHandler()
fmt = logging.Formatter("My message is: %(message)s")
my_handler.setFormatter(fmt)
my_logger = logging.getLogger()
my_logger.addHandler(my_handler)
my_logger.warning("WAKE UP!!")

If you run this in a script, the output will be:

My message is: WAKE UP!!

Notice the attribute for the message, %(message)s, included in the string. This is just a normal formatting string in the older, percent-formatting style. It’s exactly equivalent to using the format argument when you call basicConfig(). For this reason, you can use the same attributes, arranged however you like (see Table 9-1).

Conclusion

The larger your program, the more valuable logging becomes. You can get along without it so long as you write nothing but small Python scripts. But having read this far, your ambitions are likely higher. For more sophisticated software systems, smart use of Python’s rich logging module helps you create better software faster, and keep it running great.