Type something to search...
Logging in Python: Moving Beyond print()

Logging in Python: Moving Beyond print()

Every Python program starts out debugging with print(). It's immediate and it works. Then the program grows: it runs on a server where nobody watches the terminal, you need to know when something happened, you want the noisy debug output gone in production but back on when a bug shows up, and you want errors written to a file with full tracebacks. Now you're commenting print calls in and out, and they're mixed into the program's real output.

The logging module solves all of that, and it's in the standard library. Each message gets a severity level, a timestamp, and the name of the module that produced it. Where messages go, how they look, and which ones are shown is configured in one place, separate from the code that emits them.

This guide covers levels, named loggers, handlers and formatters, configuring logging for a real application with dictConfig, logging exceptions, structured JSON logs, and the mistakes that cause missing or duplicated messages.

Why Not Just print()?

print() has a few problems that get worse as a program grows:

  • No severity. A debug detail and a fatal error look the same.
  • No on/off switch. You can't silence debug output without editing code.
  • One destination. Everything goes to standard output, mixed in with the program's actual output.
  • No context. No timestamp, no module name, no line number, unless you add them by hand every time.

With logging, the code says what happened and how serious it is. Configuration decides everything else.

The Quickest Possible Start

You can call the module-level functions directly:

import logging

logging.warning("Disk space is low")
logging.info("This will not appear")
WARNING:root:Disk space is low

Two things to notice. The info message vanished, because the default threshold is WARNING. And the format is bare: level, logger name (root), message. Both are fixed with basicConfig.

Log Levels

Every message has a level. A logger only passes on messages at or above its configured level.

LevelValueUse it for
DEBUG10Detailed internals you only need while diagnosing a problem
INFO20Normal, noteworthy events: startup, requests, jobs completed
WARNING30Something unexpected that the program handled
ERROR40An operation failed
CRITICAL50The program itself may not be able to continue

Setting the level to INFO shows INFO, WARNING, ERROR, and CRITICAL, and hides DEBUG. That's the whole filtering model, and it's what lets you leave debug statements in your code permanently.

basicConfig: Good Enough for Scripts

basicConfig sets up the root logger with a level and a format in one call:

import logging

logging.basicConfig(
    level=logging.DEBUG,
    format="%(asctime)s %(levelname)-8s %(name)s: %(message)s",
    datefmt="%H:%M:%S",
)
logger = logging.getLogger("shop.orders")

logger.debug("Loaded %d orders from cache", 42)
logger.info("Order %s placed by %s", "A-1001", "ada")
logger.warning("Payment retry %d/%d", 2, 3)
logger.error("Could not reach inventory service")
logger.critical("Database unavailable, shutting down")
07:05:12 DEBUG    shop.orders: Loaded 42 orders from cache
07:05:12 INFO     shop.orders: Order A-1001 placed by ada
07:05:12 WARNING  shop.orders: Payment retry 2/3
07:05:12 ERROR    shop.orders: Could not reach inventory service
07:05:12 CRITICAL shop.orders: Database unavailable, shutting down

The format string uses LogRecord attributes. The ones you'll use most:

PlaceholderMeaning
%(asctime)sTime the record was created
%(levelname)sDEBUG, INFO, ...
%(name)sLogger name
%(message)sThe formatted message
%(module)s, %(funcName)s, %(lineno)dWhere the call happened
%(process)d, %(threadName)sProcess ID and thread name

basicConfig only does something the first time it's called, and only if the root logger has no handlers yet. If a call seems to be ignored, something else configured logging first. Pass force=True to replace the existing setup.

Pass Arguments, Don't Pre-Format

Notice the calls above use logger.info("Order %s placed by %s", order_id, user) rather than an f-string. That's intentional. The arguments are only merged into the message if the record is actually going to be emitted. With an f-string, the string is built every time, even for a debug message that gets thrown away (assume state and expensive_repr are defined elsewhere):

logger.debug(f"State: {expensive_repr(state)}")   # always calls expensive_repr
logger.debug("State: %s", expensive_repr(state))  # still evaluates the argument...

To be precise, the second form still evaluates expensive_repr(state) because it's a normal function argument. What it skips is the string formatting. If the argument itself is expensive, guard it:

if logger.isEnabledFor(logging.DEBUG):
    logger.debug("State: %s", expensive_repr(state))

The %s style also keeps the message template constant, which lets log aggregation tools group "Order %s placed" events together regardless of the order ID.

Named Loggers: One per Module

Instead of calling logging.info() on the root logger, create a logger per module:

# myapp/orders.py
import logging

logger = logging.getLogger(__name__)


def place_order(order_id: str, total: float) -> None:
    logger.debug("Validating order %s", order_id)
    logger.info("Order %s placed, total %.2f", order_id, total)

__name__ is the module's dotted import path, such as myapp.orders, so every message records exactly where it came from. getLogger returns the same object for the same name, so there's no need to pass loggers around.

The dots matter. Loggers form a hierarchy: myapp.orders is a child of myapp, which is a child of the root logger. Two rules follow from that:

  1. Levels are inherited. If myapp.orders has no level set, it uses the nearest ancestor's level. Setting myapp to DEBUG turns on debug output for your whole package.
  2. Records propagate upward. A message logged on myapp.orders is passed to the handlers of myapp and then the root logger. So you typically attach handlers once, at the root, and every module's messages flow there.

That's why library code and application modules should only ever call getLogger(__name__) and log. They shouldn't add handlers or call basicConfig. Configuration is the application's job, done once at startup.

Handlers and Formatters

A logger decides whether a message is emitted. A handler decides where it goes, and a formatter decides what it looks like. One logger can have several handlers, each with its own level and format.

A common setup sends INFO and above to the console in a short format, and everything including DEBUG to a file in a detailed format:

import logging
import sys

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

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

logfile = logging.FileHandler("app.log", encoding="utf-8")
logfile.setLevel(logging.DEBUG)
logfile.setFormatter(
    logging.Formatter("%(asctime)s %(levelname)s %(name)s [%(funcName)s:%(lineno)d] %(message)s")
)

logger.addHandler(console)
logger.addHandler(logfile)

logger.debug("Cache warmed with %d keys", 120)
logger.info("Server started on port %d", 8000)
logging.getLogger("shop.payments").warning("Card declined for order %s", "A-1002")

The console shows:

INFO: Server started on port 8000
WARNING: Card declined for order A-1002

And app.log gets everything:

2026-09-20 07:05:00,123 DEBUG shop [<module>:20] Cache warmed with 120 keys
2026-09-20 07:05:00,123 INFO shop [<module>:21] Server started on port 8000
2026-09-20 07:05:00,123 WARNING shop.payments [<module>:22] Card declined for order A-1002

Filtering happens twice: first at the logger's level, then at each handler's level. The logger is set to DEBUG so nothing is dropped early, and each handler picks what it wants. The shop.payments message reached both handlers through propagation, even though the handlers are attached to shop.

Some handlers worth knowing, all in logging or logging.handlers:

HandlerWrites to
StreamHandlersys.stderr by default, or any stream
FileHandlerA file
RotatingFileHandlerA file, rolled over at a size limit
TimedRotatingFileHandlerA file, rolled over by time (e.g. midnight)
SysLogHandlerThe system log
QueueHandler / QueueListenerA queue, so slow I/O happens off the main thread
NullHandlerNowhere (used by libraries)

Note that logging writes to standard error by default, not standard output. That's what you want: a command-line tool's real output stays clean on stdout, and diagnostics go to stderr.

Configuring a Real Application with dictConfig

Wiring handlers by hand gets verbose. For applications, logging.config.dictConfig describes the whole setup as a dictionary, which is easier to read and easy to load from a file if you want:

# myapp/logging_config.py
import logging.config
from pathlib import Path

LOG_DIR = Path("logs")


def setup_logging(level: str = "INFO") -> None:
    LOG_DIR.mkdir(exist_ok=True)
    logging.config.dictConfig(
        {
            "version": 1,
            "disable_existing_loggers": False,
            "formatters": {
                "simple": {"format": "%(levelname)s %(name)s: %(message)s"},
                "detailed": {
                    "format": "%(asctime)s %(levelname)s %(name)s %(process)d %(message)s",
                },
            },
            "handlers": {
                "console": {
                    "class": "logging.StreamHandler",
                    "formatter": "simple",
                    "level": level,
                    "stream": "ext://sys.stderr",
                },
                "file": {
                    "class": "logging.handlers.RotatingFileHandler",
                    "formatter": "detailed",
                    "level": "DEBUG",
                    "filename": str(LOG_DIR / "app.log"),
                    "maxBytes": 1_000_000,
                    "backupCount": 5,
                    "encoding": "utf-8",
                },
            },
            "loggers": {
                "myapp": {"level": "DEBUG"},
                "urllib3": {"level": "WARNING"},
            },
            "root": {"level": "INFO", "handlers": ["console", "file"]},
        }
    )

Call it once, as early as possible in your entry point:

# main.py
import logging

from myapp.logging_config import setup_logging
from myapp.orders import place_order

setup_logging()
logger = logging.getLogger("myapp")

logger.info("Starting up")
place_order("A-1001", 59.9)
logging.getLogger("urllib3").info("Starting new HTTPS connection")

Console output:

INFO myapp: Starting up
INFO myapp.orders: Order A-1001 placed, total 59.90

And logs/app.log:

2026-09-20 07:05:00,990 INFO myapp 70190 Starting up
2026-09-20 07:05:00,991 DEBUG myapp.orders 70190 Validating order A-1001
2026-09-20 07:05:00,991 INFO myapp.orders 70190 Order A-1001 placed, total 59.90

A few details in this config are worth calling out:

  • "version": 1 is required. It's the schema version, and 1 is the only one.
  • "disable_existing_loggers": False is important. The default is True, which silences every logger that already exists when dictConfig runs. Here myapp.orders was created at import time, before setup_logging() was called, so with the default its messages would silently disappear. Always set this to False.
  • Handlers live on the root logger. Everything propagates there, including third-party libraries.
  • The myapp logger is set to DEBUG, so your own debug messages reach the file handler, while the root stays at INFO for everything else.
  • Noisy libraries are turned down with their own entry. urllib3 (used by requests) is chatty at INFO, so its info message was dropped.
  • RotatingFileHandler caps the file at about 1 MB and keeps 5 old copies (app.log.1 to app.log.5), so logs never fill the disk.

Since it's just a dictionary, you can keep it in a JSON or TOML file and load it at startup, or tweak the level from a command-line flag. If you're building a CLI, mapping -v and -vv to INFO and DEBUG is a common pattern; see building command-line tools with argparse.

Logging Exceptions

When you catch an exception you want to record, use logger.exception() inside the except block. It logs at ERROR level and appends the full traceback:

import logging

logging.basicConfig(level=logging.INFO, format="%(levelname)s %(name)s: %(message)s")
logger = logging.getLogger(__name__)


def parse_price(raw: str) -> float:
    try:
        return float(raw)
    except ValueError:
        logger.exception("Could not parse price %r", raw)
        return 0.0


parse_price("12,50")
ERROR __main__: Could not parse price '12,50'
Traceback (most recent call last):
  File "/home/maria/shop/prices.py", line 9, in parse_price
    return float(raw)
ValueError: could not convert string to float: '12,50'

If you want the traceback at a different level, pass exc_info=True to any logging call, for example logger.warning("Retrying", exc_info=True).

A common anti-pattern is logger.error(str(e)) or logger.error(f"Error: {e}"). You lose the traceback, which is usually the most useful part. And avoid logging an exception and then re-raising it at every layer; you'll get the same traceback five times. Log it once, where it's actually handled. The exception handling guide covers where that should be.

Adding Context to Messages

The extra Argument

extra attaches additional attributes to a log record. They can be referenced in a format string or picked up by a custom formatter:

logger.info("Request handled", extra={"path": "/orders", "status": 201})

If your format string references %(path)s, every message through that handler must supply path, or formatting fails. That makes extra most useful with formatters that handle missing keys, such as the JSON formatter below.

LoggerAdapter for Per-Request Context

When every message in a block of code should carry the same context, like a request ID, wrap the logger in a LoggerAdapter:

import logging

logging.basicConfig(level=logging.INFO, format="%(levelname)s [%(request_id)s] %(message)s")
base = logging.getLogger("api")
log = logging.LoggerAdapter(base, {"request_id": "req-7f3a"})
log.info("Fetching user %d", 42)
INFO [req-7f3a] Fetching user 42

Structured JSON Logs

When logs go to a system like Elasticsearch, Loki, Datadog, or CloudWatch, one JSON object per line is much easier to search than free text. You don't need a library for this; a small Formatter subclass does it:

# json_logging.py
import json
import logging
from datetime import UTC, datetime

STANDARD_ATTRS = set(vars(logging.makeLogRecord({}))) | {"message", "asctime"}


class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload = {
            "time": datetime.fromtimestamp(record.created, tz=UTC).isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        # Anything passed via extra= shows up as a non-standard attribute.
        payload.update(
            {key: value for key, value in vars(record).items() if key not in STANDARD_ATTRS}
        )
        if record.exc_info:
            payload["exception"] = self.formatException(record.exc_info)
        return json.dumps(payload, default=str)


handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])

logger = logging.getLogger("api")
logger.info("Request handled", extra={"path": "/orders", "status": 201, "duration_ms": 18.4})
{"time": "2026-09-20T07:05:00.806690+00:00", "level": "INFO", "logger": "api", "message": "Request handled", "path": "/orders", "status": 201, "duration_ms": 18.4}

STANDARD_ATTRS is built from an empty LogRecord, so anything not in that set must have come from extra. record.getMessage() merges the %s arguments into the message, and default=str keeps json.dumps from failing on values like datetime or Decimal. For more on custom serialization, see working with JSON in Python.

Logging in Libraries

If you're writing a package that other people import, the rules are stricter:

  • Use logging.getLogger(__name__) and log. Nothing else.
  • Never call basicConfig or add a handler to the root logger. That's the application's decision.
  • Optionally add a NullHandler to your package's top-level logger, which is the pattern the logging docs recommend:
# mylib/__init__.py
import logging

logging.getLogger(__name__).addHandler(logging.NullHandler())

Common Pitfalls

Messages appear twice. This almost always means a handler is attached to both a logger and one of its ancestors. The record is handled by the child's handler, then propagates up and is handled again by the root's:

import logging

logging.basicConfig(level=logging.INFO, format="%(levelname)s %(name)s: %(message)s")
logger = logging.getLogger("worker")
logger.addHandler(logging.StreamHandler())
logger.info("Job finished")
Job finished
INFO worker: Job finished

Fix it by attaching handlers in one place (usually the root), or set logger.propagate = False on the child if it really needs its own handler. Re-running setup code that calls addHandler (common in notebooks and tests) causes the same thing.

Debug messages don't show up. Check both levels: the logger's and the handler's. A DEBUG handler on an INFO logger still receives nothing below INFO.

Messages from your modules vanish after configuration. That's disable_existing_loggers defaulting to True in dictConfig or fileConfig. Set it to False.

Configuring at import time. Putting basicConfig at the top of a module means importing that module changes global logging. Keep configuration in your entry point, inside if __name__ == "__main__": or a main() function.

Logging sensitive data. Logs are often shipped to third-party services and kept for a long time. Keep passwords, tokens, and personal data out of messages and extra fields.

Logging vs print: A Quick Rule

Use print() for output that is the program's result: the report a CLI generates, the answer a script computes. Use logging for everything about the program: progress, decisions, warnings, and errors. When you're hunting a bug interactively, a debugger is often faster than either; how to debug a Python program covers that side.

Conclusion

The logging module looks intimidating because of its moving parts, but the model is simple: modules call getLogger(__name__) and log at an appropriate level, and the application configures handlers and formatters once at startup. Pass arguments instead of f-strings, use logger.exception() in except blocks, set disable_existing_loggers to False, and attach handlers in one place to avoid duplicates. Once that's in place, you can turn debug output on with a config change instead of a code change, and your print() calls can go back to printing results.

Tags :
Share :

Related Posts

Abstract Base Classes in Python with the abc Module

Abstract Base Classes in Python with the abc Module

Python leans on duck typing: if an object has the method you need, you call it and move on. That works well until you have a family of classes that a

Continue Reading
*args and **kwargs in Python: Flexible Function Signatures

*args and **kwargs in Python: Flexible Function Signatures

You've seen def wrapper(*args, **kwargs): in decorators, and probably super().__init__(**kwargs) in class hierarchies. These two parameters let a

Continue Reading
Asyncio in Python: A Beginner's Guide to Asynchronous Programming

Asyncio in Python: A Beginner's Guide to Asynchronous Programming

A lot of programs spend most of their time waiting. A web scraper waits for pages to download, an API server waits for the database, a chat bot waits

Continue Reading