Source: How and why the leap second affected Cloudflare DNS, by John Graham-Cumming
At midnight UTC on 1 January 2017, a leap second made a duration in Cloudflare's RRDNS go negative. The smoothed value reached a random-number call that panics on negative input, and some CNAME lookups failed. The fix stopped negative values from being recorded.
Today's trigger: the Hacker News thread BIPM decides to stop adding leap seconds to UTC. The Cloudflare postmortem shows what one inserted second did to production code.
At midnight UTC on New Year's Day, a number deep inside RRDNS, Cloudflare's custom DNS software, went negative when it should have been, at worst, zero. A little later the negative value made RRDNS panic. The panic was caught with Go's recover, and some DNS resolutions for Cloudflare-managed sites failed.
For a CNAME, Cloudflare sometimes has to look up the origin's real IP address. RRDNS asks internal resolvers, tracks how well each performs, and picks one with a weighted selection. RRDNS is written in Go and used time.Now(), which at the time did not guarantee monotonicity; Go had no monotonic time source (issue 12914). The timing code from the post:
// Update upstream sRTT on UDP queries, penalize it if it fails
if !start.IsZero() {
rtt := time.Now().Sub(start)
if success && rcode != dns.RcodeServerFailure {
s.updateRTT(rtt)
} else {
// The penalty should be a multiple of actual timeout
// as we don't know when the good message was supposed to arrive,
// but it should not put server to backoff instantly
s.updateRTT(TimeoutPenalty * s.timeout)
}
}The resolvers are tuned to answer in a few milliseconds. If time goes back a second during a resolution, rtt is negative. RRDNS smooths many measurements, so one negative sample did not flip the resolver's value, but after a few the smoothed value became negative. The weighted selection feeds these values to rand.Int63n(), which panics if its argument is negative.
One second backwards, four steps to a failed lookup.
The post calls it "the one character fix". With a non-monotonic clock, check whether the difference between two timestamps is negative; until the clock stops rewinding, the real difference cannot be known.
| 2017-01-01 (UTC) | Event |
|---|---|
| 00:00 | Impact starts |
| 00:10 | Escalated to engineers |
| 00:34 | Issue confirmed |
| 00:55 | Mitigation deployed to one canary node and confirmed |
| 01:03 | Mitigation deployed to canary data center and confirmed |
| 01:23 | Fix deployed in most impacted data center |
| 01:45 | Fix being deployed to major data centers |
| 01:48 | Fix being deployed everywhere |
| 02:50 | Fix rolled out to most of the affected data centers |
| 06:45 | Impact ends |
Go 1.9 added transparent monotonic time: the time package tracks monotonic time in each Time value, which makes computing durations between two Time values safe when the wall clock is adjusted. The package docs state the rule:
"The general rule is that the wall clock is for telling time and the monotonic clock is for measuring time."
Since then, time.Now() carries both readings, and subtractions such as t.Sub(start), time.Since and time.Until use the monotonic one.
Compute durations from a monotonic source. Where only a wall clock is available, check the difference for a negative value before it reaches code that assumes time moves forward.
Sources: all numbers, times and code from the Cloudflare post; Go 1.9 and the clock rule from the Go release notes and package docs.