A Timeout Raised During an Incident Explains Itself Three Weeks Later

At two in the morning an alert fires: the orders database is answering slowly, and order requests are timing out. The on-call engineer raises the database timeout from 5 seconds to 30 so requests stop failing while a replica catches up. It works. The alert resolves. Everyone goes back to bed.

Three weeks later someone notices the timeout is 30 seconds and wonders whether that’s a typo. Changing it back might be right. It might also bring the incident back. The person who knows is on holiday, and the incident channel has scrolled far out of sight.

This is the most common way a setting goes stale: a sensible change made under pressure, with its reason in someone’s head. In XKV the reason travels with the value.

The why tree for db.timeout: 30s, set by sam@oncall to stop order requests timing out while the replica catches up, ref INC-4410, caused by the alert on orders database latency firing with p99 at 8.2 seconds.

What Gets Written

The alerting system records the alert as a value, with the incident number:

alerts := xkv.WithActor(ctx, "alertmanager")
alert, err := db.Put(alerts, "alert:orders-db-latency", []byte("firing: p99 8.2s"),
	xkv.Reason("p99 above 5s for 10 minutes"), xkv.Ref("INC-4410"))

On call raises the timeout and points at the alert:

oncall := xkv.WithActor(ctx, "sam@oncall")
_, err = db.Put(oncall, "db.timeout", []byte("30s"),
	xkv.Reason("stop order requests timing out while the replica catches up"),
	xkv.Ref("INC-4410"), xkv.Cause(alert.Key, alert.Rev))

When the incident closes, the alert’s value changes to “resolved”. Nobody touches the timeout, which is how these things happen.

Three Weeks Later

db.timeout = 30s   r3
│ was 5s · by sam@oncall · stop order requests timing out while the replica catches up · ref INC-4410
└─ alert:orders-db-latency = firing: p99 8.2s   r2
     by alertmanager · p99 above 5s for 10 minutes · ref INC-4410

The answer has everything needed to decide. The timeout was 5 seconds before. It went up because of a latency alert, during incident INC-4410, for a stated reason. A second question settles it: what’s the alert now?

now, err := db.Get(ctx, "alert:orders-db-latency")   // "resolved"
old, err := db.GetAt(ctx, "db.timeout", alert.Rev)   // "5s"

The alert is resolved, and GetAt shows the timeout was 5 seconds when the alert fired. The timeout can go back to 5 seconds, and that write can name the resolved alert as its cause, so the history stays readable in both directions.

Run It Yourself

git clone https://github.com/explainable-kv/xkv
cd xkv
go run ./examples/incident-timeout

The forgotten timeout is also one of the stories in the live demo.