Python Logging Tutorial: Best Practices and Examples

An alert fires at night: payments are failing. You open the logs and find four thousand lines that say Error occurred. There is no traceback, no order ID, and no way to tell which request each line belongs to. The code that wrote those lines did call a logging function. It just recorded nothing you could use.

Python logging is the practice of recording events from a running program through the standard library’s logging module. Each event carries a severity level, a timestamp, the name of the logger that produced it, and a message. Configuration then decides which events are kept and where they go.

This guide uses Python 3.10 and only the standard library, so there is nothing to install. Run python --version to confirm your interpreter. You should know how to write functions and how try and except work.

My position: learn the standard logging module properly before you adopt any third-party logging library. Every library you depend on already uses it, so you must understand it either way.

How Python logging works

Four objects cooperate on every log call. Once you can picture them, the configuration stops feeling arbitrary.

logger.info('charging order %s', 42)
      |
      v
  Logger 'shop.payments'     level check: is INFO enabled here?  no -> dropped (cheap)
      |  creates a LogRecord
      v
  propagates up the name hierarchy:  shop.payments -> shop -> root
      |
      v
  Handler (on root)          where it goes: stdout, a file, a socket
      |  optional Filter     adds fields or rejects the record
      v
  Formatter                  how it looks: plain text or JSON
      |
      v
  {"level": "INFO", "logger": "shop.payments", "message": "charging order 42"}

Loggers form a tree based on dotted names. A record created by shop.payments travels up to shop and then to the root logger, and every handler along the way receives it. Consequently, you normally attach handlers to the root only, and let every module’s logger propagate to it.

The failure model

Logging goes wrong in a small number of ways. Each practice below prevents one of them.

Practice 1: log exceptions with their traceback

This practice has the highest impact, because it decides whether an error is diagnosable at all.

# WRONG: one line of text, no traceback, no location
try:
    charge(order)
except Exception as error:
    logger.error(f'Error occurred: {error}')

# RIGHT: logger.exception records the full traceback at ERROR level
try:
    charge(order)
except PaymentError:
    logger.exception('charge failed for order %s', order.id)
    raise

logger.exception() is logger.error() with exc_info=True. Call it only inside an except block. The right version also catches a specific exception and re-raises it, so the caller still learns about the failure. It pairs well with the habit to handle exceptions at one boundary, which avoids logging the same error at every layer.

Verify: search your code for handlers that log without a traceback.

grep -rn "logger.error(" src/ | grep -v "exc_info"

Review each match that sits inside an except block.

Practice 2: create one named logger per module

# WRONG: module-level functions log through the root logger
import logging

logging.info('cache warmed')

# RIGHT: a logger named after the module
import logging

logger = logging.getLogger(__name__)

logger.info('cache warmed')

__name__ is the module’s dotted import path, such as shop.payments. The name appears in every record, so you can see where a line came from. It also lets you tune one area, for example setting shop.payments to DEBUG while the rest stays at INFO.

The wrong version has a second, hidden problem. Calling logging.info() before any configuration triggers an implicit basicConfig(), which attaches a handler to the root logger. Your real configuration may then be ignored or doubled.

Verify: grep -rnE "logging\.(debug|info|warning|error|critical)\(" src/ should return nothing.

Practice 3: configure once, at the entry point, with dictConfig

Modules create loggers. Only the program’s start-up code configures them.

# WRONG: a library module configures logging on import
import logging

logging.basicConfig(level=logging.DEBUG, filename='lib.log')

# RIGHT: configuration lives in main(), as one dictionary
import logging.config

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'plain': {'format': '%(asctime)s %(levelname)s %(name)s %(message)s'},
    },
    'handlers': {
        'stdout': {
            'class': 'logging.StreamHandler',
            'stream': 'ext://sys.stdout',
            'formatter': 'plain',
        },
    },
    'root': {'level': 'INFO', 'handlers': ['stdout']},
}


def main() -> None:
    logging.config.dictConfig(LOGGING)

Two details in that dictionary prevent the most confusing logging bugs I know, and both are easy to miss in the documentation.

First, disable_existing_loggers defaults to True. With the default, dictConfig silently disables every logger that already exists. Module-level loggers are created at import time, which is usually before main() runs. The result is a program whose own modules log nothing, while the configuration looks correct. Always set it to False.

Second, basicConfig() does nothing if the root logger already has a handler. If any imported module configured logging first, your call is a silent no-op. That is why libraries must never configure logging. A library that wants to be quiet by default adds only a logging.NullHandler() to its top-level logger.

Put the configuration call in your project’s entry point, such as the main() function behind your command-line script.

Verify: grep -rn "basicConfig\|dictConfig" src/ should show exactly one call site.

Practice 4: attach context to every record

A message is far more useful when you can tie it to a request, a user, or a job.

# WRONG: context is glued into the message text by hand, when someone remembers
logger.info(f'[{request_id}] charging order {order_id}')

# RIGHT: a filter adds the context to every record automatically
import contextvars
import logging

request_id = contextvars.ContextVar('request_id', default='-')


class RequestIdFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = request_id.get()
        return True

A ContextVar holds a value that is local to the current thread or async task. You set it once when a request starts. The filter then copies it onto every record, including records from third-party libraries. For a single call, the extra argument works too: logger.info('charged', extra={'order_id': 42}).

Verify: the complete example below includes a test that checks the field.

Practice 5: emit structured JSON in production

# WRONG: free text that a log system must parse with regular expressions
2 items charged for user 17 in 0.21s

# RIGHT: one JSON object per line, with named fields
{"level": "INFO", "logger": "shop.payments", "message": "charged", "user_id": 17, "items": 2}

Log platforms index JSON fields, so you can filter by user_id or count errors per logger without writing a parser. The standard library has no JSON formatter, but writing one takes fifteen lines, as the complete example shows. The trade-off is readability in a terminal, so many teams use plain text locally and JSON in deployed environments.

Verify: pipe one line of output through python -m json.tool. It fails loudly if the line is not valid JSON.

Practice 6: choose levels by who must act

# WRONG: a user typo is not an application error
logger.error('login failed: wrong password for %s', username)

# RIGHT: expected outcomes are INFO, and ERROR means someone should look
logger.info('login rejected for %s', username)

If ERROR fires for routine events, alerts on the error rate become useless. Reserve it for failures that a person should investigate.

Verify: count records per level in a day of logs. If ERROR outnumbers INFO, your levels are wrong.

Practice 7: let the logger format the message

# WRONG: the f-string is built even when DEBUG is disabled
logger.debug(f'payload: {payload}')

# RIGHT: arguments are formatted only if the record is emitted
logger.debug('payload: %s', payload)

With the right version, a disabled call returns after one level check. You can measure the difference. These are my own illustrative commands, and your numbers will vary:

python -m timeit -s "import logging; log = logging.getLogger('t'); log.setLevel(logging.INFO); data = list(range(1000))" "log.debug('data %s', data)"
python -m timeit -s "import logging; log = logging.getLogger('t'); log.setLevel(logging.INFO); data = list(range(1000))" "log.debug(f'data {data}')"

On my machine, the first command costs tens of nanoseconds per call. The second costs tens of microseconds, because it converts a thousand-item list to text and then throws the text away. That is a difference of about three orders of magnitude for a line that prints nothing.

The constant message template has a second benefit. Error trackers and log platforms group records by template, so 'payload: %s' counts as one event type instead of thousands.

Verify: grep -rnE "logger\.[a-z]+\(f['\"]" src/ lists every f-string log call.

Practice 8: keep secrets and personal data out

# WRONG: the whole request, including the Authorization header and card number
logger.info('request: %s', request.__dict__)

# RIGHT: log identifiers, never credentials or full payloads
logger.info('request received', extra={'path': request.path, 'user_id': user.id})

Logs are copied to more systems, and read by more people, than your database. Treat them as less protected. Log IDs that let you look up the data, not the data itself. As a safety net, a filter can mask known patterns:

import logging
import re

TOKEN = re.compile(r'(Bearer\s+)[A-Za-z0-9._-]+')


class RedactTokens(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.msg = TOKEN.sub(r'\1[REDACTED]', str(record.msg))
        return True

A redacting filter catches mistakes, but it cannot know every secret format. The reliable control is not passing secrets to the logger in the first place.

Verify: search a sample of real log output for Bearer, password, and sk-.

Practice 9: write to standard output in services

# WRONG for a deployed service: the application owns a file path
'handlers': {'file': {'class': 'logging.FileHandler', 'filename': '/var/log/app.log'}}

# RIGHT: write to stdout, and let the platform collect and ship it
'handlers': {'stdout': {'class': 'logging.StreamHandler', 'stream': 'ext://sys.stdout'}}

Process managers and hosting platforms capture standard output and handle storage and rotation. An application that writes its own files must also manage disk space and permissions. On a single long-lived host without such a platform, use logging.handlers.RotatingFileHandler so the file cannot fill the disk.

Verify: run the program and confirm that log lines appear in the terminal with no file created.

A complete example: JSON logs with request context

This script combines practices 1 to 5, 7, and 9. Save it as app.py.

import contextvars
import json
import logging
import logging.config

request_id = contextvars.ContextVar('request_id', default='-')


class RequestIdFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = request_id.get()
        return True


class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload = {
            'time': self.formatTime(record, '%H:%M:%S'),
            'level': record.levelname,
            'logger': record.name,
            'message': record.getMessage(),
            'request_id': getattr(record, 'request_id', '-'),
        }
        if record.exc_info:
            payload['exception'] = self.formatException(record.exc_info)
        return json.dumps(payload)


LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'filters': {'request_id': {'()': RequestIdFilter}},
    'formatters': {'json': {'()': JsonFormatter}},
    'handlers': {
        'stdout': {
            'class': 'logging.StreamHandler',
            'stream': 'ext://sys.stdout',
            'formatter': 'json',
            'filters': ['request_id'],
        },
    },
    'root': {'level': 'INFO', 'handlers': ['stdout']},
}

logger = logging.getLogger(__name__)


def charge(order_id: int, amount: float) -> None:
    logger.info('charging order %s', order_id)
    if amount <= 0:
        raise ValueError(f'invalid amount: {amount}')


def handle_request(req_id: str, order_id: int, amount: float) -> None:
    request_id.set(req_id)
    try:
        charge(order_id, amount)
    except ValueError:
        logger.exception('charge failed for order %s', order_id)


def main() -> None:
    logging.config.dictConfig(LOGGING)
    handle_request('req-1', 42, 19.99)
    handle_request('req-2', 43, 0)


if __name__ == '__main__':
    main()

python app.py

{"time": "10:15:02", "level": "INFO", "logger": "__main__", "message": "charging order 42", "request_id": "req-1"}
{"time": "10:15:02", "level": "INFO", "logger": "__main__", "message": "charging order 43", "request_id": "req-2"}
{"time": "10:15:02", "level": "ERROR", "logger": "__main__", "message": "charge failed for order 43", "request_id": "req-2", "exception": "Traceback (most recent call last): ... ValueError: invalid amount: 0"}

The exception field is shortened here. In real output it holds the full traceback with file names and line numbers. The example prints only the time of day to keep lines short. In production, use a full ISO 8601 timestamp in UTC.

Test your logging

Logs are part of your program’s behavior, so test the important ones. The standard library’s unittest can capture records. Save this as test_app.py next to app.py.

import unittest

from app import handle_request


class ChargeLoggingTest(unittest.TestCase):
    def test_failed_charge_logs_traceback(self) -> None:
        with self.assertLogs('app', level='ERROR') as captured:
            handle_request('req-9', 7, 0)
        record = captured.records[0]
        self.assertIsNotNone(record.exc_info)
        self.assertIn('order 7', record.getMessage())


if __name__ == '__main__':
    unittest.main()

python -m unittest test_app.py

.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK

The myth: print is good enough

Many scripts and small services still report events with print(), on the theory that logging is the same thing with more ceremony. The two differ in exactly the ways that matter during an incident.

print() remains the right tool for the actual output of a command-line program, such as the result a user asked for. It is the wrong tool for diagnostics.

The standard library compared with structlog and loguru

The copy-paste checklist

How real systems structure logging

• Configuration from the environment. The log level comes from a variable such as LOG_LEVEL, so operators can raise detail without a code change.
• A correlation ID set at the edge. Middleware reads or creates a request ID, stores it in a ContextVar, and returns it in a response header. Support staff can then find every line for one request.
• Quiet third-party loggers. Configuration sets noisy libraries, such as urllib3, to WARNING by name, while application loggers stay at INFO.
• A shared call-logging helper. Teams wrap service functions with a decorator that logs duration and outcome, so the format stays identical everywhere.
• One error log per failure. The boundary handler logs the traceback once. Inner layers add context and re-raise without logging.

We once hit a bug when a service went completely silent after a refactor. The start-up code had moved from basicConfig to dictConfig, and nobody set disable_existing_loggers. Every module-level logger had been created at import time, so the new configuration disabled all of them. The process ran normally and logged only the framework’s own start-up line. It took an hour to find, and one line to fix.

Deciding what to log: a decision framework

1. Would this line help you diagnose a failure at night? If not, do not log it, or log it at DEBUG.
2. Does a person need to act on it? Use ERROR or CRITICAL. Otherwise use INFO or WARNING.
3. Is it a number you want to graph? Send it to a metrics system instead. Logs are for events, not time series.
4. Does it contain user data or credentials? Log an identifier in its place.
5. Will it fire inside a hot loop? Log a summary after the loop, not one line per item.

When NOT to use the logging module

• For a command-line tool’s real output. Results the user asked for belong on standard output through print(), so they can be piped. Send diagnostics to logging on standard error.
• For metrics. Counting requests by parsing log lines is slow and fragile. A metrics library records counts and durations directly.
• For audit trails that must not be lost. Log pipelines can drop or delay lines. Records that you are legally required to keep belong in a database, written in the same transaction as the change.

Common mistakes

• Leaving disable_existing_loggers at its default. dictConfig then switches off loggers created at import time. Your modules go silent.
• Calling basicConfig in several places. Only the first call takes effect, so the format and level depend on import order.
• Adding handlers to child loggers and to root. Records propagate upward, so each line prints twice.
• Logging and re-raising at every layer. One failure produces five tracebacks, and readers cannot tell how many errors happened.
• Using logger.exception outside an except block. There is no active exception, so the record ends with NoneType: None.
• Passing a pre-formatted f-string. You pay the formatting cost on disabled levels, and log platforms cannot group records by template.

Key takeaways

• Use logging.getLogger(__name__) in every module.
• Configure logging exactly once, at the entry point, with dictConfig.
• Set disable_existing_loggers to False.
• Log caught exceptions with logger.exception() so the traceback survives.
• Pass arguments to the logger with %s placeholders, and do not use f-strings.
• Add a request or job ID through a filter and a ContextVar.
• Emit JSON to standard output in production, and keep secrets out.

FAQ

How do I set up logging in Python?

Create a logger in each module with logging.getLogger(__name__). Then configure handlers, formatters, and levels once in your program’s entry point, using logging.config.dictConfig or logging.basicConfig.

What are the logging levels in Python?

There are five standard levels, in increasing severity: DEBUG, INFO, WARNING, ERROR, and CRITICAL. A logger emits records at its configured level and above.

What is the difference between logging and print in Python?

print() writes text to standard output. logging adds severity levels, timestamps, source names, tracebacks, and configurable destinations, and you can adjust it without editing code.

How do I log an exception with its traceback?

Call logger.exception('message') inside an except block. It logs at ERROR level and appends the full traceback.

Why are my Python logs printed twice?

The record reaches two handlers. This usually happens when you add a handler to a named logger and another to the root logger. Attach handlers to the root only, or set propagate to False on the child.

Log for the person reading at night

Logging is written during calm development and read during an incident. Each practice here makes that later reading faster: a traceback, a source name, a request ID, and fields you can query. Configure it once, and test the lines you depend on.

Rule of thumb: if a log line cannot tell you what failed, where, and for whom, it is noise with a timestamp.