A Go service stalls for four seconds twice a day; how do you get an execution trace of it?
answer
- you cannot schedule an unpredictable event
- record always, keep only the recent past
- a bounded in-memory window, overwritten
- the process itself notices and dumps
- the run-up matters more than the stall
basics
~20 sRun runtime/trace.FlightRecorder continuously: it keeps a recent window of trace data in memory, and an in-process watchdog that notices the stall calls WriteTo to dump it. On-demand capture starts too late for an event this short.
solid answer
~50 sA five-second on-demand capture only works if you can predict the five seconds, and a twice-daily stall defeats that. The tool for it is the flight recorder in `runtime/trace`: you start a `FlightRecorder` at boot and it continuously retains the most recent slice of trace data in memory, bounded by a minimum age and a maximum size, overwriting older data. Nothing is written until you ask. Then you add a trigger inside the process — a watchdog goroutine that notices a health-check or request timer exceeding its budget — and on trip it calls `WriteTo` to dump the retained window to a file. Because the buffer covers the seconds *before* the trigger fired, you get the stall and its run-up, which is the part you actually need. The costs to state honestly: the tracer is running all the time, so you pay a few percent of CPU and hold the buffer's worth of memory permanently.
code
go · 17 linesfr := trace.NewFlightRecorder(trace.FlightRecorderConfig{
MinAge: 5 * time.Second,
MaxBytes: 32 << 20,
})
if err := fr.Start(); err != nil {
log.Fatal(err)
}
defer fr.Stop()
// ... elsewhere, when the watchdog sees a tick arrive seconds late:
f, err := os.Create(fmt.Sprintf("stall-%d.trace", time.Now().Unix()))
if err == nil {
if _, err := fr.WriteTo(f); err != nil {
log.Printf("flight recorder dump failed: %v", err)
}
f.Close()
}go deeper
Recall that Go has a flight recorder in runtime/trace which keeps a recent window of trace data in memory and writes it out only when you ask, unlike the ordinary start-and-stop capture.
Explain the mechanics: a bounded circular buffer configured by minimum age and maximum bytes, WriteTo persisting the retained window, and recording continuing afterwards.
Show you can design the whole loop — in-process detection of the anomaly, a rate-limited dump, a bounded destination — and state the standing CPU and memory cost you are accepting for it.
Own the call about whether the service carries this permanently: what class of incident justifies always-on tracing, what you would try first that is cheaper, and who is accountable for the artefacts it writes on production hosts.
## Why the obvious approach fails The standard capture paths are all *prospective*: `runtime/trace.Start` records from now, `go test -trace` records a run you launch, `/debug/pprof/trace?seconds=5` records the next five seconds. Every one of them requires you to be present, and pointed at the right instance, before the interesting thing happens. A stall that lasts four seconds and occurs twice a day gives you a window you cannot hit by hand, on one instance out of many, and by the time an alert reaches a human the evidence is gone. The general answer to "the event is over before I can attach" is a **flight recorder**: keep recording continuously into a bounded circular buffer, throw the old data away, and only persist when something tells you the recent past was interesting. ## The flight recorder in runtime/trace `runtime/trace.FlightRecorder` does exactly that. You construct it with a config, start it, and leave it running for the life of the process: ```go fr := trace.NewFlightRecorder(trace.FlightRecorderConfig{ MinAge: 5 * time.Second, MaxBytes: 32 << 20, }) if err := fr.Start(); err != nil { log.Fatal(err) } defer fr.Stop() ``` - **MinAge** asks the recorder to retain at least that much recent history, so you know the dump will cover the run-up to the trigger and not just the last few milliseconds. - **MaxBytes** caps the memory it will hold. The two are a request, not a contract: on a very busy process the byte cap binds first and you get a shorter window than the age you asked for. That tension is the whole tuning decision — a gateway holding tens of thousands of connections generates events fast, so retaining five seconds of it costs real memory. When the trigger fires, `fr.WriteTo(w)` writes the retained window out in the ordinary execution-trace format. Save it to a file (name it with the timestamp and the instance) and open it later with `go tool trace`. Recording continues, so a second incident later in the day can be dumped too — though you should rate-limit dumps so a flapping trigger cannot fill a disk. ## The trigger is the part you have to design A flight recorder with no trigger is just overhead. In-process detection is what makes it work, because only the process knows in real time that something took too long. Practical triggers: - A watchdog goroutine that ticks on a short interval and measures its own lateness — if a tick meant for 100 ms arrives 3 s late, the whole process was stalled. - A latency guard around the service's own work: if a handler or a broadcast round exceeds its budget by a wide margin, dump. - A health probe that is failing locally before the load balancer notices. Make the trigger cheap, make it fire on an *outlier* rather than a mild regression, and give it a cooldown. And dump from a goroutine that is not itself part of the stalled path if you can. ## What you do with the dump You now hold a trace whose window straddles the incident — the seconds before, the stall itself, and the recovery. That is what makes it worth the effort: the cause of a stall is almost always in the run-up, and the run-up is exactly what an after-the-fact capture misses. Open it with `go tool trace`, look at the shape of the window first, and work outwards from the moment the timeline goes quiet. ## Alternatives, and when they are better - **Continuous short captures on a loop**, keeping only the ones whose window overlapped an anomaly, is a poor substitute: it is more expensive, writes constantly, and still misses events that straddle a boundary. - **Trigger a capture from outside** — an alert that curls the trace endpoint — is reasonable when the incident lasts minutes, not seconds. Four seconds is far too short for a human or even an alerting pipeline in the loop. - **Cheaper signals first.** Before you ship a flight recorder, check whether a counter, a lightweight runtime metric, or a periodic runtime tracer already tells you enough. A trace is the heavy artillery; reach for it when you need to know exactly what was and was not running. ## The costs, stated plainly The tracer is on permanently, so you carry its CPU cost continuously rather than for five seconds — small in recent Go, but not zero, and highest on precisely the busiest process. You hold the buffer's memory for the life of the process. And you have added a code path that writes a file on a production host, which needs a size cap, a rate limit and a known destination. Those are all acceptable prices for catching a twice-daily four-second stall that has otherwise resisted every attempt at capture; they are not acceptable prices for idle curiosity, and saying so is part of the answer.
- How do you decide MinAge and MaxBytes for a flight recorder on a busy service?Start from the incident: you want the window to cover the stall plus enough run-up to show the cause, so MinAge is roughly the incident duration plus a margin. Then check what that costs by measuring the trace bytes the process produces per second under load, and set MaxBytes to a memory figure you are willing to hold permanently. If the cap binds first, you get a shorter window than you asked for — that is the tradeoff to state, not to hide.
- What triggers the dump, and why must the detection live inside the process?Something that knows in real time that the process was stalled — typically a watchdog goroutine measuring its own tick lateness, or a latency guard around the service's own work. External alerting is too slow: by the time a scrape interval and an alert rule have fired, seconds have passed and the retained window may already have rolled past the incident.
- What could go wrong if the trigger fires often?Each dump writes a large file and does I/O on a host that is already unhappy, so a flapping trigger can fill a disk and add load during an incident. Give it a cooldown, cap the number of dumps per hour, write to a known bounded location, and prefer a threshold that only an outlier crosses rather than one a mild regression trips.
- Why is a trace whose window ends at the trigger more useful than one that starts there?Causes precede symptoms. By the time you notice the stall, the thing that caused it — a lock held too long, a burst of allocation, a queue that filled — has usually already happened. A recorder that retains the seconds before the trigger captures that run-up; an on-demand capture started at the trigger records only the aftermath and the recovery.
An aircraft flight recorder is always running but only ever holds the last stretch of flight; nobody decides to start recording after the bang.
saying these in an interview costs you the question
- Proposes curling the trace endpoint after the alert fires
- Suggests leaving runtime/trace.Start on permanently writing to disk
- Assumes the flight recorder writes continuously to a file
- Ignores the memory the retained window costs
- Adds a dump trigger with no cooldown or size cap
- Expects a trace started at the symptom to show the cause