← pytest: reliable Python tests Progress & review ↗

Typorithm · medium

Assert log records, not incidental formatting

pythonpytesttestingindependent-practice

Saved on this device

Full lesson · 4 learning steps Open any exercise for focused practice

Step 1 of 4 · intro card

Assert log records, not incidental formatting

Concept and contract

Capture severity and message while keeping diagnostics free of payload data.

Logs are structured diagnostic events with a logger, severity and message. A warning may be part of an explicit operational contract even when a function returns a valid result. Test the record fields that matter rather than a timestamped formatted line.

A logging assertion should not encourage logging secrets or complete user input. In this example only a numeric count is emitted. The message supports diagnosis without copying a request, document, email or authentication value into a log record.

Mechanism and worked example

The complete function logs a warning for negative counts and returns zero.

The complete function logs a warning for negative counts and returns zero. caplog.at_level enables capture for the named logger during the call. The test filters records from that logger and checks the level and rendered message.

caplog.records contains LogRecord objects; getMessage applies the message arguments. Formatter changes should not break this assertion because a timestamp or colour prefix is not part of the required diagnostic. The return value is asserted separately.

Complete worked example

python

import logging

logger = logging.getLogger("owned.counts")


def normalize_count(value):
    if value < 0:
        logger.warning("negative count: %s", value)
        return 0
    return value


def test_negative_count_warning(caplog):
    with caplog.at_level(logging.INFO, logger="owned.counts"):
        assert normalize_count(-1) == 0
    records = [r for r in caplog.records if r.name == "owned.counts"]
    assert [(r.levelname, r.getMessage()) for r in records] == [("WARNING", "negative count: -1")]

Reasoning: The complete function logs a warning for negative counts and returns zero. caplog.at_level enables capture for the named logger during the call. The test filters records from that logger and checks the level and rendered message. caplog.records contains LogRecord objects; getMessage applies the message arguments. Formatter changes should not break this assertion because a timestamp or colour prefix is not part of the required diagnostic. The return value is asserted separately.

Open in local Python playground ↗

Focused test decision: context is in the complete example

python

records = [r for r in caplog.records if r.name == "owned.counts"]
assert records[0].levelname == "WARNING"

Focused test decision: Type this short test decision after understanding the complete runnable module. Desktop typing records practice; Run tests in the local playground executes real pytest.

Counterexamples and common mistakes

The controlled function emits info instead of warning.

The controlled function emits info instead of warning. Capture at INFO still observes the record, but the severity assertion fails. Capturing only WARNING could instead produce an empty list; either outcome needs a clear assertion about the contract.

Do not accept a warning from an unrelated module as evidence that this function logged correctly. Filter by logger or another stable ownership field. Reconfiguring all logging handlers inside a test can interfere with capture; prefer the fixture’s scoped configuration.

Controlled bug: the tests must report failure

python

import logging

logger = logging.getLogger("owned.counts")


def normalize_count(value):
    if value < 0:
        logger.info("negative count: %s", value)
        return 0
    return value


def test_negative_count_warning(caplog):
    with caplog.at_level(logging.INFO, logger="owned.counts"):
        assert normalize_count(-1) == 0
    records = [r for r in caplog.records if r.name == "owned.counts"]
    assert [(r.levelname, r.getMessage()) for r in records] == [("WARNING", "negative count: -1")]

Reasoning: The controlled function emits info instead of warning. Capture at INFO still observes the record, but the severity assertion fails. Capturing only WARNING could instead produce an empty list; either outcome needs a clear assertion about the contract. Do not accept a warning from an unrelated module as evidence that this function logged correctly. Filter by logger or another stable ownership field. Reconfiguring all logging handlers inside a test can interfere with capture; prefer the fixture’s scoped configuration.

Open in local Python playground ↗

Independent practice

Add a valid-count test that asserts the unchanged value and no warning from this logger.

Add a valid-count test that asserts the unchanged value and no warning from this logger. Clear the capture before observing the action so the assertion concerns only this call. Retain the negative-count warning test.

Predict what happens if the function emits an unexpected warning on its valid branch. A test that only checked the value would miss that operational noise. Avoid asserting that the entire process logs nothing, because unrelated libraries can have independent behavior.

Step 1: Add a valid-count test that rejects an unexpected owned warning. Step 2: Keep the existing passing cases. Add the smallest new assertion first; predict the failure before running pytest.

Practice starter: solve before reading the solution

python

import logging

logger = logging.getLogger("owned.counts")


def normalize_count(value):
    if value < 0:
        logger.warning("negative count: %s", value)
        return 0
    return value


def test_negative_count_warning(caplog):
    with caplog.at_level(logging.INFO, logger="owned.counts"):
        assert normalize_count(-1) == 0
    records = [r for r in caplog.records if r.name == "owned.counts"]
    assert [(r.levelname, r.getMessage()) for r in records] == [("WARNING", "negative count: -1")]

# Task: Add a valid-count test that rejects an unexpected owned warning.

Reasoning: Add a valid-count test that rejects an unexpected owned warning.

Open in local Python playground ↗

Hint 1: Capture WARNING for the owned.counts logger.
Hint 2: Check the return value and the filtered record list independently.

Solution, tests and trade-offs

The solution adds a positive-count no-warning check.

The solution adds a positive-count no-warning check. The probe inserts a spurious warning only on that valid path, leaving the original negative-path test intact. The new assertion detects the extra owned record.

This is a useful narrow logging contract. It does not validate the production log transport, retention or access policy. Those belong to operational configuration and dedicated integration checks, not a unit test that invents a production destination.

Practice solution and acceptance checks

python

import logging

logger = logging.getLogger("owned.counts")


def normalize_count(value):
    if value < 0:
        logger.warning("negative count: %s", value)
        return 0
    return value


def test_negative_count_warning(caplog):
    with caplog.at_level(logging.INFO, logger="owned.counts"):
        assert normalize_count(-1) == 0
    records = [r for r in caplog.records if r.name == "owned.counts"]
    assert [(r.levelname, r.getMessage()) for r in records] == [("WARNING", "negative count: -1")]

def test_valid_count_has_no_warning(caplog):
    caplog.clear()
    with caplog.at_level(logging.WARNING, logger="owned.counts"):
        assert normalize_count(2) == 2
    assert [r for r in caplog.records if r.name == "owned.counts"] == []

Reasoning: The solution adds a positive-count no-warning check. The probe inserts a spurious warning only on that valid path, leaving the original negative-path test intact. The new assertion detects the extra owned record. This is a useful narrow logging contract. It does not validate the production log transport, retention or access policy. Those belong to operational configuration and dedicated integration checks, not a unit test that invents a production destination.

Open in local Python playground ↗

Interview reasoning and next step

Explain why log levels and rendered messages can be stable contracts while full formatted text is often incidental.

Explain why log levels and rendered messages can be stable contracts while full formatted text is often incidental. Discuss how to avoid capturing a different module’s warning and why logs must avoid raw sensitive inputs.

Next explore expected failures and skips with honest reporting. A suite should distinguish an environment limitation from a known defect and should fail when an unexpectedly fixed strict xfail needs to be reviewed.

Optional stretch — after the core task works: Introduce one deliberate implementation mistake and explain which assertion catches it. A green run alone is not evidence that every possible bug is covered.

Computer lab: https://applydjinn.com/typorithm/pytest-lab-20261106.zip. Run verify.py in an isolated environment. Worked examples and solutions pass, controlled counterexamples fail, and the new practice assertions reject a mutation missed by the baseline. Run --practice pyq-logging after changing the supplied exercise. Python executes on your computer or in the browser, without submitting code to a server. Native question progress is a separate learning record.

Capture severity and message while keeping diagnostics free of payload data.