Python Testing & Debugging Beyond unittestAdvanced Python testing playbooks
Pytest & CI

Capturing Logs with caplog and log_cli

Logging sits in an awkward place in a test suite. Most of it is diagnostic — useful when a test fails, irrelevant when it passes — and a few records are contractual, such as an audit trail or a security event that must be emitted. pytest's logging integration handles both: every test's records are captured and attached to its failure report automatically, and caplog exposes them for the small number of tests that need to assert on them.

Done well, this costs almost nothing: two or three configuration lines, a fixture that quiets the chattier libraries, and a habit of asserting on fields rather than wording. Done badly, it produces failure reports too noisy to read and log assertions too brittle to maintain. The two mistakes to avoid are opposite ones. Asserting on log wording couples tests to strings nobody considers stable, so a rephrased message breaks a dozen tests. And capturing at the wrong level — raising the root logger to DEBUG to see one module's records — floods every failure report with output from every library in the process.

Prerequisites

Solution

TOML
# pyproject.toml
[tool.pytest.ini_options]
log_level = "INFO"                        # captured for failure reports
log_format = "%(levelname)-5s %(name)s: %(message)s"
log_cli = false                           # off by default; enable per run
log_cli_level = "INFO"
Python
import logging


def test_refund_emits_an_audit_record(caplog, billing):
    # Scope the capture to the logger that owns the contract.
    caplog.set_level(logging.INFO, logger="myapp.audit")

    billing.refund(order_id="ord_1", amount_minor=4999)

    audit = [r for r in caplog.records if r.name == "myapp.audit"]
    assert len(audit) == 1
    # Fields, not wording: the message can be rephrased without breaking this.
    assert audit[0].levelname == "INFO"
    assert audit[0].event == "refund_issued"
    assert audit[0].order_id == "ord_1"
Bash
# Watching a slow test live, for one run only.
pytest tests/test_sync.py -o log_cli=true -o log_cli_level=DEBUG -k stuck
Two consumers of the same log records A log record emitted by application code reaches pytest's handlers at the root logger. The capture handler stores it for caplog assertions and for the failure report. The live handler, when log_cli is enabled, writes it to the terminal immediately. Each handler has its own level. One record, two destinations, independent levels logger.info(…) myapp.audit root logger if propagate is on capture handler caplog.records + failure report live handler terminal, only with log_cli
A logger with propagate = False never reaches either handler, which is the usual reason caplog appears to capture nothing.

Why this works

pytest installs its own handlers on the root logger for the duration of each test. The capture handler stores every record at or above log_level — or the level set with caplog.set_level — and that storage is what caplog.records exposes and what appears under "Captured log call" when a test fails. The live handler, active only with log_cli, writes records to the terminal as they are emitted, which is the only way to see output from a test that never finishes.

caplog.set_level with a logger argument sets the level on that specific logger for the duration of the test and restores it afterwards. Setting it on the named logger rather than the root is what keeps capture precise: records from other libraries stay at their own levels and do not flood the report.

Edge cases and failure modes

  • propagate = False. Records never reach the root, so neither handler sees them. Re-enable propagation in a fixture for tests that need it.
  • logging.basicConfig at import. Installs a second handler on the root, so every record appears twice. Configure logging in an entry point, never at module import.
  • Asserting on caplog.text. Couples the test to the format string and the wording. Assert on records and their attributes.
  • Records from setup and teardown. caplog.records covers the call phase; caplog.get_records("setup") retrieves the others when a fixture's logging matters.
  • Leaving log_cli on in configuration. Every run streams everything, which makes output unreadable for a whole suite. Enable it per run.

Choosing capture levels for the whole suite

The log_level setting in configuration decides what every failing test's report contains, and it is worth choosing deliberately rather than leaving at pytest's default.

Too low — DEBUG across the board — and a failure report includes every debug line from every library in the process: HTTP connection pools announcing reuse, ORMs printing SQL, retry libraries narrating their back-off. The one line that explains the failure is somewhere in several hundred. Too high — WARNING — and the operational narrative that would have explained the failure is gone, because it was logged at INFO.

INFO at the root, with specific noisy libraries raised to WARNING, is the configuration that works for most applications. It keeps the application's own narrative in every failure report and removes the chatter that nobody reads. The raised levels belong in a session-scoped fixture that sets them once, so every test inherits the same quiet baseline.

Python
import logging

import pytest

NOISY = ("urllib3", "botocore", "asyncio", "sqlalchemy.engine.Engine")


@pytest.fixture(autouse=True, scope="session")
def quiet_libraries():
    for name in NOISY:
        logging.getLogger(name).setLevel(logging.WARNING)

When a specific failure needs more detail, a single run with -o log_level=DEBUG provides it without changing the baseline for everyone. Keep the list of quietened libraries short and review it occasionally, since a library that was noisy two years ago may now log only what matters.

What a failure report contains at each capture level Three failure reports. At DEBUG everywhere the report is dominated by library chatter with the relevant line buried. At WARNING the application's informational narrative is missing. At INFO with noisy libraries raised to WARNING, the report contains the application's narrative and little else. The right level makes the report readable DEBUG everywhere the clue is buried WARNING everywhere the narrative is missing INFO, libraries quiet the story, and the clue
The right-hand report is short enough to read in full, which is what makes it useful.

Log records as evidence in CI

Captured logs are most valuable in CI, where a failure cannot be re-run interactively and the report is all there is. Two settings make sure they arrive intact. junit_logging = "all" copies captured records into the JUnit XML for failing tests, so dashboards show them next to the failure. And a consistent format with the logger name and, where available, a correlation id lets a reader filter the relevant lines out of an interleaved run under pytest-xdist.

The payoff is the same one this site returns to repeatedly: a failure report that contains enough to diagnose the problem without running anything again. Logs captured at the right level, with the right format, attached to the right report, are the cheapest way to get there. They require no extra instrumentation in the tests themselves, only a few decisions made once in configuration and then left alone, which is why they are worth making carefully on day one rather than revisiting after the first frustrating CI failure.

Deciding which log lines deserve an assertion

The large majority of log statements in an application should never appear in a test assertion, and the discipline of keeping it that way is what stops logging tests from becoming a maintenance burden.

A log line deserves an assertion when something outside the codebase depends on it. Audit records consumed by a compliance process, security events that trigger alerts, operational messages referenced in a runbook, metrics derived from log parsing — each of these is an interface, and changing it silently would break something downstream. Tests on those lines are contract tests, and they should assert on the structured fields the consumer reads.

A log line does not deserve an assertion when it exists for a developer reading output during debugging. Those lines should be free to change wording, level and content as the code evolves, and a test pinning them converts every improvement into a test update. They still earn their keep in tests — they appear automatically in failure reports — without any test asserting on them.

Contractual versus diagnostic log lines Two columns. Contractual log lines such as audit records, security events and runbook messages are consumed outside the code and deserve assertions on their structured fields. Diagnostic log lines exist for developers and should never be asserted on, though they appear automatically in failure reports. Assert on interfaces; let diagnostics change freely contractual audit trail, security events runbook messages, log metrics assert on structured fields something downstream depends on it diagnostic "retrying", "cache miss", "parsed 12 rows" never assert shown in failure reports anyway
Most suites have a handful of tests in the left column and none in the right. A suite with many log-wording assertions has put diagnostic lines in the wrong column.

When a contractual log line does need testing, the test belongs next to the code that emits it and should read like any other contract test: arrange the operation, perform it, assert that exactly one record with the expected event name and fields was emitted. Asserting on the count as well as the content catches the duplicated audit record, which is a real and surprisingly common defect when a retry loop logs before rather than after deciding to retry. It also catches the opposite regression, where a refactor moves the logging call behind a condition that the test's scenario no longer satisfies, and the record silently stops being written for the case that mattered.

Frequently Asked Questions

Why is caplog.records empty when my code clearly logged something? Usually the logger's effective level is higher than the record's, or the logger has propagate set to False so records never reach the root handler caplog attaches to. Call caplog.set_level with the specific logger name and check that propagation is on.

What is the difference between caplog.text and caplog.records?caplog.text is the formatted output as a single string; caplog.records is the list of LogRecord objects with their attributes. Assert on records and their fields for anything durable, since the formatted text changes whenever the format string or the message wording changes.

Does log_cli affect what caplog captures? No. log_cli streams records to the terminal as they happen; caplog captures them for assertions. Both can be active at once, and each has its own level setting.

← Back to pytest Configuration Best Practices