High p99 latency at low CPU usage is caused by CPU throttling

Every metric on the dashboard is within its normal range. CPU usage is 44%, memory has headroom, and the error rate is zero. p50 (the value in the exact middle when response times are sorted from shortest to longest) is 21ms, the same as usual.

In that state, p99 (the value at the boundary with the slowest 1% when response times are sorted) goes up and stays up. It is normally 31ms, and now it is 139ms.

The slow requests are not concentrated in any particular time of day. A single request to the same endpoint returns quickly.

At the time this was found, it was not clear under what conditions requests became slow.

I reproduced this state with Docker and measured why only p99 gets slow.

Impact

The first impact is slower responses for users. At least 1 in 100 requests waits 139ms or more for a response that would normally come back in 31ms. Since every metric on the dashboard is within its normal range, no alert fires, and nobody notices that slow responses keep happening.

The second impact is cost. Raising the CPU limit to bring p99 back means fewer containers fit on one host, so more hosts are needed. And because usage is 44%, usage cannot tell you how far to raise the limit. Too little, and requests stay slow. Too much, and the extra becomes idle host capacity.

Reproduction

I reproduced the state above with Docker on a GitHub Actions runner (ubuntu-24.04, 4 vCPU, cgroup v2).

The server under test is an HTTP server that spends 20ms of CPU time per request and returns an empty 200. Four workers each accept and handle connections. There is no queue inside the application; while all workers are busy, connections wait in the kernel's accept queue. This is so the queue length can be read from outside the server with ss. The container has a CPU limit set with --cpus 0.5.

Load was applied from outside the container for 60 seconds. Each request opened its own connection, at an average of 10 per second, with random intervals between arrivals (Poisson arrivals). This models many users sending requests independently.

At 20ms per request and 10 requests per second, CPU usage works out to 40% of the limit. Latency was measured on the load generator side, from send to receive.

Item	Value
CPU usage (60-second average)	43.5%
p50	20.6ms
p99	138.6ms
Errors	0 of 609

This matches the dashboard described at the start. The results are here, and the code is in show-your-work.

Each condition ran in a separate CI job, and the runner CPU model differed between jobs (a mix of AMD EPYC and Intel Xeon). Comparisons between conditions below therefore span different CPU models.

Narrowing it down

I narrowed down the source of the delay by ruling out candidates one at a time.

The accept queue

A slow request was either delayed while waiting for a worker to become free, or delayed after processing started. If there are not enough workers, connections queue in the listen socket's accept queue. Its length can be read from Recv-Q in ss -lnt.

Over the 60 seconds, Recv-Q peaked at 3 and averaged 0.018. At the moments the 7 slow requests at or above p99 were sent, it was 0 to 2. Requests were not queuing for busy workers. This rules out a worker shortage.

Downstream calls

A delay after processing starts means either waiting on something downstream (a DB or an external call) or not getting CPU. If it is waiting downstream, long entries show up in APM spans or DB-side records at the same time as the slow requests. The server under test makes no downstream calls, so this check is listed only as a step to perform on a real system, and I moved on to the CPU side.

CPU usage

The dashboard shows 44% CPU usage, so CPU looks sufficient. But that is a 60-second average, and consumption concentrated in short bursts gets buried in the average. So I collected usage again as 1-second averages.

Even at 1-second averages, usage peaked at 73.5% of the limit, and 0 of the 60 seconds were at 90% or above. Shrinking the aggregation interval to 1 second still does not show any moment where CPU runs short. Instead of making the average finer, I looked at the records of hitting the limit directly.

cpu.stat

When a container hits its CPU limit, it is stopped (throttled). The number of times it was stopped accumulates as nr_throttled in the container cgroup's cpu.stat.

Over the 60 seconds, nr_throttled increased by 65. The limit is enforced per 100ms period, and there were 531 periods in the 60 seconds (nr_periods in cpu.stat). In 12% of them, roughly once per second, the container hit the limit and was stopped. If nr_throttled is not increasing, suspect CPU contention with other processes on the host.

Usage is only 44% averaged over 60 seconds. The records so far do not explain why it still hits the limit.

Conditions for hitting the limit

--cpus 0.5 is a limit that allows using up to half a core. The kernel enforces it as up to 50ms of CPU time per 100ms period. Even with 44% usage averaged over 60 seconds, arrivals are random, so the CPU time used in each period varies.

Two possible reasons for hitting the limit: usage is high to begin with, or the 4 workers use CPU at the same time. Starting from the reproduction setup, I changed one condition at a time, ran each for 60 seconds, and compared the fraction of periods that hit the limit (nr_throttled / nr_periods, called the throttle rate below).

Usage

With 4 workers, I changed arrivals to 5 and 20 per second.

Arrivals per second	CPU usage (60-second average)	Throttle rate
5	20.5%	2.8%
10 (same as reproduction)	43.5%	12.2%
20	87.1%	70.1%

The throttle rate rises with usage. But even at 20% usage it does not reach zero; the limit is hit about 3 times per 100 periods. Usage alone does not determine it.

Number of workers

With arrivals at 10 per second, I reduced the workers to 1.

Workers	Arrivals per second	CPU usage (60-second average)	Throttle rate
4 (same as reproduction)	10	43.5%	12.2%
1	10	42.9%	13.1%

The throttle rate barely changed.

The kernel checks the total CPU time used within the period, not how many workers used it. Even when one worker handles requests in sequence, 3 arrivals in one period use 60ms, which exceeds 50ms.

CPU time per period

From these two results, whether the limit is hit appears to depend on how much CPU time is needed within a period. I split the 60 seconds of the reproduction (4 workers) into 100ms periods aligned to the times the kernel switches periods, and counted the CPU time needed in each. The CPU time needed is the sum of processing for requests arriving in that period and processing that spilled over unfinished from the previous period.

Periods needing less than 40ms never hit the limit. Periods needing 40 to 50ms hit it in 4 of 78, periods needing 50 to 60ms in 16 of 17, and periods needing 60ms or more in all 45.

Restricting to periods with no spillover from the previous period, the split follows the number of arrivals. Periods with 0 to 2 arrivals hit the limit in 0 of 410, and periods with 3 or more arrivals in 29 of 34. In the periods with 3 or more arrivals that did not hit the limit, the last arrival came 93ms or later after the period started, and its processing spilled into the next period.

Of the 65 periods that hit the limit, 36 carried spillover from the previous period. Even with low average usage, random arrivals sometimes overlap, and processing that overlaps and does not finish is carried into the next period.

Both the overlap and the carryover happen on a 100ms scale, so they do not show up as usage in either the 60-second or the 1-second average. Even at 100ms granularity, what you see depends on where the window falls.

When usage is cut into 100ms windows aligned to period boundaries, all 65 periods that hit the limit used 45ms or more. In the 1-worker run, the 100ms windows used to collect usage were offset by 74ms from the period boundaries. Each window straddled two periods, and of the 70 periods that hit the limit, only 26 showed 45ms or more.

What is happening

To see how much a request in a throttled period is delayed, I followed a single request from arrival to response.

Waiting before accept

When a connection arrives, the kernel completes the TCP handshake. Even while the container is stopped by the limit, the connection is established and placed in the accept queue.

A queued connection is accepted by a free worker, which starts processing it. This request needs 20ms of CPU time. But while the container is stopped, the free workers are stopped too and cannot accept. Even at the head of the queue, the connection waits until the next period starts.

The period's 50ms

The container is allotted a budget of 50ms of CPU time per 100ms period. This 50ms is drawn down by the total CPU time used by all workers in the container. If N workers run at the same time on separate cores, it drops by N ms per 1ms of elapsed time.

The rate of drawdown depends on the number of workers, but the total CPU time demanded in that period does not. The total decides whether the budget runs out. If 3 requests arrive in one period, the demand is 60ms, which exceeds 50ms. With 4 workers, 3 run at the same time and use it up about 17ms into the period. With 1 worker, requests are processed one at a time and it is used up at 50ms. Either way it runs out.

Whether a given request is stopped depends on whether the period's 50ms runs out before the request finishes its own 20ms. What matters is how much the requests that arrived earlier in the same period have already used. If it does not run out, the request returns in a little over 20ms.

The whole container stops

When the 50ms is used up, all threads in the container are stopped. Requests being processed stop mid-processing, and connections not yet accepted wait unaccepted.

At this point nr_throttled in cpu.stat goes up by 1. The stopped time accumulates in throttled_usec in the same file, but what gets added is not the time for one container stop. It is the time per stopped CPU. If threads running on 3 CPUs are stopped for 30ms, throttled_usec goes up by 90ms.

So dividing throttled_usec by nr_throttled does not give the length of one stop. In the 60-second reproduction, this division gave 75.0ms, but the length of each stop measured individually with bpftrace averaged 39.3ms. Summing the stopped time per stopped CPU gives 4960ms, which nearly matches the 4873ms increase in throttled_usec.

While stopped, no request in the container makes progress, whatever stage it is in. Its response is delayed by the time remaining in the period.

What the number of workers changes is when the budget runs out and how long the stop lasts from there. In the example of 3 arrivals in one period, 4 workers stop for about 83ms and 1 worker for 50ms. However, as shown below in "Tracing each request", every slow request at or above p99 was stopped twice with either number of workers.

When the next period starts, the 50ms is restored. Waiting connections are accepted, and requests that were mid-processing continue. If the budget runs out again before they finish, they stop again.

Tracing each request

In the reproduction setup, I traced each request to the thread that handled it. I matched the load generator's source port to the peer port of the connection the server accepted, and used bpftrace to record which threads were running at the moment of throttling. The length of each stop was measured as the time from the kernel's throttle_cfs_rq to unthrottle_cfs_rq.

A single stop lasted at most 84.4ms, with a median of 34.5ms, and all 65 were released when the next period started.

All 7 slow requests at or above p99 were throttled twice before returning a response. Two stops on top of 20ms of processing give 139 to 192ms. The stages at which the two stops occurred were as follows.

Stage stopped	4 workers (same as reproduction)	1 worker
Once before accept, once during processing	6 of 7	6 of 7
Twice during processing	1 of 7	0
Twice before accept	0	1 of 7

With 4 workers, the 6 requests stopped before accept waited 32 to 69ms to be accepted. Every stop during processing happened while that request's thread was running.

When these 7 were sent, Recv-Q was 0 to 2. That is the same value as when the worker shortage was ruled out in "The accept queue", so the workers were not full. Even with a short queue, if the accepting side is stopped, the connection waits at the head of the queue.

Mapping to the symptoms

Only some requests are slow because identical requests to the same endpoint split by arrival timing: some finish before the period's 50ms runs out, and the rest are stopped when it does.

The slow requests are not concentrated in any time of day because the only thing deciding the split is arrival timing; the time of day itself plays no part.

A single request is fast because no other worker is running and the period's 50ms has not been drawn down. 20ms always fits within the period's 50ms.

CPU usage stays at 44% because how much of the period's 50ms was used shows up in usage, but the time spent unable to proceed after it ran out does not.

What decides it

For a resource with a fixed amount available per period, whether it runs out is not decided by average usage alone, but by how much is used within one period. Here the period is 100ms, the available amount is 50ms, and the amount used within a period was the sum of arrivals overlapping in that period and processing spilled over from the previous period. To reduce how often it runs out, change how it is used within the period, or change how much is available per period.

When a resource is handed out in short periods and observed as averages over longer intervals, the averages do not show that the allotment ran out. Here, against the 100ms period, the dashboard used 60-second averages, and even re-collected data used 1-second averages; neither showed the periods that ran out.

So a low average is not evidence of headroom. Even if the aggregation interval is shrunk to the allotment period, windows not aligned to period boundaries show only some of the periods that ran out. The reliable check is to count the number of times it ran out. For a CPU limit, that count is nr_throttled in cpu.stat.

Remedies

The cause was the combination of the CPU limit and arrivals overlapping within one period, and it did not show up in usage. There are two places to act: change how much is available per period (raise the CPU limit), and make it possible to count how many times it ran out.

Raise the CPU limit

This increases the amount available per period. Unless it is raised enough to cover the arrivals that overlap within one period, throttling remains.

This fits when the host has spare capacity and p99 takes priority over cost. It is an option to consider when the application cannot be changed.

Add nr_throttled and nr_periods to monitoring

This does not fix p99. The next time the same symptom appears, the monitoring screen shows that the limit is being hit, without re-collecting usage as 60-second and then 1-second averages.

Both are cumulative counters, so taking the difference at your current collection interval gives the number of times the limit was hit and the number of periods in that interval.

There are two costs. The location of cpu.stat differs by environment, so collection needs per-environment configuration. And as shown by the 2.8% throttle rate at 20% usage, the throttle rate is not necessarily zero in normal operation, so choosing an alert threshold takes work.

Effect of the remedy

Keeping the reproduction setup (4 workers, 10 per second), I changed only the CPU limit to 0.5 / 0.75 / 1.0 / 1.5 / 2.0 and ran each for 60 seconds. 0.5 is the reproduction condition. The limit number is how many cores' worth may be used. 2.0 is 2 cores' worth, half of the host's 4 cores.

CPU limit	CPU usage (fraction of limit)	Throttle rate	p50	p99
0.5	43.5%	12.2%	20.6ms	138.6ms
0.75	28.1%	2.1%	20.4ms	44.5ms
1.0	21.1%	0.38%	20.4ms	33.2ms
1.5	14.5%	0%	20.5ms	31.1ms
2.0	10.5%	0%	20.4ms	33.0ms

The higher the limit, the lower the throttle rate. At 1.0 it was 0.38% (2 of 522 periods), and at 1.5 and above it was 0.

p99 is 31 to 33ms at 1.0 and above, and raising the limit further barely changes it. The "usual p99" of 31ms from the start falls in this range.

The CPU the container actually used averaged 0.21 to 0.22 cores in every condition. The limit of 1.0 needed to nearly eliminate throttling is about 5 times that.

The throttle rate went from 12.2% to 0.38% when the limit was raised from 0.5 to 1.0. With nr_throttled and nr_periods in monitoring, the effect of raising the limit can also be confirmed by the change in this value.

Notes

The CPU limit appears in cpu.max under Docker, systemd, and Kubernetes (k3s) alike, and cpu.stat can be read in all of them. A half-core limit was 50000 100000 in every case. What differs between environments is where the limit is set and the path to cpu.stat.

Environment	Where the limit is set	Location of cpu.stat	From inside the container
Docker (systemd cgroup driver)	--cpus	/sys/fs/cgroup/system.slice/docker-<id>.scope/	Readable at /sys/fs/cgroup/cpu.stat
systemd service	CPUQuota=	/sys/fs/cgroup/system.slice/<name>.service/	N/A
Kubernetes (k3s)	Pod resources.limits.cpu	/sys/fs/cgroup/kubepods.slice/kubepods-<qos>.slice/kubepods-<qos>-pod<uid>.slice/cri-containerd-<cid>.scope/	Readable at /sys/fs/cgroup/cpu.stat