One request in a test server occasionally took much longer than its neighbours. Rather than convict the collector from one latency graph, I recorded request times and the runtime’s pause samples on the same workload.

The current collector stops application work while it traces the reachable heap. runtime.ReadMemStats exposes NumGC, PauseTotalNs, and a ring of recent PauseNs values. I sampled before and after a fixed five-minute run, then compared only collections added during that window. Mixing in old pauses made short tests look wonderfully stable or mysteriously awful depending on what had run first.

That pause is easy to describe and harder to judge. A short command-line tool may never care. A busy service with latency requirements can care very much, even if its average throughput looks fine. Averages are talented at concealing the request somebody was actually waiting for.

My first table kept four numbers for each run: requests per second, the 50th and 99th percentile request latency, collection count, and the largest observed GC pause. Average latency alone hid the event I cared about.

The naive handler allocated a buffer for every item:

func checksum(items [][]byte) uint32 {
	var sum uint32
	for _, item := range items {
		buf := make([]byte, len(item))
		copy(buf, item)
		for _, b := range buf {
			sum += uint32(b)
		}
	}
	return sum
}

The copy served no purpose. Removing it reduced collections and improved the long tail. This was not clever tuning; I had simply stopped manufacturing garbage.

The collector’s job depends on both allocated volume and live data. Producing temporary objects quickly causes collections to happen more often. Retaining a large graph gives each marking pass more reachable memory to inspect. These are different problems: one concerns allocation rate, the other heap size and object reachability.

After that fix I tried GOGC=50, the default 100, and 200, restarting the process for each run. Lowering it collected more often with a smaller heap. Raising it collected less often but used more memory. On this service, 200 helped the tail a little and increased memory enough that I kept the default. That is a result, not a disappointment.

Manual runtime.GC() calls were useful to prove that the latency recorder could see a pause. They did not belong in the handler. Forcing collection chooses when to pay and can easily turn an occasional pause into a dependable stream of them.

The useful knob came last. First came a repeatable load, pause deltas from the same time window, and removal of an accidental allocation. Otherwise GOGC is just a dial with excellent opportunities for superstition.