Buffering Log Records with MemoryHandler

The most useful DEBUG records are the ones immediately before an error, and the most wasteful DEBUG records are all the others. logging.handlers.MemoryHandler resolves that tension: hold recent records in memory, ship them only when something goes wrong. This page covers the buffering handler, the ring-buffer variant that makes it practical, and the per-request scoping that makes it correct under concurrency. It builds on the handler architecture guide, part of the Python logging fundamentals and structured data section.

Prerequisites

Standard library only.

export LOG_BUFFER_CAPACITY=500     # records held per buffer
export LOG_BUFFER_FLUSH_LEVEL=ERROR

Implementation

Step 1 — Wrap the real handler. MemoryHandler(capacity, flushLevel, target) accumulates records and replays them into target on flush. The target keeps its own formatter and level, so the replayed records look exactly like normal output.

import logging
import logging.handlers

target = logging.StreamHandler()                       # the real sink
target.setFormatter(logging.Formatter("%(asctime)s %(levelname)s %(name)s %(message)s"))
target.setLevel(logging.DEBUG)                         # must accept what the buffer replays

buffer = logging.handlers.MemoryHandler(
    capacity=500,
    flushLevel=logging.ERROR,
    target=target,
)

root = logging.getLogger()
root.setLevel(logging.DEBUG)                           # DEBUG must reach the buffer
root.addHandler(buffer)

Note the level split. The logger is at DEBUG so records are created; the buffer holds them; the target must be at DEBUG too, or it will discard the very records the flush was meant to deliver. If you also want ordinary INFO traffic emitted immediately, add a second handler at INFO directly on the logger rather than raising the target's level.

Step 2 — Turn it into a ring buffer. The stock shouldFlush returns True when the buffer is full, which means a quiet service periodically dumps five hundred DEBUG records for no reason. Override it to flush on level only, and discard the oldest record when full.

class RingMemoryHandler(logging.handlers.MemoryHandler):
    """Flush on level only; when full, drop the oldest record instead of flushing."""

    def shouldFlush(self, record: logging.LogRecord) -> bool:
        return record.levelno >= self.flushLevel

    def emit(self, record: logging.LogRecord) -> None:
        if len(self.buffer) >= self.capacity:
            del self.buffer[0]                         # oldest out, newest in
        super().emit(record)

That is the whole difference between "a batching handler" and "an incident context buffer". With it, a healthy process holds a rolling window of the last five hundred records and writes nothing.

Step 3 — Scope the buffer to a request. A single process-wide buffer under concurrency interleaves every in-flight request, so a flush ships eight other requests' DEBUG records alongside the failing one. In an async or threaded service, create the buffer per request and attach it to a request-scoped logger.

from contextlib import contextmanager

@contextmanager
def request_log_buffer(target: logging.Handler, capacity: int = 200):
    handler = RingMemoryHandler(capacity=capacity, flushLevel=logging.ERROR, target=target)
    logger = logging.getLogger("request")
    logger.addHandler(handler)
    try:
        yield logger
    finally:
        handler.close()                                # flushes if anything triggered it
        logger.removeHandler(handler)                  # never leak handlers per request

removeHandler in a finally is not optional. A handler added per request and never removed is one of the classic slow leaks in a Python service: memory grows, and every log record is handled once more for each request the process has ever served.

Step 4 — Guard what the buffer keeps alive. A held record keeps its args alive, and exc_info keeps every frame and every frame's locals alive. A five-hundred-record buffer holding tracebacks can pin far more memory than the record count suggests. Either keep exc_info out of buffered DEBUG records, or format them on the way in.

Configuration options

Verification

Assert the two behaviours: nothing is written on the happy path, and everything is written on the error path.

import io, logging

def test_no_output_without_an_error():
    stream = io.StringIO()
    target = logging.StreamHandler(stream)
    target.setLevel(logging.DEBUG)
    handler = RingMemoryHandler(capacity=10, flushLevel=logging.ERROR, target=target)
    log = logging.getLogger("t1"); log.addHandler(handler); log.setLevel(logging.DEBUG)

    for i in range(5):
        log.debug("step %d", i)
    assert stream.getvalue() == ""                  # buffered, not written

def test_error_flushes_the_context():
    stream = io.StringIO()
    target = logging.StreamHandler(stream)
    target.setLevel(logging.DEBUG)
    handler = RingMemoryHandler(capacity=10, flushLevel=logging.ERROR, target=target)
    log = logging.getLogger("t2"); log.addHandler(handler); log.setLevel(logging.DEBUG)

    for i in range(5):
        log.debug("step %d", i)
    log.error("failed")
    assert stream.getvalue().count("step") == 5     # the whole run-up shipped

Expected Output:

test_memory.py::test_no_output_without_an_error PASSED
test_memory.py::test_error_flushes_the_context PASSED

Common mistakes

The buffer flushes on its own

Error signature: batches of DEBUG records appear in the log at regular intervals with no error near them. Root cause: the stock shouldFlush also returns True when the buffer reaches capacity. Remediation: override shouldFlush to test the level only, and drop the oldest record when full.

The flush produces nothing

Error signature: an error record appears with no preceding context, although DEBUG calls definitely ran. Root cause: the target handler's level is INFO, so every replayed DEBUG record is discarded on arrival. Remediation: set the target to DEBUG and control ordinary volume with a second handler rather than with the target's level.

Handlers accumulate on a logger

Error signature: memory grows steadily and each log line is written many times over. Root cause: a per-request addHandler with no matching removeHandler. Remediation: use a context manager with removeHandler in finally, and assert the handler count in a test that runs many requests.

What this pattern replaces

The error-context buffer competes with two other approaches to the same problem, and the comparison is worth making explicitly because they have very different operating costs.

Logging everything at DEBUG and filtering at the backend. This works, and it is expensive in exactly the way the buffer avoids: every record is formatted, serialised, shipped, ingested and stored, and the filtering happens after all of that has been paid for. It has one genuine advantage — the records exist even for requests that succeeded, so a question asked afterwards about a successful request can still be answered. If that matters, this is the right choice and the buffer is not.

Turning DEBUG on temporarily during an incident. Covered in changing Python log levels at runtime, and it has the opposite trade: nothing is stored until you ask, and what you get starts from the moment you asked. For an ongoing problem that reproduces, this is ideal. For an intermittent failure that has already happened, it is useless, because the interesting request finished before anyone typed the command.

The buffer sits between them: nothing is stored for successful requests, and the detail for a failing one already exists at the moment it fails. The cost is memory and a small amount of complexity, and the limitation is that a request has to fail for its context to appear — a request that succeeded slowly leaves nothing behind.

That last row is a small extension worth knowing about: flush on a condition other than level. Since shouldFlush receives the record, it can trigger on anything the record carries — a duration attribute above a threshold, a specific error code, a tenant under investigation.

class ConditionalMemoryHandler(logging.handlers.MemoryHandler):
    """Flush on an error, or on any record marking a request slower than the SLO."""

    def shouldFlush(self, record: logging.LogRecord) -> bool:
        if record.levelno >= self.flushLevel:
            return True
        return getattr(record, "duration_ms", 0) > 1000          # a slow success, kept

Operating it

Three things are worth watching once this is running. The first is the flush rate: buffers flushing on a large share of requests means the error rate is high enough that the pattern is not saving anything, and the level threshold or the error rate itself needs attention. The second is memory, for the reasons in the figure above — capacity is measured in records and cost is measured in what they reference. The third is handler count on the logger, which is the leak this pattern is most prone to and the easiest to assert on.

def test_handlers_do_not_accumulate():
    logger = logging.getLogger("request")
    before = len(logger.handlers)
    for _ in range(1000):
        with request_log_buffer(target):
            pass
    assert len(logger.handlers) == before        # every one removed in its finally

A thousand iterations is enough to make the failure obvious: without the removeHandler, the count is a thousand higher and every subsequent log record is handled a thousand times.

Related

• Handler architecture for Python logging — the parent guide: one handler per sink and where buffering fits.
• Writing a custom logging handler in Python — when the buffering behaviour you need is not in the standard library.
• Non-blocking logging with QueueHandler — buffering for latency rather than for context.
• Rate limiting and sampling noisy loggers — the other way to keep volume down without losing the signal.
• Using contextvars for request tracing — request scoping for the buffer and everything else.

Frequently Asked Questions