# DDIA Ch. 12: windowing by processing time invents a 61× spike that never happened ## Concept A steady stream — exactly **one event per second** for 120 seconds — flows past a consumer whose job is to graph the per-second event rate. The true rate is flat: **1/second**, start to finish. But the consumer suffers a 60-second outage (a redeploy). While it is down the events pile up in the broker's backlog, and when it restarts all 60 buffered events drain at nearly the **same instant**. Bucket the events by **processing time** — when the consumer got to each one — and those 60 events land in a single per-second bucket alongside the one live event of that second: a **61 events/second** bar, a **61× phantom spike** (DDIA Figure 12-8), flanked by empty buckets where the outage swallowed the traffic. Re-bucket the **same events** by their embedded **event-time** timestamp — when they happened in the world — and the spike vanishes: a flat **1/second** across every bucket. Nothing in the data spiked. The consumer's own schedule did. ## Provenance *Designing Data-Intensive Applications*, 2nd ed. (Kleppmann & Riccomini, 2025), Chapter 12 — *Stream Processing*, §"Reasoning About Time", subsection "Event time versus processing time" (Figure 12-8): > Confusing event time and processing time leads to bad data. [...] if there is > any kind of queueing, [processing time] is unlikely to be an accurate estimate > of the time at which the event actually occurred. The book's Figure 12-8 shows a stream restarting after a pause and a "spike" of events appearing at the restart — an artifact of a metric bucketed by when the consumer processed each event, not by when it happened. Here you manufacture that exact figure and watch the spike appear and disappear depending only on which timestamp you count by. ## Prerequisites The whole surprise is which clock you count by. These help; each line notes where it shows up in the run. 1. **Event time vs processing time** — every event carries two timestamps: when it happened in the world (`event_time`) and when your consumer got to it (`processing_time`). It shows up as the two fields on each event, and as the two histograms that disagree. **This is the one that carries the whole result.** 2. **Windowing / bucketing** — turning a stream into a rate means grouping events into fixed time buckets (here, per-second) and counting. It shows up as `bucket_by()`: the same events, bucketed by two different keys, give two graphs. 3. **Consumer lag / backlog** — when a consumer can't keep up (or is down), unread events accumulate in the broker; on catch-up they are all delivered in a burst. It shows up as the 60 outage-events all taking `processing_time = 90`. 4. **Processing time is a property of the consumer, not the data** — `event_time` is stamped by the producer and never changes; `processing_time` depends entirely on your consumer's schedule (pauses, restarts, backpressure). It shows up as the spike existing in one histogram and not the other, from identical events. ### Where to learn the prerequisites - **Event time vs processing time, windowing (#1, #2, #4):** DDIA §"Reasoning About Time" and §"Event time versus processing time"; Akidau et al., *"The Dataflow Model"* (VLDB 2015) and the *"Streaming 101 / 102"* articles for windowing, event-time vs processing-time, watermarks and allowed lateness. - **Consumer lag / backlog (#3):** any log-broker's consumer-lag docs (e.g. Kafka's "consumer lag" / partition offsets) — lag is exactly the count of events buffered ahead of a slow or stopped consumer. If only one is new, make it #1 — the entire artifact is the difference between the two clocks, and everything else is machinery for showing it. ## Environment Deterministic, so the histograms reproduce exactly: - macOS 26.5.2 (Darwin 25.5.0), arm64 - Python 3.15.0a8, standard library only — no Docker, no deps - The event stream and the outage are modeled explicitly (no wall-clock, no sleeps), so timing is data, not chance — the transcript is fixed every run - Fixed workload: 120 events, one per event-time second; consumer down over event-times [30, 90); backlog drained at processing-time 90 ## Mental model Every event carries two clocks, and a rate graph has to pick one. - **Event time** — when the event happened in the world. The producer stamps it and it never changes. Bucket by this and you measure *reality*: what the traffic actually did, regardless of anything downstream. - **Processing time** — when your consumer got around to the event. It is whatever the clock said the moment the event was read, which depends on the consumer's schedule: if the consumer pauses, restarts, or falls behind, processing time drifts arbitrarily far from event time. A **backlog** is what makes the two diverge violently. While the consumer is down, events don't stop happening — they queue in the broker. When it restarts it drains the whole queue in a burst, so **many distinct event-times get stamped with one processing-time**. Count by processing time and that compression reads as a spike; count by event time and the events spread back out across the seconds they truly belong to. Same events, two keys — one script, `code/processing_time_spike.py`. ## Setup ``` cd study/ddia/ch12 python3 code/processing_time_spike.py ``` Do **not** read the output yet — make each prediction first. ## Steps ### Step 1 — the workload **Predict.** One event per second for 120 seconds, then a graph of the per-second event rate. If you *hadn't* been told about the outage, what would you expect the rate graph to look like — and what is the true underlying rate at every second? **Observe.** ``` A steady stream: one event per second for 120 seconds (true rate = 1/s, flat). The consumer is DOWN for a redeploy over event-times [30, 90) -- those 60 events buffer in the backlog and all get processed at the restart instant, processing_time = 90s. ``` The real traffic is a flat line at **1/second** — nothing spikes, nothing drops. The only wrinkle is *when the consumer reads* each event, not when it happened. ### Step 2 — bucket by processing time **Predict.** Bucket the events by **processing time** (the second the consumer read each one) and graph per-second counts around the restart. The consumer was down for the 60 seconds [30, 90) and drains the backlog at the restart instant, t=90. What is the peak per-second rate the graph shows — and what does it show during the outage? **Observe.** ``` per-second rate bucketed by PROCESSING time (zoom on t=85..95s): t= 85s | 0 t= 86s | 0 t= 87s | 0 t= 88s | 0 t= 89s | 0 t= 90s | ############################################################# 61 t= 91s | # 1 t= 92s | # 1 t= 93s | # 1 t= 94s | # 1 t= 95s | # 1 peak = 61 events/second at processing-time t=90s -- a 61x PHANTOM SPIKE. ``` **A 61 events/second spike where the truth was 1/second.** The 60 events that happened during the outage all got `processing_time = 90`, and the one live event that genuinely occurred at t=90 lands in the same bucket — 60 + 1 = **61**. Every second of the outage reads as **0**, then it all detonates in one bar. This bar chart *is* DDIA Figure 12-8, and every event in it is a real event that really happened one per second. ### Step 3 — bucket the same events by event time **Predict.** Take the **identical** 120 events and bucket them by their embedded **event-time** timestamp instead. Same data, different key. What does the same window t=85..95 look like now — and where does the spike go? **Observe.** ``` per-second rate bucketed by EVENT time (same window t=85..95s): t= 85s | # 1 t= 86s | # 1 t= 87s | # 1 t= 88s | # 1 t= 89s | # 1 t= 90s | # 1 t= 91s | # 1 t= 92s | # 1 t= 93s | # 1 t= 94s | # 1 t= 95s | # 1 peak = 1 event/second, floor = 1 event/second -- FLAT 1/s, no spike anywhere. ``` **Flat 1/second — the spike is gone.** Bucketing by event time puts each event back in the second it actually happened, so the outage's 60 events spread across event-times 30..89 exactly as they occurred. The peak rate and the floor rate are both **1/second**, everywhere in the stream. The spike was never in the data. ### Step 4 — the verdict **Predict.** Same events, two clocks. State the two peak rates side by side: what does the processing-time graph claim the peak traffic was, and what was it really? **Observe.** ``` verdict: processing-time peak rate = 61/s (invented by the backlog) event-time peak rate = 1/s (the real traffic) same 120 events, same data -- the 61x spike is an artifact of WHEN the consumer looked, not of anything that happened in the world. ``` **61× versus 1×, from one set of events.** The only thing that changed between the two graphs was the timestamp field the bucketing keyed on. One measured the world; the other measured the consumer's outage-and-catch-up schedule and reported it as if it were traffic. ## What you should see - The true event rate is **flat at 1/second** across all 120 seconds. - Bucketed by **processing time**: a **61 events/second** spike at t=90 (60 drained backlog events + 1 live event of that second), with **0** during the whole outage. - Bucketed by **event time**: **1/second** everywhere — peak and floor both 1, no spike. - The **61× vs 1×** gap comes entirely from which timestamp the graph counts by. ## Why A per-second rate graph is a count of events per time bucket, and the bucket key decides *which clock's seconds* you are counting into. Event time is stamped by the producer when the event happens and is then immutable — bucketing by it measures a property of the world. Processing time is read off the consumer's clock at the moment it happens to dequeue the event, so bucketing by it measures a property of the **consumer's schedule**. As long as the consumer keeps up, the two clocks track each other and the graphs agree. The instant the consumer stops keeping up, they come apart, because event time keeps advancing in the broker's backlog while processing time is frozen until the consumer runs again. The spike is that gap made visible. During the 60-second outage, 60 events are produced — one per event-time second, 30 through 89 — and every one of them sits in the backlog with no processing time yet. At the restart instant, t=90, the consumer drains the entire backlog in one burst, so all 60 get the **same** processing-time stamp, and the one live event that genuinely arrives at t=90 joins them: 60 + 1 = **61 events in a single processing-time second**. That is the arithmetic of the 61× spike — it is exactly the length of the pause (plus the one live event of the restart second) collapsed into one bucket. Symmetrically, the 60 buckets during the outage read as 0, because their events were carried forward to t=90. Re-key the identical events by event time and each one returns to the second it was produced in; the count per second is 1 again, everywhere, because the producer really did emit one per second. No event was created or destroyed — only relabeled. **The boundary — if the consumer never falls behind, the artifact disappears.** When the consumer keeps up, `processing_time` ≈ `event_time` for every event, the two histograms are identical, and bucketing by processing time is harmless. The phantom spike is manufactured *only* by lag: an outage, a redeploy, a GC pause, backpressure, a slow downstream call — anything that pauses the consumer and lets a backlog form, which then drains in a burst. So the failure mode isn't "processing time is always wrong"; it's "processing time silently becomes wrong exactly when your system is under stress" — which is precisely when you are staring at the dashboard, and precisely when a fake 61× spike is most likely to be mistaken for a real incident. ### Go deeper 1. **Add a watermark and allowed lateness.** Real event-time windows can't wait forever for stragglers. Introduce a watermark (a "we've probably seen everything up to time T" marker) and an allowed-lateness bound, then feed the backlog through it: watch which of the 60 late events still land in their correct event-time bucket and which fall outside the window and get dropped or sent to a late-data path. 2. **Bucket by ingestion time.** Add a third timestamp — when the broker *received* the event — and re-bucket. Ingestion time is stamped before the consumer outage, so it sits between event time and processing time: predict whether the spike survives, and see why "when the broker got it" is a better-but-still-imperfect proxy for "when it happened." 3. **Vary the outage length.** Make the pause 10s, then 120s, and confirm the peak processing-time rate is (outage length + 1)× every time — the spike's height is just the backlog depth, so a dashboard bucketed by processing time turns every consumer pause into a proportional lie.