Python Logging Examples (Run Online)

1One message at every level

The same five calls are shown with two thresholds. Lowering the level from WARNING to DEBUG reveals more output, and no log call changed.

One message at every level

import logging
import sys

for threshold in (logging.WARNING, logging.DEBUG):
    logging.basicConfig(level=threshold, format="%(levelname)s %(message)s", stream=sys.stdout, force=True)
    print("threshold", logging.getLevelName(threshold))
    logging.debug("cache key built")
    logging.info("report started")
    logging.warning("slow query")
    logging.error("report failed")
    logging.critical("out of memory")

Expected outputthreshold WARNING
WARNING slow query
ERROR report failed
CRITICAL out of memory
threshold DEBUG
DEBUG cache key built
INFO report started
WARNING slow query
ERROR report failed
CRITICAL out of memory

2What the format fields give you

%(name)s, %(levelname)s, %(funcName)s and %(lineno)d show who logged and where. Line numbers change if you edit the code, so use them for debugging, not for tests.

What the format fields give you

import logging
import sys

logging.basicConfig(level=logging.INFO, stream=sys.stdout, force=True,
                    format="[%(levelname)-8s] %(name)s.%(funcName)s: %(message)s")
log = logging.getLogger("billing")

def send_invoice(customer):
    log.info("invoice sent to %s", customer)

def refund(customer, amount):
    log.warning("refunding %.2f to %s", amount, customer)

send_invoice("Asha")
refund("Ben", 12.5)

Expected output[INFO    ] billing.send_invoice: invoice sent to Asha
[WARNING ] billing.refund: refunding 12.50 to Ben

3Child loggers inherit the parent's level

shop.cart has no level of its own, so it uses the nearest parent that has one. Setting the level on shop changes the whole family at once.

Child loggers inherit the parent's level

import logging
import sys

logging.basicConfig(level=logging.WARNING, format="%(name)s:%(message)s", stream=sys.stdout, force=True)
shop = logging.getLogger("shop")
cart = logging.getLogger("shop.cart")
shop.setLevel(logging.WARNING)
cart.setLevel(logging.NOTSET)

cart.info("hidden: below WARNING")
shop.setLevel(logging.INFO)
cart.info("shown: parent now allows INFO")
print(cart.getEffectiveLevel(), cart.level)

Expected outputshop.cart:shown: parent now allows INFO
20 0

4Screen gets warnings, a file keeps everything

Two handlers on one logger with different thresholds. The file is written to the temporary file system and read back to show that debug lines were kept.

Screen gets warnings, a file keeps everything

import logging
import sys

log = logging.getLogger("sync")
log.handlers.clear()
log.setLevel(logging.DEBUG)
log.propagate = False

screen = logging.StreamHandler(sys.stdout)
screen.setLevel(logging.WARNING)
screen.setFormatter(logging.Formatter("!! %(message)s"))
journal = logging.FileHandler("sync.log", mode="w")
journal.setFormatter(logging.Formatter("%(levelname)s %(message)s"))
log.addHandler(screen)
log.addHandler(journal)

log.debug("scanning 3 folders")
log.info("copied 12 files")
log.warning("1 file skipped")
journal.close()
print(open("sync.log").read().splitlines())

Expected output!! 1 file skipped
['DEBUG scanning 3 folders', 'INFO copied 12 files', 'WARNING 1 file skipped']

5Log the traceback with logger.exception

exception() is error() plus the traceback. Here the output is captured so we can print just the first and last line, which keeps the demo free of file paths.

Log the traceback with logger.exception

import io
import logging

buffer = io.StringIO()
log = logging.getLogger("grades")
log.handlers.clear()
log.propagate = False
handler = logging.StreamHandler(buffer)
handler.setFormatter(logging.Formatter("%(levelname)s:%(name)s:%(message)s"))
log.addHandler(handler)

scores = {"Asha": [90, 80], "Ben": []}
for student, marks in scores.items():
    try:
        print(student, sum(marks) / len(marks))
    except ZeroDivisionError:
        log.exception("no marks for %s", student)

lines = buffer.getvalue().splitlines()
print(lines[0])
print(lines[-1])

Expected outputAsha 85.0
ERROR:grades:no marks for Ben
ZeroDivisionError: division by zero

6Skip expensive debug work with isEnabledFor

Arguments are formatted lazily, but computing an argument still costs time. isEnabledFor lets you skip the whole calculation when DEBUG is off.

Skip expensive debug work with isEnabledFor

import logging
import sys

logging.basicConfig(level=logging.INFO, format="%(levelname)s:%(message)s", stream=sys.stdout, force=True)
log = logging.getLogger("stats")
data = list(range(1, 101))
calls = 0

def summary(values):
    global calls
    calls += 1
    return f"min={min(values)} max={max(values)} total={sum(values)}"

if log.isEnabledFor(logging.DEBUG):
    log.debug("data: %s", summary(data))
log.info("processing %d numbers", len(data))
print("summary calls:", calls)

Expected outputINFO:processing 100 numbers
summary calls: 0

Practise next

Python Logging exercises → Back to the lesson

Python Modules and Imports examples Python Exceptions: try, except, else and finally examples Python with Statement examples Python Testing examples