Python Observability

Testing Logging Configuration in CI

A logging configuration is code that runs exactly once per process, at startup, and in most services it is only ever run in full in production. That makes it an unusually efficient source of deploy failures: a mistyped class path, a file handler pointed at a directory the container does not have, a formatter whose dependency is missing from the image. This page covers loading every environment's configuration in the test suite, asserting that the resulting logger tree is right, and a smoke test in the built image for the failures only the image can produce. It is a task article under log testing and verification, part of the Python logging fundamentals and structured data section, and it assumes the configuration is expressed as described in configuring logging with dictConfig.

Where each failure is caught Three logging configuration failures are traced through a pipeline with three test stages. A configuration that fails to load, such as a misspelled handler class path, is caught at the first stage, which loads every environment's configuration with dictConfig in the unit test suite. A configuration that loads but is wrong, such as a production logger left at DEBUG or a library logger missing its level entry, passes the first stage and is caught at the second, which asserts on the resulting logger tree. A configuration that is correct but fails in the built image, such as a file handler writing to a directory that does not exist in the container or a formatter depending on a package missing from the lockfile, passes both and is caught at the third, a smoke test that runs the real image and validates one line of output. Without any of these stages, all three are caught at the same point: a production deploy that fails at startup. three kinds of failure, three stages that catch them 1 · load in tests catches: fails to load misspelled class path 2 · assert on the tree catches: loads, but wrong DEBUG left on in prod 3 · smoke test the image catches: right, but not here directory missing in image without these stages, all three are caught in the same place a production deploy that fails at startup, usually with an unstructured traceback nothing is parsing each stage is cheap — seconds in the test suite, one container start in the pipeline and each catches a class of failure the others cannot see
Each stage catches a class the others cannot. Skipping any of them moves that class of failure to startup in production.

Prerequisites

pip install "pytest>=8.0.0,<9.0.0" \
            "python-json-logger>=2.0.7,<4.0.0"

Implementation

Step 1 — Build the configuration from a function that takes the environment. A configuration file per environment tends to drift, and the variant nobody loads locally is the one that breaks. A function that returns a dictConfig dictionary given an environment name makes every variant constructible and therefore testable, and it keeps the differences between environments explicit in one place.

# myservice/logging_config.py
import os

def build_config(environment: str, queue: bool = True) -> dict:
    level = {"production": "INFO", "staging": "INFO"}.get(environment, "DEBUG")
    handlers = {
        "stdout": {
            "class": "logging.StreamHandler",
            "stream": "ext://sys.stdout",
            "formatter": "json" if environment != "local" else "plain",
        },
    }
    if environment == "production":
        handlers["audit"] = {
            "class": "logging.handlers.RotatingFileHandler",
            "filename": os.path.join(os.environ["LOG_DIR"], "audit.jsonl"),
            "maxBytes": 64 * 1024 * 1024,
            "backupCount": 5,
            "formatter": "json",
        }
    return {
        "version": 1,
        "disable_existing_loggers": False,
        "formatters": {
            "json": {"()": "pythonjsonlogger.jsonlogger.JsonFormatter",
                     "fmt": "%(asctime)s %(levelname)s %(name)s %(message)s"},
            "plain": {"format": "%(levelname)-8s %(name)s: %(message)s"},
        },
        "handlers": handlers,
        "loggers": {
            "urllib3": {"level": "WARNING"},
            "botocore": {"level": "WARNING"},
            "audit": {"handlers": ["audit"] if "audit" in handlers else [],
                      "level": "INFO", "propagate": environment != "production"},
        },
        "root": {"level": level, "handlers": ["stdout"]},
    }

Step 2 — Load every variant in a test. Parametrising over environments means each one is applied with dictConfig in the test suite. Any configuration that cannot load — an unimportable class, a formatter key referencing a formatter that does not exist, a missing environment variable — fails here rather than at startup.

import logging
import logging.config
import pytest

from myservice.logging_config import build_config

@pytest.mark.parametrize("environment", ["local", "staging", "production"])
def test_config_loads(environment, tmp_path, monkeypatch):
    monkeypatch.setenv("LOG_DIR", str(tmp_path))
    logging.config.dictConfig(build_config(environment))

Step 3 — Assert on the resulting logger tree. Loading proves the configuration is valid; it does not prove it is right. A small set of assertions on the loggers that matter — the root level, the handler types, the level of chatty libraries, the propagation of special loggers — catches the configuration that loads and does the wrong thing.

def test_production_tree_is_as_intended(tmp_path, monkeypatch):
    monkeypatch.setenv("LOG_DIR", str(tmp_path))
    logging.config.dictConfig(build_config("production"))

    root = logging.getLogger()
    assert root.level == logging.INFO, "production must not log DEBUG"
    assert {type(h).__name__ for h in root.handlers} == {"StreamHandler"}

    for noisy in ("urllib3", "botocore"):
        assert logging.getLogger(noisy).level >= logging.WARNING, f"{noisy} will flood"

    audit = logging.getLogger("audit")
    assert audit.propagate is False, "audit records must not also go to stdout"
    assert any(type(h).__name__ == "RotatingFileHandler" for h in audit.handlers)

Expected Output: a failure that explains itself when somebody sets the production root to debug for an investigation and forgets to revert it.

FAILED test_logging_config.py::test_production_tree_is_as_intended
AssertionError: production must not log DEBUG

Step 4 — Smoke test the built image. The unit tests run against the development environment's installed packages and filesystem. The image has its own. A few seconds of running the real container with its production configuration, emitting a record and validating the output catches failures that exist only there.

#!/bin/sh
# ci/log-smoke.sh — run the built image, emit one record, validate it
set -e
IMAGE="$1"
OUTPUT=$(docker run --rm -e ENVIRONMENT=production -e LOG_DIR=/var/log/app \
  "$IMAGE" python -c "
import logging, logging.config
from myservice.logging_config import build_config
logging.config.dictConfig(build_config('production'))
logging.getLogger('smoke').info('log smoke test', extra={'probe': 'ok'})
" 2>&1)
echo "$OUTPUT" | python3 -c '
import json, sys
lines = [l for l in sys.stdin.read().splitlines() if l.strip()]
assert len(lines) == 1, f"expected one line, got {len(lines)}: {lines}"
rec = json.loads(lines[0])
assert rec["probe"] == "ok" and rec["levelname"] == "INFO", rec
print("log smoke: ok")
'

Expected Output: one line of valid JSON, or a failure naming what the image lacks.

log smoke: ok

FileNotFoundError: [Errno 2] No such file or directory: '/var/log/app/audit.jsonl'

Step 5 — Check library logger levels explicitly. A configuration refactor that drops the entries quietening noisy dependencies loads cleanly, passes a load test, and floods production with debug output from HTTP and cloud client libraries. An explicit assertion for each such library — or a loop over a maintained list — catches it. The background on which libraries are noisy and why is in taming third-party library loggers.

One function, every variant tested A single configuration function takes an environment name and returns a dictConfig dictionary. Three calls produce three variants: local, with a plain formatter and debug level; staging, with a JSON formatter and info level; and production, with a JSON formatter, info level and an additional rotating audit file handler whose path comes from an environment variable. A parametrised test loads each variant with dictConfig and runs assertions against the resulting logger tree. The production variant is the only one with the audit handler, which is exactly the part that most often fails, and it is exercised in every test run rather than only at deploy time. The note contrasts this with separate YAML files per environment, where the production file is typically never loaded outside production. build_config(environment) — every variant is constructible build_config() one function local · plain · DEBUG staging · JSON · INFO production · JSON · + audit file loaded + asserted every test run the production variant is the one that differs most — and the one most often never loaded with a YAML file per environment, production.yaml is typically first parsed during a production deploy building it from a function puts it in every test run instead
The production variant is the one with the most moving parts and, in most codebases, the one loaded least often before it matters.

Why configuration fails where it does

The failures this page targets have a common cause: the configuration's behaviour depends on its environment, and the one environment where it has never been exercised is the one that matters.

Import paths differ. A dictConfig references handler and formatter classes by dotted path, resolved by importing at load time. A path that resolves in a development checkout — because the package is installed in editable mode, or a module is on the path by accident — may not resolve in an image built from a wheel. The failure is an import error at startup, and nothing else in the service would have exercised that import.

Filesystems differ. File handlers open their files at configuration time, not at first write. A path that exists on every developer machine and in the test environment may not exist in a minimal container image, or may exist and be read-only. The handler raises during dictConfig, before the application has logged anything.

Dependencies differ. A formatter provided by a package that is a transitive dependency in development but not listed directly may be absent from a production image built from a stricter lockfile. The configuration references it; the import fails.

Environment variables differ. A configuration that reads a directory, a level or a feature flag from the environment behaves differently wherever the variable differs. A missing variable is sometimes a crash and sometimes, worse, a silent fallback to a development default — debug level in production.

In every case the configuration is correct in the abstract and wrong in one environment. That is why loading it in tests is necessary but not sufficient, and why the image smoke test is worth the few seconds it costs.

What to do when the configuration fails at startup anyway

No amount of testing makes startup failure impossible, and a logging configuration that fails is an unusually awkward failure, because the thing that would report the problem is the thing that is broken. Two defensive measures make the failure legible when it happens.

The first is a fallback. Wrapping the dictConfig call so that an exception installs a minimal configuration — a plain stream handler on standard error at warning level — and then logs the original exception means the service at least reports why its logging is degraded, in a form the container runtime will capture. Whether the service should then continue or exit is a policy decision; the important property is that the failure is visible either way.

The second is to fail loudly and early rather than partially. A configuration that loads some handlers and not others — possible when a handler's construction fails after others have been set up — produces a service that logs to some destinations and silently not to others. Treating any configuration error as fatal, after emitting the fallback message, is preferable to running with a half-configured logging tree that nobody knows about.

import logging, logging.config, sys

def configure(environment: str) -> None:
    try:
        logging.config.dictConfig(build_config(environment))
    except Exception:
        logging.basicConfig(level=logging.WARNING, stream=sys.stderr, force=True)
        logging.getLogger("startup").exception("logging configuration failed")
        raise SystemExit(78)       # configuration error: fail the deploy visibly
Time from a broken config to its discovery A bar chart of how long a broken logging configuration typically goes unnoticed depending on where it is checked. Checked by a unit test that calls dictConfig on every environment's configuration: found in about two minutes, in the pull request. Checked only by a service starting in staging: found in about an hour, after deploy. Checked only by a production start: found when the deploy fails or, worse, when records are missing, often a day or more later. The note says loading every environment's configuration in a test is cheap and moves discovery from days to minutes. time until a broken logging config is noticed unit test loads every env ~2 min · in the PR staging start only ~1 hour · after deploy production only a day or more · records missing loading every environment's config in a test moves discovery from days to minutes
A configuration that is only exercised in production is only tested in production. A test that loads it is nearly free.

Configuration options

Check Stage Catches Cost
Load each variant unit tests invalid configuration milliseconds
Root level per environment unit tests debug in production milliseconds
Handler types unit tests synchronous handlers where a queue was intended milliseconds
Library levels unit tests noisy dependencies re-enabled milliseconds
Propagation of special loggers unit tests audit records duplicated or lost milliseconds
Image smoke test pipeline missing packages, paths, variables one container start

Verification

Confirm the suite catches a deliberately broken configuration before trusting it.

# introduce a typo in a handler class and run only the config tests
sed -i 's/logging.StreamHandler/logging.StreamHandlr/' myservice/logging_config.py
pytest tests/test_logging_config.py -q; git checkout myservice/logging_config.py

Expected Output: every variant failing to load, naming the bad class.

FFF
ValueError: Unable to configure handler 'stdout'

Common mistakes

Only production loads the production configuration. Error signature: deploys failing at startup on configuration errors. Root cause: the variant is never exercised elsewhere. Remediation: build every variant from a function and load each in a test.

Load tests with no assertions. Error signature: a configuration that loads and logs at debug level in production. Root cause: loading proves validity, not correctness. Remediation: assert on the resulting tree.

File handlers pointed at development paths. Error signature: FileNotFoundError during dictConfig in the container. Root cause: the path exists locally and not in the image. Remediation: take paths from the environment, and smoke test the image.

A silent fallback for a missing variable. Error signature: production running at a development log level with no error. Root cause: a default applied when the environment variable is absent. Remediation: require the variable in production, and assert the level in tests.

Tests that leave logging configured. Error signature: unrelated tests changing behaviour depending on order. Root cause: dictConfig modifies global state. Remediation: reset logging after each configuration test.

Frequently Asked Questions

Why does a logging configuration fail only in production?

Because it is only ever loaded there. A dictConfig referencing a handler class that is imported differently in the production image, a file handler pointed at a directory that exists on developer machines but not in the container, or a formatter depending on a package missing from the lockfile all fail at startup, and startup in production is the first time they run.

Is loading the configuration in a test enough?

It catches configurations that fail to load. It does not catch configurations that load and are wrong — a handler attached to the wrong logger, a level set to DEBUG, propagation disabled where it should not be. Assertions on the resulting tree catch those.

What does an image smoke test add?

It runs in the environment that will actually run, with the dependencies and filesystem the image actually has. Failures caused by the image rather than by the code — a missing package, a read-only path, an absent environment variable — only appear there.

Should the configuration live in YAML or in code?

Either works, but building it with a function that takes the environment as a parameter makes every variant testable. A YAML file per environment tends to drift, and the variant nobody loads locally is the one that breaks.

Related Guides