Logging & debugging

Every program misbehaves sometimes. The difference between a junior and a senior developer is often how quickly they find out why. This lesson covers two complementary skills: logging, which records what your program does while it runs (essential in production, where you can't attach a debugger), and debugging, which lets you pause a program and inspect it interactively.

Why not just print?#

print is fine for quick experiments, but in real applications it falls short:

• You can't turn messages on or off without editing code.
• There's no severity — a debugging detail looks the same as a critical failure.
• No timestamps, no module names, no way to send output to a file or a log service.
• Leftover print calls clutter output for your users.

The standard library's logging module solves all of this.

Logging basics#

import logging

logging.basicConfig(level=logging.DEBUG, format="%(levelname)s: %(message)s")

logging.debug("detailed diagnostic info")
logging.info("server started on port %d", 8000)
logging.warning("disk usage at %d%%", 91)
logging.error("could not connect to database")
logging.critical("out of memory, shutting down")

DEBUG: detailed diagnostic info
INFO: server started on port 8000
WARNING: disk usage at 91%
ERROR: could not connect to database
CRITICAL: out of memory, shutting down

The five standard levels, from least to most severe:

Setting level=logging.INFO shows INFO and above; DEBUG messages are skipped (cheaply). Without any configuration, only WARNING and above appear.

Notice the %-style arguments: logging.info("port %d", 8000) rather than an f-string. The message is only formatted if it's actually going to be emitted, and log aggregators can group messages by their template. f-strings work too and are common in practice, but the lazy form is the recommended style.

Use a logger per module#

Instead of calling logging.info directly, create a named logger at the top of each module:

import logging

logger = logging.getLogger(__name__)    # e.g. "shop.payments"


def charge(order_id, amount):
    logger.info("charging order %s: ₹%s", order_id, amount)
    if amount <= 0:
        logger.warning("refusing non-positive amount for order %s", order_id)
        return False
    return True


if __name__ == "__main__":
    logging.basicConfig(
        level=logging.INFO,
        format="%(asctime)s %(levelname)-8s %(name)s: %(message)s",
        datefmt="%H:%M:%S",
    )
    charge(1001, 499)
    charge(1002, 0)

...:...:... INFO     __main__: charging order 1001: ₹499
...:...:... INFO     __main__: charging order 1002: ₹0
...:...:... WARNING  __main__: refusing non-positive amount for order 1002

Loggers form a hierarchy based on dotted names: configuring shop also affects shop.payments and shop.cart. That lets you, say, show DEBUG logs only for your own package while keeping noisy libraries at WARNING:

import logging

logging.basicConfig(level=logging.WARNING, format="%(name)s %(levelname)s %(message)s")
logging.getLogger("shop").setLevel(logging.DEBUG)

logging.getLogger("shop.cart").debug("cart recalculated")
logging.getLogger("urllib3").debug("connection pool details")   # hidden
logging.getLogger("urllib3").warning("retrying request")

shop.cart DEBUG cart recalculated
urllib3 WARNING retrying request

Rule: libraries only create loggers and log to them; the application's entry point configures handlers and levels, once, at start-up.

Logging exceptions#

Inside an except block, logger.exception() logs at ERROR level and includes the full traceback:

import logging

logging.basicConfig(format="%(levelname)s %(message)s")
logger = logging.getLogger("importer")


def parse_row(row):
    return int(row["qty"])


try:
    parse_row({"qty": "seven"})
except ValueError:
    logger.exception("failed to parse row")

ERROR failed to parse row
Traceback (most recent call last):
  File "...", line 12, in <module>
    parse_row({"qty": "seven"})
    ~~~~~~~~~^^^^^^^^^^^^^^^^^^
  File "...", line 8, in parse_row
    return int(row["qty"])
ValueError: invalid literal for int() with base 10: 'seven'

This is the pattern for top-level error handlers: catch, log with traceback, and either continue or exit cleanly.

Handlers, formatters and files#

basicConfig covers simple scripts. Real applications attach handlers (where logs go) with formatters (how they look). A common setup: INFO to the console, DEBUG to a rotating file:

import logging
from logging.handlers import RotatingFileHandler
from pathlib import Path

logger = logging.getLogger("app")
logger.setLevel(logging.DEBUG)

console = logging.StreamHandler()
console.setLevel(logging.INFO)
console.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))

file_handler = RotatingFileHandler("app.log", maxBytes=1_000_000, backupCount=3, encoding="utf-8")
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(logging.Formatter("%(asctime)s %(name)s %(levelname)s %(message)s"))

logger.addHandler(console)
logger.addHandler(file_handler)

logger.debug("only in the file")
logger.info("in both places")

lines = Path("app.log").read_text(encoding="utf-8").splitlines()
print(len(lines), "lines in app.log; last ends with:", lines[-1].split()[-3:])

INFO: in both places
2 lines in app.log; last ends with: ['in', 'both', 'places']

RotatingFileHandler starts a new file when the current one reaches maxBytes, keeping backupCount old files — so logs never fill your disk. For larger apps, configure everything from a dict with logging.config.dictConfig. In containers and cloud platforms, the norm is to log to stdout, often as JSON lines, and let the platform collect them.

Never log secrets: passwords, tokens, full card numbers or personal data.

Debugging with breakpoint() and pdb#

When you need to see what's happening inside a running program, drop a breakpoint() call where you want to pause:

def average(scores):
    total = 0
    for s in scores:
        total += s
    breakpoint()                 # execution pauses here
    return total / len(scores)


print(average([80, 90, 100]))

Running it opens the pdb prompt:

> /home/you/buggy.py(5)average()
-> breakpoint()                 # execution pauses here
(Pdb) p total
270
(Pdb) p len(scores), scores
(3, [80, 90, 100])
(Pdb) c
90.0

(p total and the other commands are what you type. On Python 3.12 the arrow points at the line after breakpoint(); 3.13 stops on the call itself.)

The essential pdb commands:

Other ways in: python3 -m pdb script.py starts a script under the debugger; pytest --pdb opens pdb at the point a test fails; and after a crash in the REPL, import pdb; pdb.pm() inspects the post-mortem state. Set the environment variable PYTHONBREAKPOINT=0 to disable all breakpoint() calls without removing them.

Graphical debuggers

VS Code and PyCharm offer the same features with a GUI: click in the gutter to set breakpoints, press F5, then hover over variables, watch expressions and step through code. Conditional breakpoints ("pause only when order_id == 1042") are invaluable for bugs that only show up on the 10,000th iteration.

A systematic debugging process#

Tools help, but method matters more:

1. Reproduce the bug reliably — ideally as a failing test.
2. Read the traceback bottom-up. The last line says what; the frames above say where.
3. Form a hypothesis ("scores is empty here") and check it with a breakpoint, a log line, or an assert.
4. Narrow it down: comment out halves, use smaller inputs, git bisect to find the commit that broke it.
5. Fix, then add a test so the bug can never come back.
6. Explain the problem out loud (to a colleague or a rubber duck) — it works surprisingly often.

Quick inspection helpers worth knowing: print(f"{value=}"), type(x), dir(obj), vars(obj), repr(x) (reveals hidden whitespace like 'abc\n'), and the pprint module for nested data.

from pprint import pprint

order = {"id": 7, "items": [{"sku": "KB-01", "qty": 1}, {"sku": "MS-02", "qty": 2}], "customer": {"name": "Ada", "city": "Pune"}}
pprint(order, width=60)

{'customer': {'city': 'Pune', 'name': 'Ada'},
 'id': 7,
 'items': [{'qty': 1, 'sku': 'KB-01'},
           {'qty': 2, 'sku': 'MS-02'}]}

Assertions for internal sanity checks#

assert condition, message raises AssertionError if the condition is false. Use it to document and check assumptions inside your code — never for validating user input, because asserts are removed when Python runs with -O:

def apply_discount(price, percent):
    result = price * (1 - percent / 100)
    assert 0 <= result <= price, f"discount produced {result} from {price}"
    return result


print(apply_discount(200, 25))

150.0

Common mistakes#

• Leaving print debugging and breakpoint() calls in committed code — a linter like ruff can flag them.
• Calling basicConfig in library modules — only the application should configure logging.
• Logging and re-raising at every level, producing the same traceback five times. Log once, where you handle the error.
• Swallowing exceptions silently (except: pass) — at least log them.
• Logging sensitive data.
• Guessing instead of observing — use the debugger and verify hypotheses.

What's next#

Your programs are now tested and observable. Next we'll make them do several things at once: concurrency with threads, processes and asyncio.