Rate Limiting and Sampling Noisy Python Loggers

One retry loop, one connection that flaps, one validation error in a batch job, and a service that normally emits two hundred records a second emits two hundred thousand. This page builds the filter that stops it — a token bucket keyed by event class, with first-N pass-through, a suppressed count, and a hard exemption for errors. It is for engineers whose measurements already point at volume rather than at per-call cost. It belongs to the Python logging performance and overhead guide, part of the Python logging fundamentals and structured data section.

Raising the level is the reflex, and it is the wrong tool: it silences whole severities across the whole service to fix one loop.

Prerequisites

Standard library only.

export LOG_RATE_BURST=5        # records emitted in full at the start of a burst
export LOG_RATE_PER_SECOND=1   # sustained rate per event class afterwards

Implementation

Step 1 — Key by event class. The uninterpolated record.msg is the event; the interpolated message is an instance of it. Keying on (record.name, record.msg) means a retry loop that logs "retrying %s after %s" for ten thousand hosts is one bucket, not ten thousand.

import logging
import threading
import time

class RateLimitFilter(logging.Filter):
    """Token bucket per (logger, event), with first-N pass-through and a suppressed count."""

    def __init__(self, burst: int = 5, per_second: float = 1.0, level_floor: int = logging.WARNING):
        super().__init__()
        self.burst = burst
        self.per_second = per_second
        self.level_floor = level_floor            # at or above this level: never limited
        self._state: dict[tuple[str, str], list] = {}
        self._lock = threading.Lock()

    def filter(self, record: logging.LogRecord) -> bool:
        if record.levelno >= self.level_floor:    # errors are never sampled
            return True
        key = (record.name, str(record.msg))
        now = time.monotonic()
        with self._lock:
            seen, last_pass, suppressed = self._state.get(key, (0, 0.0, 0))
            seen += 1
            if seen <= self.burst:                # the onset, in full
                self._state[key] = (seen, now, 0)
                return True
            if now - last_pass >= 1.0 / self.per_second:
                self._state[key] = (seen, now, 0)
                record.suppressed = suppressed    # what we dropped since the last pass
                record.event_seen = seen
                return True
            self._state[key] = (seen, last_pass, suppressed + 1)
            return False

The lock covers only the counter update. Nothing formats or serialises inside it, so the critical section is a dictionary lookup and a few integer operations — far cheaper than the record construction it prevents downstream.

Step 2 — Attach it to the noisy logger, not to the root. Scope is the whole point: a limiter on the root logger is just a slower way of raising the level.

import logging.config

CONFIG = {
    "version": 1,
    "disable_existing_loggers": False,
    "filters": {
        "ratelimit": {
            "()": "observability.ratelimit.RateLimitFilter",
            "burst": 5,
            "per_second": 1.0,
        },
    },
    "handlers": {"stdout": {"class": "logging.StreamHandler", "formatter": "json"}},
    "loggers": {
        "urllib3.connectionpool": {"level": "INFO", "filters": ["ratelimit"]},
        "myapp.retry":            {"level": "DEBUG", "filters": ["ratelimit"]},
    },
    "root": {"level": "INFO", "handlers": ["stdout"]},
}

Remember that a filter attached to a logger runs only for records logged on that logger — it is not inherited by children. Name the loggers you mean, or attach the filter in code by walking logging.Logger.manager.loggerDict for a known prefix.

Step 3 — Surface the suppressed count in the output. A record that passes after suppression carries suppressed and event_seen attributes; the formatter must promote them, or the whole exercise produces a log that quietly understates reality.

class CountAwareFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        base = super().format(record)
        n = getattr(record, "suppressed", 0)
        return f"{base} (suppressed={n}, seen={getattr(record, 'event_seen', 1)})" if n else base

In a JSON pipeline, promote them as fields instead of appending to the message — then sum(suppressed) + count(records) reconstructs the true event rate in a query, which is what makes the sampled stream trustworthy for alerting.

Step 4 — Bound the state. One entry per distinct (logger, msg) pair is normally a handful of keys, but code that builds its format string dynamically can mint unbounded keys. Cap the dictionary and fall open — never fall closed, or a full table silently silences the service.

MAX_KEYS = 2048

# inside filter(), before inserting a new key:
if key not in self._state and len(self._state) >= MAX_KEYS:
    return True                                   # fail open: log it rather than lose it

Configuration options

Verification

Assert the three properties that matter: the onset survives, the count is exact, and errors are untouched.

import logging

def test_burst_then_sample():
    f = RateLimitFilter(burst=3, per_second=1000.0)   # fast clock for the test
    logger = logging.getLogger("t.retry")
    records = []
    logger.addFilter(f)
    logger.addHandler(type("H", (logging.Handler,), {"emit": lambda s, r: records.append(r)})())
    logger.setLevel(logging.INFO)

    for host in range(50):
        logger.info("retrying %s after %s", f"host-{host}", "timeout")

    assert len(records) >= 3                          # the onset is always there
    assert records[0].getMessage().endswith("timeout")

def test_errors_are_never_limited():
    f = RateLimitFilter(burst=1, per_second=0.001)
    for _ in range(100):
        rec = logging.LogRecord("t", logging.ERROR, "", 0, "boom", (), None)
        assert f.filter(rec) is True                  # every one passes

Expected Output:

test_ratelimit.py::test_burst_then_sample PASSED
test_ratelimit.py::test_errors_are_never_limited PASSED

In a running service, the shape to look for after deployment is a short cluster of full-detail records at the start of an incident followed by a steady trickle carrying growing suppressed values — and unchanged volume from every logger you did not name.

Common mistakes

The limiter keys on the formatted message

Error signature: volume does not drop at all; every record is its own bucket. Root cause: the key used record.getMessage(), which interpolates the host, ID or timestamp that made each record unique. Remediation: key on record.msg before interpolation, together with record.name.

Suppressed records vanish without a trace

Error signature: a post-incident query reports nine occurrences of an event that actually fired two thousand times. Root cause: the filter dropped records without recording a count, and the formatter would not have printed one anyway. Remediation: carry suppressed on the next passing record and promote it as a field, then reconstruct the rate with count + sum(suppressed).

Errors get sampled along with everything else

Error signature: an incident timeline is missing the failure that started it. Root cause: the filter applied uniformly, with no level floor. Remediation: return True immediately for levelno >= WARNING. If error volume is itself the problem, treat that as a bug rather than as volume to shed — the technique for costing it is in measuring Python logging overhead.

Choosing what to limit

A rate limiter applied to the wrong logger reduces volume and loses signal. Three properties identify the loggers where it is safe, and they are worth checking before adding a key rather than after an incident.

The records are repetitive. The value of the tenth identical record is much lower than the value of the first, and the value of the ten-thousandth is zero. Retry loops, connection-pool chatter, validation failures across a batch, and per-item progress records all have this shape. A record whose content differs meaningfully every time does not, and limiting it discards information rather than redundancy.

The count matters more than the instances. If the question you would ask of the log is "how often did this happen", a suppressed count answers it exactly. If the question is "what were the arguments the third time", it does not, and the records need to survive — or, better, the thing you actually want is a metric with the argument as a bounded label.

There is no legal or audit requirement. Access records, authorisation decisions and financial events are frequently subject to a retention requirement that does not admit sampling. Those loggers get an explicit exemption alongside the level floor, and it is worth writing that exemption as a named constant so nobody removes it by accident.

NEVER_LIMIT = frozenset({
    "audit",                       # retention requirement
    "security.authz",              # authorisation decisions
    "billing.ledger",              # financial events
})

def filter(self, record: logging.LogRecord) -> bool:
    if record.name.split(".")[0] in NEVER_LIMIT:
        return True                # exempt, before any other consideration
    ...

Sizing burst and rate

The two parameters answer different questions and are worth setting separately rather than tuning as one knob.

burst decides how much of the onset survives. Five is a reasonable default because it is enough to show the first occurrence plus a few that establish whether the event is identical each time or varies. Raising it to fifty rarely adds information, because by the fiftieth occurrence the pattern is established.

per_second decides the sustained sampling rate, and it should be read as "how often do I want to be reminded this is still happening". Once per second is generous; once per ten seconds is usually enough for a condition that will either resolve or escalate. The suppressed counter carries the true rate regardless, so a low sustained rate loses nothing except immediacy.

Watching the limiter itself

A rate limiter is a component that discards data, which makes it worth monitoring in its own right. Two signals are enough: the total suppressed count, exported as a counter, and the number of distinct keys in the state table. The first tells you how much the limiter is doing; the second tells you whether the keying is working, because a key count that grows with traffic means the limiter is keying on something request-specific and is achieving nothing.

from prometheus_client import Counter, Gauge

SUPPRESSED = Counter("log_records_suppressed_total", "Records dropped by the rate limiter", ["logger"])
KEYS = Gauge("log_ratelimit_keys", "Distinct event keys held by the rate limiter")

Alert on the key count crossing a fixed threshold rather than on the suppressed count, which is expected to be large and uninteresting. A key count approaching MAX_KEYS means the fail-open path is about to engage and the limiter is about to stop limiting — which is the correct behaviour, and worth knowing about before it happens rather than afterwards.

Related

• Python logging performance and overhead — the parent guide: the cost model this filter is answering.
• Measuring Python logging overhead — proving that volume, not per-call cost, is the problem.
• Non-blocking logging with QueueHandler — the queue whose drop policy this filter keeps from ever engaging.
• Log levels and severity mapping — why the floor sits at WARNING.
• Sampling strategies for distributed tracing — the same volume problem, solved differently because traces must stay whole.

Frequently Asked Questions