cswork / libraryOpen practice workspace

Articles

Python Logging Interview Questions: Duplicate Records, Handlers, and Request IDs

Practice Python logging interview questions with duplicate-handler traces, propagation rules, safe request IDs, queue boundaries, and configuration checks.

One Python logging call prints twice. Raising the parent logger's level does not fix it. Adding a request ID works locally, then every queued message shows the same placeholder. These failures become easier to explain when you separate three decisions: whether a record is created, which handlers receive it, and how each handler formats and emits it.

A strong interview answer traces that path before changing configuration. You can practice that explanation with independent-handler logger design. This guide develops that approach through duplicate-output examples, a propagation truth table, and a request-ID experiment across an asynchronous queue.

Evidence boundary: Python documentation supplies the official behavior cited below. The examples are original preparation exercises, executed on CPython 3.12.14 where noted. Recommendations about interview explanations are our inference, not reported employer questions. We use no candidate reports and make no claim about how often a company asks these topics.

Why does one logging call produce duplicate records?

First establish what “duplicate” means. An exception record can legitimately produce several lines because its traceback spans multiple lines. Two records with similar messages can also represent two separate calls. Ask for the logger name, process, timestamp, call site, and destination before assuming the logging framework duplicated an event.

Official behavior: loggers form a hierarchy through dotted names. When propagation is enabled, a record can reach handlers attached to the originating logger and its ancestors. Attaching handlers to both levels can therefore emit the same record multiple times. Repeated calls to getLogger() with the same name return the same logger, rather than a fresh object. Python logging API

That makes initialization inside a frequently called helper particularly dangerous: retrieving the logger repeatedly is fine; adding a fresh handler on every call accumulates output paths.

Consider this standalone reproduction:

import io
import logging

output = io.StringIO()
parent = logging.getLogger("demo")
child = logging.getLogger("demo.worker")
parent.handlers.clear()
child.handlers.clear()
parent.propagate = False
child.propagate = True
parent.setLevel(logging.ERROR)
child.setLevel(logging.DEBUG)

parent.addHandler(logging.StreamHandler(output))
child.addHandler(logging.StreamHandler(output))
child.info("processed")
assert output.getvalue() == "processed\nprocessed\n"

We observed two lines on CPython 3.12.14. One comes from the child's handler; one comes from the parent's handler. The parent logger's ERROR setting does not remove the second line.

In this deliberately isolated fixture, clearing handlers makes the result reproducible. Do not copy that reset into application libraries: another component may own those handlers. In a real service, choose one configuration owner and inspect the actual hierarchy. A child that deliberately owns a separate destination may need propagate=False; a child intended to feed centralized output usually needs no local output handler.

Which level applies during propagation?

There are two different thresholds. The originating logger determines whether the logging call produces a record, using its effective level. Once propagation happens, ancestor handlers apply their own levels and filters.

Official behavior: propagated records are passed directly to ancestor handlers; ancestor logger levels and filters are not considered again. A logger set to NOTSET ordinarily looks up the hierarchy for its effective level. Python logging API

The following truth table uses one parent handler, no child handler, and propagation enabled. Each row changes an isolated fixture:

Child loggerParent loggerParent handlerA child DEBUG call
DEBUGERRORDEBUGEmits once: child accepts, handler accepts
DEBUGERRORERRORDoes not emit: handler rejects
NOTSETERRORDEBUGDoes not create a record: effective level is ERROR
INFODEBUGDEBUGDoes not create a record: child rejects DEBUG

Our native checks verified the first three rows, plus the same logger-versus-handler distinction for filters. The fourth follows the documented originating-level rule.

A weak answer says, “The parent is ERROR, so DEBUG cannot appear.” A stronger answer names the origin's effective level, enumerates reachable handlers, and checks each handler's threshold. That explanation also gives you a precise fix when a development console and production sink require different verbosity.

How should configuration survive repeated initialization?

Treat logger retrieval and logging configuration as separate responsibilities. Modules can obtain named loggers; the application startup path decides output destinations and policies. Frameworks and test runners may already configure logging before your code runs.

Official behavior: basicConfig() does nothing when the root logger already has handlers, unless force=True is supplied. Forcing configuration removes and closes existing root handlers. The HOWTO explains the roles of loggers, handlers, filters, and formatters. Python Logging HOWTO

Our standalone test configured stream A, then called basicConfig() for stream B. The next record still went to A. Repeating the second call with force=True redirected subsequent output to B. This is evidence about configuration ownership, not a recommendation to force-reset every imported application.

Another trap is using hasHandlers() as though it meant “this logger owns a handler.” It can find handlers up the hierarchy. Inspect the logger's own handlers collection when diagnosing local attachment, and inspect ancestors separately for propagation. Avoid treating a check-then-add helper as universally safe under concurrent initialization.

For dictionary configuration, be explicit about existing loggers. Official behavior in Python 3.12: disable_existing_loggers defaults to true unless the incremental configuration rules apply; existing non-root loggers outside the specified logger hierarchy can be disabled. This is different from merely lowering their verbosity. Python 3.12 logging configuration

A useful interview follow-up is: “Which component owns startup configuration, and which named loggers must remain active?” That is more diagnostic than adding a second console handler until output returns.

How do you add request IDs without mixing requests?

A formatter containing %(request_id)s requires that attribute on each record it formats. A logger name alone identifies a component, not a particular concurrent request. Storing the active ID in a shared global variable can cause one request to overwrite another's value.

Official guidance: the Logging Cookbook demonstrates contextual information using filters and contextvars. Context variables support context-local values, with a default available when no value has been set. Logging Cookbook, contextvars documentation

This small application-owned setup captures the current ID at a synchronous output handler:

import logging
from contextvars import ContextVar

request_id = ContextVar("request_id", default="-")

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

handler = logging.StreamHandler()
handler.addFilter(RequestIdFilter())
handler.setFormatter(logging.Formatter(
    "%(request_id)s %(name)s %(message)s"
))
logger = logging.getLogger("service.requests")
logger.handlers = [handler]
logger.propagate = False
logger.setLevel(logging.INFO)

The fallback - handles startup or background records that have no request ID. It does not prove that all expected request records were correctly labeled; monitor missing IDs where they should exist. Attaching a filter only to an ancestor logger would not enrich propagated child records, because that ancestor logger's filters are skipped.

Scope the value around the request work:

async def handle_request(rid, work):
    token = request_id.set(rid)
    try:
        logger.info("start")
        await work()
        logger.info("end")
    finally:
        request_id.reset(token)

Resetting the token restores the previous value, which matters for nested scopes as well as cleanup after failures or cancellation. In our interleaving test, requests A and B each retained their own IDs for start and end; a subsequent outside record received -. A separate cancellation test verified the reset in the cancelled task's cleanup path. The test establishes isolation for this fixture, not automatic correctness across every worker boundary.

Why does queue-based logging lose request context?

A queue introduces a change in execution context. The producer creates a record during the request; a listener later formats or emits it in another thread. Looking up the active request ID in that listener does not reconstruct the producer's request context.

Official mechanism: QueueHandler sends records to a queue and QueueListener receives and handles them on a separate thread. The handler documentation describes preparation, enqueueing, and listener shutdown. Python logging handlers

Our preparation rule is to attach request metadata before enqueueing, then format the stored fields at the listener. Move the RequestIdFilter to the producer's QueueHandler; do not attach another filter that overwrites the same attribute from the listener's context.

We tested both arrangements. With producer enrichment and no listener overwrite, the sink printed A queued. With the same enrichment filter also attached at the listener, it printed - queued: the listener's default replaced the ID already stored on the record. That counterexample makes the boundary visible.

A queue also needs an overload policy. The default enqueue operation uses a nonblocking queue insertion; a full bounded queue can enter logging error handling. Decide whether to drop, count, sample, or deliberately block through a customized design, and explain the latency consequence. Do not present an in-memory logging queue as durable delivery or an exactly-once audit system.

The cookbook discusses using a separate listener for multiple processes instead of assuming ordinary file handlers coordinate all process writes safely. During shutdown, account for pending records and listener lifecycle. A successful stop() in our small test is not evidence that a crashed service cannot lose logs. Logging Cookbook

What should you investigate when logging slows the service?

Separate record production, formatting, enqueueing, and sink I/O. Measure the busiest logger, record size, handler count, queue occupancy, and sink latency before removing useful diagnostics.

Passing arguments to a format string postpones message interpolation, but it does not postpone arbitrary Python argument evaluation:

logger.debug("payload=%s", build_large_payload())

build_large_payload() still runs before the call, even when DEBUG is disabled. If constructing the value is expensive, guard that work with logger.isEnabledFor(logging.DEBUG). Our native counter remained one after a disabled unguarded call and did not increase for the guarded branch. A handler can still reject a record that the logger accepts, so this guard concerns the logger's enabled level, not guaranteed downstream emission. Python Logging HOWTO

For failures, keep the causal exception evidence and avoid logging the same exception repeatedly at every layer. Minimize sensitive fields before a record enters downstream queues and storage. A request ID supports correlation; it does not justify copying complete request payloads or credentials into logs.

Practice routing, overload, and correlation

The extensions below are original Python-focused practice suggestions, not claims that every prompt mandates the standard logging module.

Practice questionPython logging extension
Design a Logger That Runs Each Message Through an Ordered List of HandlersCompare a custom ordered pipeline with stdlib handler fan-out; do not assume identical semantics.
Design a Logger with Independent HandlersSpecify per-handler thresholds and show why one record can have several destinations.
Design an asynchronous logger with formattingCapture request fields before enqueueing and define overload and shutdown behavior.
Investigate a Server Saturated by LoggingMeasure handler duplication, expensive arguments, queue growth, and sink latency independently.
Detect timed-out RPC calls from paired start and end log recordsState correlation-ID and missing-end assumptions before interpreting timeouts.

Explain one record's route, reproduce the duplicate, then move the request-ID capture point across a queue and predict what changes.

Sources and Further Reading