Logging and monitoring — structured logging, metrics, alerting: Worked examples

Two symbols we lean on all page — defined once, here

The scenario matrix

Every worked example below is tagged with the cell of this matrix it covers. Together they touch every cell.

#	Case class	What makes it tricky	Covered by
C1	Counter → rate, clean	ordinary slope of a monotone line	Ex 1
C2	Counter reset / wrap-around	value drops → naive subtraction goes negative	Ex 2
C3	Percentile, ordinary	pick the rank, read the value	Ex 3
C4	Percentile, degenerate + interpolation	rank rounding, tail dominates, even- $n$ median	Ex 4
C5	Error budget → count & time	multiply the fraction	Ex 5
C6	Budget burn rate (limiting: how fast is "too fast")	rate of spending vs allowed	Ex 6
C7	Alert with `for` duration (noisy input, blip vs real)	sustained-condition logic	Ex 7
C8	Average vs percentile trap (the "looks fine" case)	mean hides the tail, p100 = max	Ex 8
C9	Real-world word problem (structured-log field design)	choosing what to emit	Ex 9
C10	Exam twist (multi-window burn-rate alert)	combine burn rate + windows	Ex 10

Ex 1 — Counter → rate, clean (C1)

Worked example Statement

A request counter reads $C (t_{1}) = 1, 000, 402$ at $t_{1} = 12 : 00 : 00$ and $C (t_{2}) = 1, 003, 402$ at $t_{2} = 12 : 00 : 30$ . What is the request rate in requests/second?

Forecast: guess before reading — is it closer to 1, 100, or 3000 req/s?

Step 1 — Find the number of events. Subtract the two readings. $Δ C = 1, 003, 402 - 1, 000, 402 = 3000 events$ Why this step? A counter increments by one per event, so the difference between two readings is exactly how many events happened in between — the absolute value $1, 003, 402$ is meaningless on its own (see Time Series Databases).

Step 2 — Divide by the elapsed time. $Δ t = 30 s, rate = \frac{Δ C}{Δ t} = \frac{3000}{30} = 100 req/s$ Why this step? Events ÷ seconds = events per second. This is the discrete version of the derivative (slope) from the parent's rate formula.

Verify: units check — $\frac{events}{s}$ ✓. Sanity: 100 req/s over 30 s is 3000 events, matches Step 1. ✓

Ex 2 — Counter reset AND wrap-around (C2)

Two distinct ways a counter's value can drop, both of which break naive subtraction.

Worked example Statement (a) — full reset (process restart)

A counter reads $C (t_{1}) = 5, 000, 000$ , then $C (t_{2}) = 200, 000$ over $Δ t = 15$ s. What rate should the system report?

Forecast: the naive subtraction gives a negative number. Is the real rate negative? (No — a counter cannot count backwards.)

Step 1 — Try the naive formula and watch it break. $\frac{200 , 000 - 5 , 000 , 000}{15} = \frac{- 4 , 800 , 000}{15} = - 320, 000 req/s$ Why this step? A negative rate is physically impossible for a monotone counter — this is our red flag. The drop means the counter reset to zero (process restart), then climbed back to 200,000.

Step 2 — Detect the reset. A counter is defined to only increase. If $C (t_{2}) < C (t_{1})$ , a reset happened. This is the sign-based case check — just like the arctan quadrant fix, we look at the sign of the difference to know which formula applies. Why this step? The sign of the difference is the flag that tells us which formula to use: a non-negative difference means "ordinary slope" (Ex 1), a negative difference means "a reset happened, switch formulas." Checking the sign first prevents us from ever reporting the impossible negative rate from Step 1.

Step 3 — Apply the reset correction. Assume it reset to 0 and counted up from there, so the events since restart are simply $C (t_{2})$ : $rate = \frac{C ( t _{2} )}{Δ t} = \frac{200 , 000}{15} \approx 13, 333.33 req/s$ Why this step? After a reset the counter is the count-since-reset. Real systems (Prometheus rate()) do exactly this: on any decrease, they treat the new value as the increment. It slightly under-counts (misses the events right at the boundary) but is never negative.

Verify: result is positive ✓ and equals events-since-reset ÷ time ✓. $13, 333.33 \times 15 = 200, 000$ ✓.

Worked example Statement (b) — fixed-width WRAP-AROUND

A different, sneakier drop. Some counters live in a fixed-width integer — say an unsigned 32-bit counter, whose maximum value is $M = 2^{32} - 1 = 4, 294, 967, 295$ . When it exceeds $M$ it "wraps" back around to 0 (like a car odometer rolling over from 999999 to 000000). It reads $C (t_{1}) = 4, 294, 967, 290$ , then $C (t_{2}) = 60$ over $Δ t = 10$ s. It did not restart. What is the true rate?

Forecast: did roughly 5 events happen, or roughly 4 billion?

Step 1 — Recognise it is a wrap, not a reset. In a reset the counter returns to 0 and the pre-reset events are lost. In a wrap the counter is still running; it just overflowed past $M$ and continued from 0. The give-away is knowing the counter's width. Here $C (t_{2}) < C (t_{1})$ but the process is alive. Why this step? Reset and wrap look identical (a drop) but need different arithmetic — this is the extra edge case beyond a plain restart.

Step 2 — Add the modulus back. The true number of increments is the distance from $C (t_{1})$ up to $M$ , plus one to roll to 0, plus the new $C (t_{2})$ : $Δ C = (M - C (t_{1})) + 1 + C (t_{2}) = (4, 294, 967, 295 - 4, 294, 967, 290) + 1 + 60 = 5 + 1 + 60 = 66$ Why this step? We "unwrap" by measuring how far it climbed before rolling over ( $M - C (t_{1}) + 1$ takes it to zero) and then how far past zero it went ( $C (t_{2})$ ).

Step 3 — Rate. $rate = \frac{66}{10} = 6.6 req/s$ Why this step? Now the increment is a small, physical number, not a negative one.

Verify: $Δ C = 66$ is tiny and positive ✓. Contrast with reset case (a) where we'd have thrown away pre-drop history; here we recover it because the counter never actually restarted ✓.

Ex 3 — Percentile, ordinary (C3)

Read the figure below to see what "value at a rank" means: the bar chart plots the 20 sorted latencies (black) with each bar's height = its latency and its position = its rank. The two red bars are exactly the ranks the formula selected — rank 10 (p50) and rank 18 (p90). The picture makes the definition concrete: a percentile is not a computed average, it is literally one bar you point at after sorting.

Figure — Logging and monitoring — structured logging, metrics, alerting

Ex 4 — Percentile: degenerate inputs AND interpolation (C4)

Four sub-cases: all-equal, tiny- $n$ tail, even- $n$ median interpolation, and why they differ.

Worked example Statement (c) — even-

$n$ median and INTERPOLATION Take the six values [10, 20, 30, 40, 50, 60], $n = 6$ . What is the median (p50)? Notice there is no single middle — 6 is even, so the middle falls between rank 3 (30) and rank 4 (40).

Forecast: should the median be 30, 35, or 40?

Step 1 — Nearest-rank answer (this page's default). $k = ⌈ 0.50 \times 6 ⌉ = ⌈ 3 ⌉ = 3 \Rightarrow P_{50} = x_{(3)} = 30$ ms. Why this step? Nearest-rank always lands on an actual observed sample, so it never invents a value that didn't occur.

Step 2 — Interpolated answer (the "textbook median"). Many definitions instead average the two middle values for even $n$ : $median = \frac{x _{(3)} + x _{(4)}}{2} = \frac{30 + 40}{2} = 35 ms$ Why this step? Interpolation gives a smoother, more "central" number and is what spreadsheets/numpy.percentile do by default (linear interpolation between neighbouring ranks). It can return a value no request actually had (35 ms here), which is fine for a summary statistic but surprising if you expected a real observation.

Verify: nearest-rank gives an observed value (30) ✓; interpolation gives the arithmetic midpoint (35) ✓; the two differ by exactly half the gap between ranks 3 and 4 ✓.

Ex 5 — Error budget → count and time (C5)

Worked example Statement

Your SLO is 99.95% success over a 7-day window during which you serve 20,000,000 requests. How many failures are allowed, and how much downtime does that equal?

Forecast: more or fewer than 100,000 failures?

Step 1 — Failure fraction. Budget fraction $= 1 - SLO = 1 - 0.9995 = 0.0005$ . Why this step? SLO is the fraction that must succeed; whatever's left over is the allowed failure — the parent's derivation.

Step 2 — Failures allowed (count). $0.0005 \times 20, 000, 000 = 10, 000 failed requests$ Why this step? Fraction × total = count. This is a hard budget: fail 10,000 and you've spent it all.

Step 3 — Downtime allowed (time). First convert the window to minutes, then multiply by the failure fraction. $window = 7 \times 24 \times 60 = 10, 080 minutes$ $0.0005 \times 10, 080 = 5.04 min/week$ Why this step? Fraction × window = allowed unavailable time. We must express the window in the same time unit we want the answer in (minutes), hence the $7 \times 24 \times 60$ conversion first. "Three-and-a-half nines" buys you only ~5 minutes a week — a number worth memorising before you promise it to a customer.

Verify: units — (dimensionless fraction) × requests = requests ✓, × minutes = minutes ✓. $10, 000/20, 000, 000 = 0.0005$ ✓.

Ex 6 — Budget burn rate, limiting behaviour (C6)

Worked example Statement

Same 99.95% SLO over 7 days = 10,000 allowed failures. In the last 1 hour you served 200,000 requests and 500 failed. What is your burn rate (how many times faster than sustainable are you spending the budget)?

Forecast: is $14 \times$ possible? Guess before computing.

Step 1 — Your actual error rate this hour. $error rate = \frac{500}{200 , 000} = 0.0025 = 0.25%$ Why this step? Burn rate compares actual failure fraction to the budgeted one, so we first need the actual fraction failing right now.

Step 2 — Divide by the budget fraction. The budget allows 0.0005 (0.05%). Burn rate is the ratio: $burn rate = \frac{0.0025}{0.0005} = 5 \times$ Why this step? A burn rate of 1 means you'd spend the whole budget exactly over the whole window. A burn rate of 5 means you'd exhaust a 7-day budget in $7/5 = 1.4$ days.

Step 3 — Time to exhaustion (the limiting view). $time to burn all budget = \frac{window}{burn rate} = \frac{7 days}{5} = 1.4 days$ Why this step? This is why we alert on burn rate instead of raw errors — it directly answers "how long until we breach the SLO?" See Incident Response.

Verify: at 5× burn for 1.4 days you'd accrue $5 \times \frac{1.4}{7} = 1.0$ of the budget ✓. Also $0.25%/0.05% = 5$ ✓.

Ex 7 — Alert with a `for` duration, noisy input (C7)

Worked example Statement

Alert rule: error rate > 2% for 5 minutes. The metric is scraped every minute. Here is a 9-minute trace of error rate: [0.5, 3.0, 0.4, 2.5, 2.8, 2.1, 2.9, 3.2, 2.6] (percent, minutes 1–9). At which minute (if any) does the alert fire?

Forecast: minute 2 spiked to 3% — does it fire then?

Step 1 — Mark which minutes breach the threshold ( $> 2%$ ). Minute: 1❌ 2✅ 3❌ 4✅ 5✅ 6✅ 7✅ 8✅ 9✅ Why this step? The threshold gives a boolean per scrape; the for clause then requires a run of trues.

Step 2 — Find the first sustained run of length ≥ 5. Minute 2 is a single-scrape blip (minute 3 is below), so it resets. The next run starts at minute 4 and is continuous: 4,5,6,7,8,9. The condition has held continuously starting at minute 4; after 5 consecutive breaching minutes (4,5,6,7,8) the for: 5m is satisfied at minute 8. Why this step? The for clause needs the condition continuously true for the whole duration — the blip at minute 2 is exactly the false page the clause exists to suppress.

Verify: run length required = 5; run 4→8 inclusive is 5 minutes ✓; the lone minute-2 spike never reaches length 5, so no false page ✓. This is the noise-vs-signal tradeoff from the parent — 4 minutes of detection delay bought in exchange for killing single-scrape false alarms.

Read the figure below to see the for logic: the black step line is the error rate minute by minute; the dashed line is the 2% threshold. The red shaded band marks the continuous breaching run (minutes 4–8) that finally satisfies for 5m, and the red dot marks the exact minute the page fires. Notice the lone spike at minute 2 pokes above the threshold but sits alone — the picture shows why it never accumulates a 5-minute run and so is correctly ignored.

Ex 8 — Average vs percentile, the "looks fine" trap (C8)

Worked example Statement

100 requests: 99 of them take 10 ms, and 1 takes 7000 ms (7 s). Compute the mean latency and the p99, and decide whether the dashboard-green "mean = 80 ms" is honest.

Forecast: which one screams "problem"?

Step 1 — Mean. $\overset{x}{ˉ} = \frac{99 \times 10 + 1 \times 7000}{100} = \frac{990 + 7000}{100} = \frac{7990}{100} = 79.9 ms$ Why this step? The mean smears the one 7-second outlier across all 100 samples, producing a comfortable-looking ~80 ms.

Step 2 — p99. Sorted, the 7000 ms is the single largest. $k = ⌈ 0.99 \times 100 ⌉ = 99 \Rightarrow P_{99} = x_{(99)} = 10$ ms. But p100 (the max, from the definition above) = 7000 ms, and 1 in 100 users hits it. Why this step? With exactly one bad sample out of 100, p99 still sits at 10 ms — you need p99.9 or p100 to see the outlier. On a page that fires 100 sub-requests, that 1% chance means nearly every page contains one 7-second call.

Verify: mean $= 7990/100 = 79.9$ ms ✓. Fraction of users hitting 7 s $= 1/100 = 1%$ ✓. Conclusion: the mean is technically true but operationally a lie — the parent's core warning about tails.

Ex 9 — Real-world word problem: designing log fields (C9)

Worked example Statement

A user emails "my payment failed at about 3 pm and I got charged twice." You must design the structured log event for a payment attempt so this complaint is answerable in one query. Which fields do you emit, and which must you never emit?

Forecast: list 5 fields before reading on.

Step 1 — Fields that let you find the events. request_id and trace_id (stitch the whole request across services, see Distributed Tracing), user_id (slice to this one complainer), ts (the "around 3 pm" filter). Why this step? Every field must be something you'll filter, group, or alert on — the parent's rule. Without user_id you cannot isolate one customer; without trace_id you cannot see the double-charge as two attempts of one flow.

Step 2 — Fields that let you diagnose. event="payment_attempt", amount_cents=1999, currency="USD", idempotency_key, outcome="success|declined|error", attempt_number. Why this step? idempotency_key reveals whether the "double charge" was two distinct intents or a missing dedup — the actual bug class. Numeric amount_cents can be summed/aggregated.

Step 3 — Fields you must NEVER log. Full card number (PAN), CVV, password, raw auth token. Why this step? Logging these is a compliance/security breach — the parent's PII and Data Privacy warning. Log a masked card_last4="4242" instead.

Verify: the single query event=payment_attempt AND user_id=42 AND ts~15:00 returns both attempts, showing the same idempotency_key — so the "double charge" is diagnosed as a missing-dedup bug, and no secret was ever written to the logs. Complaint answerable in one query ✓, zero PII leaked ✓. Aligns with Observability.

Ex 10 — Exam twist: multi-window burn-rate alert (C10)

Worked example Statement

An SLO of 99.9% uses two burn-rate alert windows (Google SRE style): a fast alert (1-hour window, burn rate ≥ 14.4) and a slow alert (6-hour window, burn rate ≥ 6). Over the last hour you burned 2% of the monthly budget. Does the fast alert fire? And what does burn rate 14.4 mean in hours-to-exhaustion?

Forecast: 2% in an hour — feels small. Trap?

Step 1 — Convert "2% of monthly budget in 1 hour" to a burn rate. A burn rate of 1 spends $\frac{1}{month}$ of the budget per unit time; over 1 hour that is $\frac{1}{30 \times 24} = \frac{1}{720} \approx 0.1389%$ of the monthly budget. $burn rate = \frac{2%}{0.1389%} = 2% \times 720 = 14.4$ Why this step? Burn rate = (fraction of budget spent) ÷ (fraction of window elapsed). One hour is $1/720$ of a 30-day month, so spending 2% of the budget in that hour is $0.02 \times 720 = 14.4 \times$ the sustainable pace.

Step 2 — Does the fast alert fire? Threshold is ≥ 14.4, and we got exactly 14.4 → yes, it fires. Why this step? The 14.4 threshold is chosen so the alert fires when you'd burn the whole month's budget in about 2 days, while the 1-hour window makes it fast to react.

Step 3 — Hours to exhaust the whole monthly budget at 14.4×. $\frac{30 days \times 24}{14.4} = \frac{720}{14.4} = 50 hours \approx 2.08 days$ Why this step? This is why 14.4 is the magic number — it corresponds to burning a 30-day budget in ~2 days, urgent enough to page immediately.

Step 4 — Why TWO windows (the exam twist). The slow alert (6-hour window, burn ≥ 6) catches a gentler leak that the fast alert would miss, while the fast alert catches sudden gushers the slow one is too laggy to see. Pairing a fast+sensitive and a slow+steady window gives both quick detection AND few false pages — the multi-window burn-rate pattern. Why this step? A single window forces one bad tradeoff (fast = noisy, slow = late); two windows let you have both, the whole reason the exam favours this design.

Verify: $0.02 \times 720 = 14.4$ ✓; $720/14.4 = 50$ hours ✓. See Rate Limiting for the analogous "consuming an allowance too fast" pattern.

Recall Rapid self-test

Two counter reads 900 then 300 over 10 s (64-bit, alive) — reported rate? ::: Treat as reset (a decrease); rate = 300/10 = 30 req/s (never negative). A 32-bit counter reads its max 4,294,967,295 then 4 over 5 s — increments? ::: Wrap-around: (M − old) + 1 + new = 0 + 1 + 4 = 5 increments, rate 1 req/s. p95 of 10 samples where the max is 800 ms? ::: 800 ms — because $⌈ 0.95 \times 10 ⌉ = 10$ , the last rank; too few samples to trust. Median of [10,20,30,40,50,60] by nearest-rank vs interpolation? ::: Nearest-rank 30; interpolated 35 (average of 30 and 40). 99.95% SLO over 7 days with 20M requests — allowed failures? ::: 10,000 failures (≈ 5.04 min/week). Error rate 0.25% against a 0.05% budget — burn rate? ::: 5× (exhausts a 7-day budget in 1.4 days). Alert "> 2% for 5 min", one-minute blip at minute 2 — does it page? ::: No; a single-scrape spike resets the for run. What is p100? ::: The maximum (rank $n$ ); $P_{0}$ is the minimum.