Incident Command and Postmortems
Rebuilding the Timeline
In one sentence
A timeline is built from evidence, not memory. Only after aligning different time zones and drifting clocks to a single reference clock can you say "what came first", and only if you know the same symptom can come from different causes will you avoid rolling back the wrong thing.
Why this was needed
When an incident ends, everyone remembers that "errors started right after the deploy". But that "right after" is the result of a person matching logs stamped by server clocks by eye. If one server's clock is 3 minutes behind, that server's errors look as if they happened before the deploy; the other server is in KST, the deploy record is in the committer's time zone (+0900 and -0800 mixed), and the flag record is in yet another time zone. Ordering things in this state either makes a healthy deploy the culprit or pushes the real cause out of the window.
And the same symptom, "errors since around the deploy", comes from different causes. A bug in the new version, a config change that went in around the same time, latency in a downstream dependency: all three show the same 5xx spike on the graph. Yet the correct actions are, respectively, an app rollback, a config rollback, and rolling back nothing.
How it works
First, pick one reference clock. A load balancer or metrics system synced with NTP is usually the reference. If the same request is stamped on both the reference and the server (request id), the difference between the two times is that server's clock skew. Use the median of many pairs rather than one pair so processing delay does not throw you off. A time zone is not skew: reading the time zone marker and converting to the same instant comes first.
Second, line up the changes. Convert deploys, configs, and flags all to UTC instants and sort them, and treat changes within a fixed window (for example, 30 minutes) before the first error on the aligned clock as suspects.
Third, separate causes by pattern. With a bug in a rolling deploy, errors start in turn, beginning with the servers that got the new version. Config usually goes to all servers at once, so errors also start at the same time. With a dependency problem, that service's latency metric spikes first, and the shape of the errors (timeout codes, responses that took several seconds) is different.
Fourth, name the phases. If you fix detection delay (first error → alert) and mitigation time (the first point at which the error rate dropped below the threshold and stayed there) as definitions over the data, different people will not come up with different numbers.
The calculation that measures skew looks like this. If the same request is stamped on both sides, collect many differences and use the median.
req=r0700123 기준(LB) 05:21:40.112Z web-2 가 찍은 시각 05:18:12.125Z 차이 -207.987
req=r0700131 기준(LB) 05:21:44.530Z web-2 가 찍은 시각 05:18:16.541Z 차이 -207.989
… 가운데 값 ≈ -208초 (web-2 가 208초 뒤처짐)
맞춘 시각 = 서버가 찍은 시각 − 어긋남 → 05:18:12 − (−208) = 05:21:40
And the three causes of the same symptom differ in signals and actions.
| Cause | How the errors start | Signals seen alongside | What to do |
|---|---|---|---|
| Defect in the new app version | In turn, starting with servers that got the new version | Start times per server spread by the rolling interval | Roll the app back to the previous version |
| Config deploy | All servers in the same second | Right after the config deploy, ahead of the app deploy | Roll the config back to the previous revision |
| Dependency latency | All servers together, timeout codes | The dependency's p99 spikes first | Do not roll back; handle it on the dependency side |
What it looks like in the field
A common scene is "all three are the deploy's fault, so roll everything back". But errors caused by a dependency stay the same after a rollback, and the rollback itself is another change that brings in new risk. Another common scene is one server with a skewed clock creating the illusion that "there were errors before the deploy", acquitting the deploy. Both are sorted out within minutes once you align the clocks and look at the patterns.
The git record is also a trap. By default, git log stamps dates in the committer's time zone and puts the newest at the top. A commit made at 9 p.m. in the US shows as Tue Nov 3 21:14 -0800, but in UTC it is the early morning of November 4. Sorting by the date text pushes this deploy as if it were a day earlier, and it drops out of the list of "changes within 30 minutes before the incident". When collecting change records, always convert to instants (UTC) before sorting.
Detection delay is set by the alert rule. A rule of "per-minute error rate above 5% for 3 consecutive minutes" fires at the earliest when the third minute ends, and later if errors rise slowly. If you extract the detection delay from the timeline as a number, the feeling in the postmortem that "the alert was late" turns into the fact "at least 3 minutes because of the rule, 4 minutes 12 seconds in reality", and what to fix (the rule's threshold or duration) becomes clear.
What you will do in the next lab
You line up two server logs (with different time zones and clocks), a load balancer sample, the git deploy record, the flag record, and alerts and metrics to measure clock skew, and find the first error on the reference clock, the suspect changes, the detection delay, and the mitigation time. At the end, you separate the same symptom in three services by cause and roll back only what should be rolled back.