Repeat Suppression and Template Fingerprints

A service that fails to reach a dependency often fails for every request. At a thousand requests per second, a single broken dependency produces a thousand identical log records per second, and the interesting information, that the dependency is unreachable, appears in the first record and is merely repeated in the other 999. Repeat suppression collapses those repetitions into one record with a count, a first-seen time, and a last-seen time. It is the cheapest form of log reduction and the one most likely to be implemented incorrectly, because the correctness condition is subtle: the records being collapsed must be indistinguishable in every field a consumer might use.

The reduction and its arithmetic

Consider a stream where the same event template recurs with identical field values. Emitting one record per occurrence produces N records; emitting one record per interval with an occurrence count produces one record per interval. The reduction factor is the number of occurrences per interval, which for a stuck retry loop is bounded only by the interval length and the rate.

The mechanism requires a key and a state. The key is a hash over the fields that define the message’s identity. The state is a counter and a pair of timestamps, held in a table keyed by that hash. When a record arrives, the table is consulted: if the key exists and the interval has not expired, the counter increments; otherwise a record is emitted for the previous interval and a new entry is created.

import hashlib, time

class Suppressor:
    def __init__(self, window=60.0, max_entries=4096):
        self.window = window
        self.max_entries = max_entries
        self.state = {}   # key -> [count, first_ts, last_ts]

    def key_of(self, record):
        # identity is the template plus every field value, not the rendered text
        material = "\x1f".join([
            record["event"],
            record["template"],
            *(f"{k}={v}" for k, v in sorted(record["values"].items())),
        ])
        return hashlib.blake2b(material.encode(), digest_size=16).digest()

    def observe(self, record, now=None):
        now = time.monotonic() if now is None else now
        k = self.key_of(record)
        entry = self.state.get(k)
        if entry is None:
            if len(self.state) >= self.max_entries:
                self.flush(now)          # bounded memory, at the cost of early emission
            self.state[k] = [1, now, now]
            return None
        entry[0] += 1
        entry[2] = now
        if now - entry[1] >= self.window:
            return self.emit(k, entry)
        return None

The separator byte in key_of matters. Concatenating field values without a separator that cannot appear in a value allows two different records to produce the same key: a=b|c and a=b with c empty both serialize to a=b|c. A control byte that the encoder forbids in field values removes the ambiguity, which is the same delimiter argument that governs record framing.

The max_entries bound is not optional. A stream of distinct messages, such as an error containing a unique request identifier, fills the table without producing any reduction, and the memory cost is proportional to the number of distinct keys. A suppressor without a bound is a memory leak with a logging interface.

Fingerprinting over the template, not the text

The naive approach hashes the formatted message. This collapses records that are byte-identical and fails on the case that matters most: a message that includes a variable value, such as a timestamp, a port number, or a hostname. Ten thousand failures against ten thousand different hosts produce ten thousand distinct strings, so nothing is collapsed, and the operator sees a wall of nearly identical lines with the one differing token buried in each.

Fingerprinting over the template solves this, but only if the template is known. When the producer emits structured records with a declared template, as described in Structured Fields Versus Formatted Message Strings, the template is available and the fingerprint is exact. When the producer emits only text, the template must be inferred, and inference is the hard problem.

Inference works by clustering: messages are tokenized, and tokens are classified as constant or variable by observing which positions vary across messages. The published approaches use a fixed-depth parse tree over token positions, or a prefix tree with wildcards, and both operate online so that the template is available as the stream arrives. The classification is heuristic. A field that varies rarely is treated as constant until it varies, at which point the template is revised and previously assigned records are retroactively misclassified. A field that happens to be constant within the observation window is treated as constant even though it is conceptually variable.

The practical consequence is that inference-based clustering is approximate by construction and its errors are not symmetric. Treating a variable token as constant splits one template into many and under-collapses. Treating a constant token as variable merges distinct templates and over-collapses, which is worse: it hides a genuinely different failure inside the count of a common one. A suppressor that merges connection refused with connection reset because both vary in the same position has destroyed the distinction that the operator needed.

What collapsing destroys

A collapsed record is not equivalent to the records it replaces, and the loss is specific.

Ordering. The individual records had positions in the stream relative to other events. The collapsed record has a first and last timestamp and no internal structure, so a correlation with another stream is preserved only at the resolution of the interval.

Interleaving. If two different events alternated, a failure followed by a retry then another failure, collapsing the failures produces a count that cannot be decomposed back into the alternation. Any analysis that depends on adjacency is invalidated.

Distribution within the interval. A count of 600 over a minute is consistent with a constant rate of ten per second and with a single burst of 600 in the first second followed by silence. The two have different diagnoses. Suppressors that also record a minimum and maximum inter-arrival time, or a small histogram of arrivals, preserve enough to distinguish them at modest cost.

Individual identifiers. If each record carried a distinct request identifier, collapsing them discards the identifiers, so a query for one request no longer finds its log line. This is the case where suppression is actively harmful: the collapsed record cannot answer the question that the identifier exists to answer.

The design rule that follows is that suppression applies to records whose variable fields are not themselves query keys. A message that carries a request identifier is a candidate for storage-level deduplication with the identifiers retained in a list, not for suppression at the producer, where the identifiers are dropped before anyone can ask.

Where in the path to suppress

Suppression can happen at the producer, at the collector, or at the storage layer, and the three are not equivalent.

Producer-side suppression is cheapest in bytes: the collapsed record is the only one transmitted, so the saving is realized in network, ingestion, and storage simultaneously. It is also the least reversible, because the individual records never existed anywhere else. Its natural home is a hot loop inside one process, where the identical records are generated by the same code path with the same values, and where the count is the only interesting fact.

Collector-side suppression sees records from many producers, so it can collapse the same message across instances. That is valuable when a fleet-wide failure produces one identical line per host. It is dangerous for the same reason: two hosts reporting the same message may be two independent failures, and collapsing them into one record with a count of two loses the host attribution unless the host is part of the key. Making the host part of the key restores attribution and removes the fleet-wide reduction, which is the trade in its purest form.

Storage-side suppression keeps every record on disk and collapses only at query time. It saves nothing in storage and everything in reader attention, and it is fully reversible because the underlying records remain. This is the right default for a system that can afford the bytes, and the wrong one for a system that cannot.

A common hybrid keeps a count at the producer for the hottest loops, a count at the collector for the fleet, and full records for a sample. The sample rate determines what can be reconstructed: a one-in-a-thousand sample of a collapsed stream still yields the individual records needed to see the interleaving, at a cost of one record per thousand.

Interval boundaries and clock behaviour

The suppression window is usually wall-clock based, and wall clocks are not monotonic. An adjustment backwards, from a time synchronization step or a manual correction, makes a record appear to have arrived before the interval began, and a suppressor that compares timestamps naively will emit a record with a negative duration or reset a counter it should have kept.

The robust choice is a monotonic clock for interval arithmetic and a wall clock only for the emitted timestamps. The two are then independent: the interval advances monotonically, and the emitted record carries the wall-clock time at which the interval closed. A backward wall-clock step then affects the labels on the record, not the counting logic. The cost is that a record’s reported first-seen time can precede its last-seen time in wall-clock terms, which is honest but surprising, and worth documenting in the emitted record itself.

The second boundary problem is the interval’s alignment. Windows aligned to absolute boundaries produce records at predictable times, which makes downstream bucketing simple. Sliding windows that close after a quiet period produce records at unpredictable times and a variable number per hour. The first is better for aggregation, the second for latency: a sliding window emits as soon as the burst stops, while an aligned window holds the count until the boundary. Neither is wrong, and mixing the two across components produces counts that cannot be summed, because a record can be split across two windows of different alignment.

The fingerprint computed here is also the natural join key for grouping in storage, which is why the template mechanism connects to Inverted Index Construction and Query Planning for Log Search and to the aggregation described in Counting Distinct Values Without Storing Every Record.