skip to content

How do you assert in unittest that a block of code emitted a WARNING log record?

level: juniorimportance: must knowfreq 45%

answer

  1. Proving that code logged something
  2. A with block, not a callable
  3. Silence inside the block is failure
  4. Two views: objects and formatted lines
  5. Default level is INFO

basics

~10 s

Wrap the call in with self.assertLogs("my.logger", level="WARNING") as captured:. The block fails unless at least one record is emitted, and afterwards captured.records holds the LogRecord objects and captured.output the formatted strings.

solid answer

~40 s

`unittest.TestCase.assertLogs` is a context manager: `with self.assertLogs("thumbs.resize", level="WARNING") as captured:` runs the code, and the assertion **fails if no record at that level or above was emitted** on that logger or any of its children. Afterwards the object it yields exposes two views of the same capture: `records`, a list of `logging.LogRecord` objects you can inspect field by field (level number, logger name, the message arguments), and `output`, the same records rendered with the fixed format `"%(levelname)s:%(name)s:%(message)s"`. The first argument may be a logger name or a `logging.Logger`; when `level` is omitted it defaults to INFO. Assert on `records` rather than on `output` so the test checks the level and the payload rather than the exact wording. The negative form, `assertNoLogs`, was added in Python 3.10 and yields nothing.

code

python · 28 lines
python
import logging
import unittest

log = logging.getLogger("thumbs.resize")


def resize(width):
    if width > 4096:
        log.warning("width %d exceeds the cap", width)
    return min(width, 4096)


class ResizeTest(unittest.TestCase):
    def test_over_cap_warns(self):
        with self.assertLogs("thumbs.resize", level="WARNING") as captured:
            resize(4097)
        self.assertEqual(len(captured.records), 1)
        self.assertEqual(captured.records[0].levelno, logging.WARNING)
        self.assertIn("exceeds the cap", captured.records[0].getMessage())
        self.assertEqual(captured.output, ["WARNING:thumbs.resize:width 4097 exceeds the cap"])

    def test_at_cap_is_silent(self):
        with self.assertNoLogs("thumbs.resize", level="WARNING"):
            resize(4096)


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

go deeper

for a junior

Recall the shape: with self.assertLogs("name", level="WARNING") as captured:, then assert on captured.records. Remember that a block which logs nothing fails the test, and that the level defaults to INFO.

for a middle

Explain the two views the context manager yields, why records beats output, that a name or a logging.Logger may be passed, and that records from child loggers are captured because they propagate to the named logger's handler.

for a senior

Show that you check levelno as well as the text, that you pass structured data through extra= so assertions do not depend on wording, and that you know the block overrides the logger's handlers, level and propagation for its duration.

for a principal

Own the policy question: which log lines are contract and therefore worth a test, and which are debugging noise. Argue for asserting on structured record fields over prose so that log-message edits never become a build-breaking change.

### What the assertion is for Logging is real behaviour: an operator's alert, an audit line, a deprecation notice. Testing it with an ad-hoc handler that you attach and remember to detach is fiddly and leaks state between tests, so `unittest` ships the capture as an assertion. `unittest.TestCase.assertLogs(logger=None, level=None)` is **only a context manager** — unlike `assertRaises` or `assertWarns`, there is no callable form. Its contract has two halves, and interview answers usually miss the first one: 1. **It is an assertion.** If the block finishes and *nothing* was captured, the test fails with `no logs of level INFO or higher triggered on <name>`. An empty `with self.assertLogs(...)` block is a failing test, not a no-op. 2. **It is a capture.** The object bound by `as` carries `records` — a list of `logging.LogRecord` instances — and `output` — the same records formatted with the hard-coded `"%(levelname)s:%(name)s:%(message)s"`. ### Arguments The first argument is either a logger **name** (`"thumbs.resize"`) or a `logging.Logger` object; omit it and you get the root logger, which in a real test process also captures whatever any third-party library logs — almost always the wrong target. `level` accepts a name (`"WARNING"`) or a number (`logging.WARNING`) and **defaults to INFO**, not to WARNING and not to the logger's configured level. Records below the requested level are dropped by the capturing handler, so `assertLogs(level="ERROR")` around code that only logs a warning fails with the "no logs triggered" message. ### What it does to the logger Inside the block the named logger is temporarily rewired: its handler list is **replaced** by a single capturing handler, its level is set to the requested level, and its propagation flag is turned off so the records do not also reach the root handlers and spray your test output. All three are restored on exit, including when the body raises. Two consequences follow. First, the test does not depend on how logging is configured in the application — `assertLogs` forces the level, so a logger left at ERROR in production config still yields INFO records inside the block. Second, and for the same reason, `assertLogs` **cannot** prove that a given record would actually be visible in production; it proves the call site emitted it. Because the handler hangs on the *named* logger, records emitted on descendants are captured too — `assertLogs("thumbs")` sees a record logged on `thumbs.resize`, because the child propagates up to it. That is the idiomatic way to assert "this subsystem said something" without pinning the exact logger. It fails only when a descendant has its own propagation switched off. ### Assert on the records, not on the strings The common mistake is `self.assertEqual(captured.output, ["WARNING:thumbs.resize:width 4097 exceeds the cap"])`. It works, and it welds the test to the exact format string and to argument interpolation, so a harmless copy edit breaks it. Prefer the record: ```python record = captured.records[0] self.assertEqual(record.levelno, logging.WARNING) self.assertIn("exceeds the cap", record.getMessage()) ``` `getMessage()` is what performs the deferred `%`-style interpolation — logging does not format the message until something asks for it, which is why `record.msg` is still the raw template and `record.args` still the tuple. Any key you passed through `extra=` becomes a plain attribute on the record, which makes structured assertions (`record.elapsed_ms`) both precise and wording-independent. The level is the field people forget: asserting only on the text passes happily when a bug demotes an error to a debug line. Checking `levelno` is the whole reason to look at records at all. ### The negative form `assertNoLogs(logger=None, level=None)`, added in **Python 3.10**, is the mirror image: it fails if *any* record at that level or above appears, and it yields `None`, so `as cm` gives you nothing to inspect — there is nothing to inspect, by definition. Before 3.10 people hand-rolled it, usually by asserting that `assertLogs` itself raised `AssertionError`, which is a trick to recognise in old code rather than to write today. ### Where it stops `assertLogs` captures via the `logging` package only. A library that writes to `sys.stderr` directly, or issues a `warnings.warn` call, produces nothing for it — warnings are `assertWarns`'s job, and stream output belongs to `--buffer` or a redirect. Keep the two mechanisms distinct in your head; conflating them is the second-most-common answer failure after forgetting that an empty block fails.

  • What happens if the code inside a `with self.assertLogs(...)` block logs nothing at all?
    The test fails on exit with `no logs of level <LEVEL> or higher triggered on <logger>`. `assertLogs` is an assertion, not a passive recorder — an empty block is a failure, which is exactly why you cannot use it to express "this must stay quiet". Use `assertNoLogs` (Python 3.10+) for that.
  • Does `self.assertLogs("thumbs")` capture a record logged on `thumbs.resize`?
    Yes. The capturing handler is attached to the named logger, and a child logger's records propagate up to its ancestors' handlers, so anything under `thumbs.` is captured. The exception is a descendant whose own propagation has been switched off — those records never reach the ancestor's handler.
  • Why prefer `records` over `output` when writing the assertion?
    `output` is a rendered string, so asserting on it pins the test to the message's format string and to the interpolated arguments, and it silently ignores the level unless you parse the prefix. `records` gives `logging.LogRecord` objects, so you can assert `levelno` separately, call `getMessage()` for a substring check, and read any attribute passed via `extra=`.

It is a wiretap with a warrant condition attached: for the duration of the block every call on that logger is recorded, and if the line stays silent the test itself fails.

saying these in an interview costs you the question

  • Thinking an empty assertLogs block simply passes
  • Believing assertLogs also captures warnings.warn calls
  • Assuming the default capture level is WARNING
  • Asserting only on the formatted string, never on the level
  • Calling assertLogs with a callable instead of a with block
  • Defaulting to the root logger and capturing every library's output

context

resolving links…