Scheduler

Chasing a Go latency spike

An HTTP service of mine usually answered in a few milliseconds but occasionally took more than 100. Average latency looked healthy, which is one of the average’s less charming habits. I wanted to know whether requests were waiting on the network, the scheduler, or garbage collection.

My first attempt added timers around every handler. That established that a slow request was slow, a breakthrough unlikely to threaten the scientific establishment. I needed observations below the handler.

I started with GODEBUG=gctrace=1. A run under load printed lines resembling:

gc1(1): 0+6+1 ms, 18 -> 22 MB 12033 -> 8411 (123004-114593) objects
gc2(1): 0+9+1 ms, 25 -> 29 MB 15020 -> 9170 (171220-162050) objects

The exact format is runtime-version dependent, but the useful correlation was clear: several latency spikes lined up with collections. The Go collector at this point includes stop-the-world work. During those pauses, goroutines do not make application progress. More processors do not turn a global pause into concurrent work.

I then reduced allocation rate rather than immediately tuning the collector. A JSON path decoded first into interface{} and then into a struct. Removing that intermediate object graph reduced collection frequency. Reusing a scratch byte slice within a request also helped, provided I kept ownership local and did not retain a huge backing array for a tiny value.

Heap size and pause time are related but not identical. Setting GOGC lower collects more often with a smaller heap; setting it higher collects less often while retaining more memory. Neither setting fixes accidental allocation. I leave GOGC at its default until measurements show a reason to trade memory for collection frequency.

The scheduler was the next suspect. Go multiplexes goroutines onto operating-system threads. Runnable goroutines wait in scheduler queues; goroutines blocked in syscalls or channel operations allow others to run. GOMAXPROCS controls how many processors may execute Go code simultaneously, not how many sockets the program may hold and not a magic goroutine limit.

I had one CPU-heavy goroutine parsing a large report. Function calls provide scheduling opportunities in the current runtime, but preemption is only partial. A long computation with few safe points can delay other runnable work, particularly with a low GOMAXPROCS. Breaking the report into bounded jobs improved fairness and made cancellation by closing a work channel practical. Adding runtime.Gosched inside the innermost loop helped one test and made the algorithm uglier, so I did not keep it.

Network waiting has a different path. On supported systems, the runtime’s network poller integrates non-blocking descriptors with mechanisms such as kqueue or epoll. A goroutine waiting for socket readiness can park without consuming an operating-system thread for the duration. When the descriptor becomes ready, the poller makes the goroutine runnable again.

This is why one goroutine per connection can be practical. It does not mean each connection has a dedicated thread. It also does not mean network code is immune to thread exhaustion: file operations and syscalls that the poller cannot manage may block threads, DNS behavior varies by platform and resolver path, and cgo calls have their own costs.

I made the wait visible by taking a goroutine profile from net/http/pprof while the service was loaded. Most goroutines were parked in network reads, which was normal. The interesting stack was a growing set waiting on one mutex around a response cache. My “thread-safe map” protected JSON encoding under the lock, turning a short critical section into serialized CPU work.

The repair copied the cached value’s reference while holding the lock, unlocked, and encoded afterward. That shortened scheduler queues during bursts. I verified the data was immutable before doing this; moving mutable state outside a lock would have exchanged latency for corruption, a poor bargain even by my standards.

One test run then looked roughly like this:

before: p50=4ms  p95=37ms  p99=128ms
after:  p50=3ms  p95=11ms  p99=42ms

The remaining tail still correlated with collections. This was not a proof that all pauses were GC pauses: kernel scheduling, packet loss, disk activity, and clients contribute too. I kept wall-clock request histograms beside allocation and GC observations rather than assigning every gap to the runtime.

The mechanism suggests a practical diagnostic order. First, establish whether time is spent runnable, blocked on synchronization, parked on network I/O, or stopped globally. Goroutine profiles reveal blocking locations, mutex and channel structure reveal serialization, GC traces reveal collection timing, and CPU profiles reveal actual execution. Then change the source of delay.

I also capped the work queue. Before that change, a burst created more live request state than workers could consume, raising heap size and GC cost after traffic subsided. Back pressure made overload visible to callers instead of translating it into a delayed collector problem. A goroutine waiting in a queue is still retained work.

My direct opinion is that “goroutines are cheap” is useful sales material and terrible capacity planning. Their stacks consume memory, their work must be scheduled, their objects burden the collector, and their shared locks serialize. The runtime makes concurrency remarkably approachable, but it cannot make an unbounded queue or a giant critical section reasonable. Mine was a runtime mystery only until I measured my own code.

What Go 1.2 changed under my goroutines

One of my test programs had a rude goroutine: it performed a long loop containing function calls while another goroutine waited to print progress. With one processor, older Go releases could let the loop dominate longer than I liked.

func spin(n int) int {
	total := 0
	for i := 0; i < n; i++ {
		total += step(i)
	}
	return total
}

func step(i int) int { return i & 7 }

Go 1.2 introduces partial preemption when entering non-inlined functions. The scheduler can arrange for a goroutine to yield when it reaches one of these safe points. I built this experiment with -gcflags=-l so the tiny step call would remain a call. It does not make arbitrary Go code preemptible at every instruction. A tight loop with no calls can still be an unpleasant neighbor, and long cgo calls remain a different matter.

That distinction matters. I first described the change to a colleague as “preemptive scheduling,” then wrote a no-call loop and disproved my own sentence. Progress became much fairer when the loop called step, but not because the runtime had acquired a general-purpose interruptible stack map for every program counter.

The other runtime change I can actually feel is stack size. New goroutine stacks in Go 1.2 start at 8 KiB rather than the smaller segments used before. That spends more virtual and physical memory up front, but avoids repeated stack splitting in modest call chains. In a crude test creating 100,000 blocked goroutines, memory is therefore not simply “100,000 times a tiny number.” Goroutines are cheap, not free.

The segmented stacks still grow by linking stack segments. This is why a function prologue checks whether enough stack remains before proceeding. The check and occasional split are part of the cost hidden behind an ordinary call.

I confirmed the scheduling effect with GOMAXPROCS=1, because multiple operating-system threads otherwise conceal starvation by running both goroutines simultaneously. That is a useful test setting, not necessarily a production recommendation. With more processors, synchronization and cache traffic enter the result; the single-processor run isolates whether one runnable goroutine gets a chance to yield to another.

Channel sends, receives, and system calls introduce other scheduling boundaries. My example intentionally removed those ordinary blocking points so the function-call behavior could be seen without a busy server around it.

My practical rule remains boring: do not add runtime.Gosched to every loop as seasoning. First determine whether the loop really starves useful work, then put natural blocking or chunking boundaries into the algorithm. Go 1.2 improves the worst behavior around calls, but it does not repeal scheduling.

Making the Scheduler Show Its Work

Scheduler discussions become folklore quickly, so I built a few experiments that force observable events instead of inferring everything from total runtime.

The first launches workers that announce when they start, wait on a gate, perform fixed CPU work, and announce completion. A channel carries each announcement to one logger goroutine. That gives me a trace without concurrent writes making the output resemble ransom typography.

func worker(id int, gate <-chan bool, events chan<- Event) {
    events <- Event{id, "ready"}
    <-gate
    burnCPU()
    events <- Event{id, "done"}
}

I run the same executable with different GOMAXPROCS values. With one processor thread allowed, CPU-bound completion is serialized even though all workers are runnable. With two, completions overlap in wall time on my dual-core machine. More than two adds runnable work but no additional cores, and eventually loses to scheduling overhead.

The second experiment replaces CPU work with pipe reads. Many goroutines can wait for I/O while the runtime arranges for other work to proceed. Increasing the processor allowance barely changes throughput because the external producer is the limit. This is why one benchmark cannot characterize “goroutine performance.”

The third experiment is intentionally rude: one goroutine runs a tight arithmetic loop with no communication while another tries to report periodically. On this early runtime, the reporter can be delayed noticeably. Scheduling behavior is under active development, and I should not assume the preemption properties of a mature operating-system scheduler.

Adding explicit communication points makes the test cooperative and reflects real pipeline code better. I do not sprinkle meaningless calls into production loops merely to influence today’s runtime; I break large work into units with natural channel operations or function calls, then measure again.

The event channel affects the experiment, of course. Observing a scheduler changes timing by adding synchronization. I keep messages outside the inner loop and compare against an uninstrumented wall-clock run. The trace explains ordering; it does not provide cycle-accurate truth.

These results belong to the May 2011 snapshot and my machine. They are not a specification of future Go scheduling, and I am deliberately avoiding an internal diagram that will expire before the ink dries. The practical findings are modest: concurrency is not parallelism, blocking and CPU work stress different paths, and processor settings should follow measurements. Schedulers are quite willing to show their work, but only if the experiment asks a specific question.

One Thread, Two Threads

I ran two independent CPU loops in goroutines and expected my dual-core machine to halve the time. It did not. Expectations remain the cheapest profiler available and the least accurate.

This runtime defaults to limited processor use. Setting GOMAXPROCS=2 for the experiment allowed Go work to execute on two operating-system threads:

$ time GOMAXPROCS=1 ./spin
real  0m3.84s

$ time GOMAXPROCS=2 ./spin
real  0m2.17s

The result is not exactly half. Both loops touch memory, the scheduler has work, and the rest of the machine has declined to disappear for my benchmark.

Goroutines and parallel execution are separate ideas. Thousands of goroutines can make a concurrent design clear while one thread runs them. Increasing the thread allowance can provide parallelism when there is independent CPU work and hardware to execute it.

The early scheduler also has rough edges. A tight loop with no calls may delay other goroutines more than I expect from mature thread schedulers. I add real synchronization rather than relying on hopeful fairness, and I test the weekly runtime I intend to use.

For I/O-heavy programs, two processor threads may change little. For CPU loops, it can help until memory bandwidth or coordination dominates. The variable is a knob, not a turbo button. Turbo buttons at least had a satisfying light.

Watching Latency on Linux 2.6

I have been comparing two Linux 2.6 configurations for a workstation: one with kernel preemption enabled and one without it. Looking only at total build time made them appear nearly identical, while using the machine made them feel different. The missing measurement was latency.

Throughput asks how much work finishes in an interval. Latency asks how long a particular piece of work waits. A kernel build is a reasonable throughput load, but its completion time does not reveal that an audio process waited long enough to miss a deadline or that keyboard input paused for a fraction of a second.

My crude but useful test runs the same build while playing audio, copying a large file, and interacting with KDE. I record build time, note audio underruns reported by the application, and repeat enough times to distinguish a pattern from one lucky run.

time make -j2 bzImage

The O(1) scheduler helps when many tasks are runnable. Its priority arrays and per-CPU run queues keep selection costs predictable, while interactive heuristics favour tasks that sleep and wake frequently. But the scheduler cannot run a task until the current execution context can be switched.

That is where kernel preemption matters. With it enabled, ordinary kernel code can be preempted when no lock or other critical condition forbids it. An interactive task awakened during a long system call may run sooner. Interrupt handlers and protected sections remain non-preemptible, so a poor driver can still dominate worst-case delay.

On my machine, enabling preemption does not materially improve the build time. It does reduce occasional input stalls and audio trouble under mixed I/O load. That is the result I expected: better responsiveness, not newly manufactured processor cycles.

Thread behaviour can alter the picture too. NPTL mutexes stay in userspace when uncontended and use futex operations when a thread must sleep or wake. A heavily contended threaded program may therefore create a very different scheduling load from one with mostly private work. Counting threads alone says little; runnable and blocked states matter.

I also test without excessive parallelism. Starting far more compile jobs than processors can turn the test into a contest between memory pressure, disk traffic, and scheduling. That may resemble a real workload, but it is a poor way to isolate one mechanism.

The caveat is that my observations are not hard real-time guarantees. General-purpose Linux still has sources of unbounded or hardware-dependent delay, and an average hides the worst pause. For desktop tuning, however, repeated underrun counts and interaction under a controlled load tell me more than one impressive jobs-per-minute number.

I am keeping preemption enabled on the workstation and evaluating it separately on servers. A server handling many requests may care about response-time distribution, but a batch machine may prefer the smallest scheduling overhead. There is no universally fast switch. First decide whether the itch is throughput or latency; only then does the benchmark know what question to answer.