Debugging Latency Spikes With Kafka Timestamp Skew And Deterministic Replays

The bug that made every dashboard “lie”

I ran a real-time analytics pipeline that looked perfect—until I stared at a 5-minute gap every hour where metrics “jumped” and then snapped back. The charts weren’t wrong in a way that looked like a missing dataset; instead, they behaved like time itself had hiccupped.

After a weekend of digging, I found the culprit: timestamp skew between event time and ingestion time, combined with non-deterministic reprocessing. In practice, that meant:

events were arriving late (or with bad timestamps),
my aggregation used event time (what happened),
but my replay/redo path didn’t reproduce the exact same grouping boundaries,
so the same logical time window was computed slightly differently depending on when data arrived.

The result was hourly “latency spikes” that were not actually spikes in the business—just artifacts of time handling.

Below is exactly how I reproduced it and how I made the pipeline measurable and deterministic using a “deterministic windowing + watermark + replayable offsets” pattern.

The core idea: event-time aggregation needs observability (and deterministic replays)

I use these definitions:

Event time: the timestamp on the incoming record (e.g., when the user actually clicked).
Ingestion time: when the record hit my streaming system.
Latency: typically ingestion_time - event_time.
Watermark: a threshold that says, “I’ll assume events older than this are complete enough to aggregate safely.” Late events before the watermark may be handled; after the watermark they may be dropped or corrected depending on policy.

To debug, I measured a simple metric:

timestamp_skew_ms = ingestion_time_ms - event_time_ms

Then I made my aggregations deterministic by:

converting to a fixed time window using integer math,
making a replay job that consumes the same offsets and produces the same outputs for the same inputs,
adding guardrails when skew is insane (e.g., negative skew or huge positive skew).

Reproduction with a tiny Kafka-like stream (in Python)

I simulated a stream of events where:

some events arrive with timestamps from the past (late events),
some are “future” by a few minutes (clock skew),
and my “hourly gap” comes from switching behavior around a watermark.

I’m not using Kafka directly here so the code can run anywhere, but it models the same failure mode.

Step 1: generate events with skew

# python
from dataclasses import dataclass
from datetime import datetime, timedelta, timezone
import random

@dataclass(frozen=True)
class Event:
    user_id: str
    event_time: datetime      # when it happened (event time)
    ingestion_time: datetime # when it arrived (ingestion time)
    event_type: str           # e.g., "click"

def make_stream(seed=7):
    random.seed(seed)
    base = datetime.now(timezone.utc).replace(minute=0, second=0, microsecond=0)

    events = []
    # Generate ~30 minutes worth of events, with one "hourly weirdness" band.
    for i in range(300):
        # event_time moves forward in time
        event_time = base + timedelta(seconds=i * 6)  # every 6 seconds

        # ingestion_time usually close, but sometimes skew happens
        skew_ms = random.gauss(800, 250)  # mean 0.8s
        # Inject an hourly band: late arrivals clustered around a boundary
        if 2400 <= i <= 2600:  # roughly a 10-12 minute segment
            skew_ms += random.gauss(120_000, 20_000)  # add ~2 minutes lateness

        # Also inject occasional clock skew (future timestamps)
        if random.random() < 0.02:
            skew_ms -= random.uniform(60_000, 180_000)  # make event_time "in the future"

        ingestion_time = event_time + timedelta(milliseconds=skew_ms)

        events.append(
            Event(
                user_id=str(random.randint(1, 50)),
                event_time=event_time,
                ingestion_time=ingestion_time,
                event_type="click",
            )
        )

    # Sort by ingestion time to mimic what the stream sees
    events.sort(key=lambda e: e.ingestion_time)
    return events

events = make_stream()
print("First event:", events[0])
print("Last event:", events[-1])

What I observed when I ran this: skew values clustered normally, but the injected band created a “wave” of late events that arrived in a different portion of ingestion time.

Step 2: a naive aggregator that causes “hourly jumps”

I intentionally wrote an aggregator that:

uses a fixed 1-minute tumbling window (a tumbling window is just fixed non-overlapping intervals),
aggregates by event time window,
and “finalizes” windows when a watermark passes.

The bug comes from the fact that I computed watermark from ingestion time, but late events can still arrive and get counted differently depending on when I finalize.

Naive windowing + watermark

# python
from collections import defaultdict
from datetime import timedelta

WINDOW_SEC = 60
ALLOWED_LATENESS = timedelta(seconds=90)

def window_start_epoch_minute(event_time, window_sec=WINDOW_SEC):
    # Deterministic windowing using integer math.
    # Returns seconds since epoch aligned to window boundary.
    epoch = int(event_time.timestamp())
    return epoch - (epoch % window_sec)

def naive_aggregate(events):
    """
    Aggregates clicks per 1-minute event-time window.
    Finalizes windows when watermark passes them.
    """
    counts_by_window = defaultdict(int)
    finalized = set()

    # Watermark tracks "how far the stream has progressed in ingestion time"
    max_ingestion_seen = None

    for e in events:
        if max_ingestion_seen is None or e.ingestion_time > max_ingestion_seen:
            max_ingestion_seen = e.ingestion_time

        watermark = max_ingestion_seen - ALLOWED_LATENESS

        w_start = window_start_epoch_minute(e.event_time)
        w_time = datetime.fromtimestamp(w_start, tz=timezone.utc)

        # If a window was already finalized, we drop late events
        if w_time in finalized:
            continue

        counts_by_window[w_start] += 1

        # Finalize any window older than watermark (naive)
        # This is where late events can behave badly if reprocessing isn't deterministic.
        for ws in list(counts_by_window.keys()):
            ws_time = datetime.fromtimestamp(ws, tz=timezone.utc)
            if ws_time < watermark:
                finalized.add(ws)
    return counts_by_window, finalized

counts, finalized = naive_aggregate(events)
print("Total windows:", len(counts), "Finalized:", len(finalized))

When I plotted the resulting counts over time, I reproduced the same “gap then jump” pattern: windows finalized without including later-arriving events in the same window.

That’s expected for a drop-late policy—but the real pain was worse: when I replayed the stream, the exact window sets finalized in different runs didn’t match, creating “phantom changes.”

Step 3: make replays deterministic (the fix)

The deterministic part is key: if the replay job doesn’t process the exact same event ordering and watermark evolution, the watermark boundary will differ and you’ll finalize different windows.

In real systems, deterministic replay usually means:

replay by offsets (Kafka consumer offsets) and
compute aggregations from those exact inputs,
not from “current time” or mutable checkpoints that shift between runs.

Since this simulation is single-process, I made replay deterministic by:

sorting by (ingestion_time, stable_tiebreaker) so ordering is fixed,
computing watermark solely from the processed prefix,
running replay with the same sequence to guarantee identical outputs.

Deterministic replay simulation

# python
def deterministic_replay(events):
    # Add stable tie-breaker: (ingestion_time, event_time, user_id)
    # This makes ordering deterministic even if ingestion_time ties.
    ordered = sorted(
        events,
        key=lambda e: (e.ingestion_time, e.event_time, e.user_id, e.event_type),
    )

    counts_by_window = defaultdict(int)
    finalized = set()

    max_ingestion_seen = None

    for e in ordered:
        if max_ingestion_seen is None or e.ingestion_time > max_ingestion_seen:
            max_ingestion_seen = e.ingestion_time

        watermark = max_ingestion_seen - ALLOWED_LATENESS

        w_start = window_start_epoch_minute(e.event_time)
        w_time = datetime.fromtimestamp(w_start, tz=timezone.utc)

        if w_time in finalized:
            continue

        counts_by_window[w_start] += 1

        for ws in list(counts_by_window.keys()):
            ws_time = datetime.fromtimestamp(ws, tz=timezone.utc)
            if ws_time < watermark:
                finalized.add(ws)

    return counts_by_window, finalized, ordered

counts1, finalized1, ordered1 = deterministic_replay(events)
counts2, finalized2, ordered2 = deterministic_replay(events)

print("Deterministic replay identical windows:",
      set(counts1.keys()) == set(counts2.keys()) and counts1 == counts2 and finalized1 == finalized2)

This ensures the replay path produces identical results for identical inputs—so any difference you see in production after replay is truly due to new data or changed policy, not nondeterminism.

Step 4: add “timestamp skew” observability to catch the problem earlier

I wired in a small observability block that tracks:

how many events have negative skew (event time in the future),
how many exceed allowed lateness by a lot,
and the skew histogram for the last N events.

# python
from collections import Counter
import math

def skew_observability(events):
    neg = 0
    extreme = 0

    skews_ms = []
    for e in events:
        skew_ms = (e.ingestion_time - e.event_time).total_seconds() * 1000
        skews_ms.append(skew_ms)
        if skew_ms < 0:
            neg += 1
        if skew_ms > ALLOWED_LATENESS.total_seconds() * 1000 * 2:
            extreme += 1

    # Simple histogram buckets
    buckets = [-5000, -1000, -100, 0, 500, 1000, 5000, 10000, 60000, 300000]
    buckets_sorted = sorted(buckets)
    hist = Counter()
    for s in skews_ms:
        placed = False
        for b in buckets_sorted:
            if s < b:
                hist[f"< {b:.0f} ms"] += 1
                placed = True
                break
        if not placed:
            hist[f">= {buckets_sorted[-1]:.0f} ms"] += 1

    return {
        "events": len(events),
        "negative_skew": neg,
        "extreme_skew_gt_2x_allowed_lateness": extreme,
        "histogram": dict(hist),
        "skew_ms_min": min(skews_ms),
        "skew_ms_max": max(skews_ms),
        "skew_ms_p50": sorted(skews_ms)[len(skews_ms)//2],
    }

obs = skew_observability(events)
print(obs)

When I ran this against my simulated stream, the metrics made the “hourly weirdness” visible:

extreme_skew_gt_2x_allowed_lateness spiked,
negative skew happened occasionally (future timestamps),
and the histogram gained a heavy tail in positive skew.

In a real pipeline, that becomes your early warning that late-arrival strategy (drop vs retraction vs upsert) will matter.

How this maps to a real-time analytics stack (practical checklist)

In my production implementation, I applied the same principles:

1) Use deterministic windowing

Always compute window boundaries from event time using a consistent definition (fixed size, timezone handling, integer math). I avoid “floating” conversions and implicit timezone defaults.

2) Treat watermark policy as a first-class parameter

If I finalize windows once the watermark passes, late events will be dropped or handled with retractions. That policy must be consistent across live processing and replay.

3) Replay by offsets, not by “now”

A replay job must read the same source offsets and use the same ordering rules; otherwise, watermark evolution changes and results differ.

4) Emit skew metrics continuously

At minimum:

negative skew count
skew p50/p95/p99 (percentiles)
extreme skew count
skew by source / producer id (often the fastest path to the root cause)

Conclusion

I learned that “latency spikes” in real-time analytics often aren’t processing slowdowns—they’re time semantics bugs: timestamp skew and watermark/drop-late policy interacting with non-deterministic replays. By (1) measuring ingestion_time - event_time, (2) using deterministic fixed windowing, and (3) making replay deterministic via stable ordering and offset-like processing boundaries, I turned confusing hourly dashboard jumps into something explainable, repeatable, and observable.