Debugging Concurrency

Hold Time, Wait Time, and the Ratio Between Them

A lock held for 2ms with a p99 wait of 500ms is contended. Neither number says so on its own — 2ms is a fine critical section and 500ms could be a slow dependency. The ratio is the signal, and it is the one number that tells you whether to shrink the section or reduce the arrivals.

The question this answers

The question

Given a lock's hold time and wait time, how do I tell contention from slow work?

The work

A rate-limiter check on every inbound request: read a per-tenant counter from an in-memory map, compare against a budget, increment, release. Roughly 2ms of work under one lock, called on every request.

What is shared

One std::mutex-shaped lock guarding a hash map from tenant id to request counter, shared by every request thread in the process.

The invariant — what must stay true under every interleaving

Every accepted request increments exactly one counter exactly once, and no request is accepted after its tenant's counter has passed the budget.

Synchronization exists to preserve this sentence. If a schedule can make it false, the code is wrong no matter which primitive it uses.

WorkCan it overlap?Can it parallelise?What is shared?What ordering?What synchronization?Where is contention?What can deadlock?What can race?What is gained?What complexity?

Two numbers, four diagnoses

Hold time is how long the lock is owned: acquire to release. Wait time is how long a caller sat in the acquire queue before owning it. They answer different questions. Hold time is a property of *your code* — the size of the critical section. Wait time is a property of *arrivals* — how many callers wanted it while it was held.

The mistake that costs the most hours is reading one and concluding about the other. "Hold time is only 2ms, the lock is fine" ignores that a 2ms section called 900 times a second cannot possibly serve everyone: the section is busy 1.8 seconds out of every second, which is impossible, so a queue forms and grows without bound. "Wait is 500ms, the lock is terrible" ignores that a lock held for 400ms by design will produce a 500ms wait with almost no contention at all.

The diagnostic quantity is the ratio, read together with the utilization of the section — arrival rate times hold time. Below is the four-quadrant reading and what each quadrant actually means.

Hold timeWait p99Ratio wait/holdDiagnosisThe fix that works
Low (2ms)Low (0.2ms)~0.1Uncontended. The lock is doing its job invisibly.Nothing. Do not optimize this.
Low (2ms)High (500ms)~250Contention. Many callers, small section, queue formed.Reduce arrivals at this lock: shard it, stripe the map per tenant, or make the counter atomic.
High (400ms)High (500ms)~1.25Serialization, not contention. The section itself is slow.Shrink the section. Almost always: move I/O out from under the lock.
High (400ms)Low (5ms)~0.01A slow section nobody else wants. Correct but suspicious.Nothing urgent — but this lock becomes quadrant three the moment traffic doubles.
Reading hold and wait together. "High" is relative to the operation's own latency budget.

The read-out, and the arithmetic that explains it

The numbers below are a rate limiter under load. Hold time is stable and small — the code did not change and is not slow. Wait time is enormous, and the arithmetic explains it exactly: the section is 2.1ms of serial work, so the lock can serve at most about 476 acquisitions per second. Arrivals are 900 per second. That is not "some contention", it is a fundamentally over-subscribed serial resource, and every additional thread you add makes the wait longer, not shorter.

This is Little's Law as Working Intuition applied to a critical section. Mean queue length equals arrival rate times mean wait; equivalently, once utilization of a serial resource passes one, wait grows without bound until arrivals slow. The general treatment of that curve is Queueing: Why Systems Get Slow Before They Get Broken; the point here is that hold time and arrival rate together *predict* the wait, so a wait you cannot predict from them means you are measuring the wrong lock.

Note the last two rows. Acquisitions per second stayed flat while attempted acquisitions climbed — the lock is at its ceiling and the surplus is pure queue. That gap is the cleanest possible statement of "this lock is the bottleneck".

lock: ratelimiter.counters                     window: 60s

  hold_time      p50    2.1 ms
  hold_time      p99    2.6 ms          <-- flat, and flat all week
  hold_time      max    3.9 ms

  wait_time      p50   180   ms
  wait_time      p99   500   ms         <-- 240x the hold time
  wait_time      max  1400   ms

  ratio p99(wait) / p50(hold)  =  238

  acquisitions/sec (completed)     476   <-- 1s / 2.1ms. this is the ceiling
  acquire attempts/sec             900   <-- arrivals
  waiters (mean, sampled)           38
  waiters (max, sampled)            94

  cpu.utilization                   22 %  <-- the trap: looks like headroom
Rate-limiter lock, one minute at peak. Illustrative; derived from the arithmetic, not measured.

Which fix the ratio selects

Quadrant two — small hold, huge wait — is an *arrival* problem, and shrinking the critical section further barely helps: halving 2.1ms to 1.0ms doubles the ceiling to 950/s, which buys you until traffic grows 6%. The fixes that change the shape are the ones that reduce how many callers want the *same* lock: stripe the map into N independent locks keyed by tenant hash, give each thread a local counter reconciled periodically, or replace the whole read-modify-write with an atomic — see Atomics: What Is Actually Indivisible and What Contention Actually Costs.

Quadrant three — large hold, comparable wait — is a *section* problem, and there is nearly always one cause: something slow is inside the lock. A downstream call, a disk write, a log flush, an allocation under memory pressure. Moving it out is the fix, and Lock Scope: What You Hold It Across is the whole lesson on how to do it without losing the invariant.

The schedule below shows the mechanism generating the wait: nothing is broken, no invariant is violated, and the system is still nearly unusable. That distinction matters — a contention diagnosis is a *performance* finding, and treating it as a correctness bug sends people looking for a race that does not exist.

Four requests, one 2ms section, arriving 0.5ms apart. The invariant holds throughout.ILLUSTRATIVE
Invariant · Every accepted request increments its tenant counter exactly once, and no request is accepted past budget.
#Request 1Request 2Request 3Request 4State
1acquire (free) at t=0.0ms···holder=r1 waiters=0 r1 wait=0.0ms
2·attempt acquire at t=0.5ms — blocks··holder=r1 waiters=1
3··attempt acquire at t=1.0ms — blocks·holder=r1 waiters=2
4···attempt acquire at t=1.5ms — blocksholder=r1 waiters=3
5increment counter, release at t=2.1ms···holder=none waiters=3 counter=1
6·acquire granted at t=2.1ms··holder=r2 waiters=2 r2 wait=1.6ms
7·increment counter, release at t=4.2ms··holder=none waiters=2 counter=2
8··acquire granted at t=4.2ms·holder=r3 waiters=1 r3 wait=3.2ms
9··increment counter, release at t=6.3ms·holder=none waiters=1 counter=3
10···acquire granted at t=6.3msholder=r4 waiters=0 r4 wait=4.8ms
The counter is exactly 4 after all four complete — the invariant never breaks. What broke is latency: with arrivals every 0.5ms into a 2.1ms section, each request waits longer than the last, without bound. Contention is a queueing outcome, not a correctness bug.

Key points

  • Hold time measures your critical section; wait time measures how many callers wanted it. Neither is diagnostic alone.
  • A high wait-to-hold ratio means contention — many arrivals at a small section — and the fix is to reduce arrivals at that lock, not to shave the section.
  • A wait comparable to a large hold means serialization — the section itself is slow — and the fix is almost always to move I/O out from under the lock.
  • Arrival rate times hold time gives the section's utilization; past 1.0, wait grows without bound and adding threads makes it worse.
  • Contention is a performance finding, not a correctness one. A contended lock is still protecting its invariant perfectly.

The loop, answered

Every field is required, which is why no lesson here can recommend concurrency without naming the interleaving that breaks it, the complexity it adds, and the simpler thing to consider first.

How it works
  • Wrap acquisition: take a monotonic timestamp before the blocking call and one after it is granted; the difference is wait, recorded as a histogram under the lock's name.
  • Take a third timestamp at release; grant-to-release is hold, recorded separately.
  • Count attempted acquisitions and completed acquisitions separately — the gap under load is the queue.
  • Sample the number of waiters periodically; a waiter count that tracks pool size means every worker is behind this one lock.
  • Compute p99(wait) / p50(hold) as a derived series, and alert on that rather than on either input.
Interleavings that matter
  • Arrivals every 0.5ms into a 2.1ms section: request N waits roughly 1.6ms × N until arrivals slow, so the tail is unbounded even though every individual operation is fast.
  • One caller performs a 300ms downstream call while holding the lock; forty callers arrive during it and every one records a wait between 300ms and 8s while hold time p99 jumps to 300ms — quadrant three, and the trace shows an unchanged handler.
  • Under an unfair lock, a thread that just released can immediately re-acquire while queued waiters stay parked; wait p50 improves and wait p99 explodes, because the same unlucky waiter is skipped repeatedly — starvation dressed as good throughput. See Fairness.
What it guarantees — and does not
  • Wait time proves callers queued. It does not prove *which* caller held the lock, and pairing waiters with holders needs a dump or a profile, not a metric.
  • A low wait time does not prove the lock is uncontended — it proves it was uncontended during the measured window, and contention is bursty by nature.
  • The ratio identifies the lock as a bottleneck. It says nothing about whether the lock is *necessary*, which is a Finding the Critical Section question.
  • These metrics say nothing about correctness. A lock with beautiful numbers can still be guarding the wrong region.
Where contention appears
  • The measurement adds two clock reads inside the acquisition path, on the exact path that is already the bottleneck.
  • Recording into a shared histogram from every acquiring thread creates a second contended structure; per-thread accumulation aggregated at scrape avoids it.
  • Waiter-count sampling that walks the lock's queue may need the lock's internal state, which perturbs the thing being measured.
How it fails
  • Misreading hold time as the contention signal, concluding "the section is fast so the lock is fine", and spending the incident on the database.
  • Alerting on absolute wait time, which fires on every deliberately slow lock and never fires on the 2ms section that just crossed its utilization ceiling.
  • Starvation invisible in p50: an unfair lock keeps p50 wait low while a specific waiter is repeatedly skipped, and only p99 and max show it.
  • Convoy formation: once a queue exists, released waiters immediately re-queue behind each other and the group moves as a block, so throughput stays flat even as load drops. See Lock Convoys.
  • Instrumenting the wrapper but not the runtime's own internal locks — allocator, logger, connection pool — so the visible lock looks fine and the real queue is somewhere unmeasured.
When it helps
  • Any incident where latency rose and CPU did not — the ratio settles in one graph what otherwise takes a day of guessing.
  • Capacity planning: hold time times projected arrival rate tells you when a currently-fine lock becomes a wall, before it does.
  • Validating a contention fix. Striping a lock should drop wait p99 by roughly the stripe count while leaving hold time untouched; if hold time moved, you changed the section too and the experiment is confounded.
When it hurts
  • On locks acquired tens of millions of times a second, where the timestamp pair is a measurable share of the operation. Sample one acquisition in a thousand instead.
  • When the ratio becomes a target: teams shave hold time from 2.1ms to 1.9ms, report a win, and change the ceiling from 476/s to 526/s against 900/s of arrivals.
  • In systems where the real waiting is in a connection pool or a downstream service, and lock metrics point confidently at the wrong resource — see Connection Pool Saturation: Waiting in Front of an Idle Database.
How you would know
  • p99(wait) / p50(hold) above roughly 10, sustained: contention, regardless of the absolute numbers.
  • Completed acquisitions per second flat while attempts climb: the lock is at its serial ceiling.
  • Hold time p99 jumping to match a downstream service's latency: something did I/O under the lock.
  • Waiter count approaching pool size: every worker in the process is behind this one lock, and the service has effectively one thread.
  • Wait p50 low and p99 very high with a non-fair lock: suspect starvation before suspecting load.
Complexity it introduces
  • Two more histograms per lock, plus a derived ratio series, plus the naming discipline to keep lock names stable across refactors.
  • The wrapper must not alter acquisition semantics — no accidental reentrancy, no changed fairness, no try-lock turned into a blocking lock.
  • Alerting on a ratio is harder to explain on-call than alerting on a duration, and needs a runbook that names the four quadrants.
  • Sampling introduces its own subtlety: a 1-in-1000 sample of acquisitions under-represents exactly the bursty contention you care about unless the sample is time-based rather than count-based.
Simpler alternatives

What people believe, and what is true

Claim

The lock is held for 2ms, so it cannot be the problem.

Reality

A 2ms section can serve about 476 callers a second. At 900 arrivals a second it is the problem, and the hold time is exactly why.

Claim

High wait time means the critical section is too big.

Reality

Only in the quadrant where hold time is also high. With a small hold and a huge wait, the section is fine and the arrival rate is the problem.

Claim

Contention means there is a race condition.

Reality

Contention means the lock is working — callers are correctly serialized. It is a latency finding. Races happen where locks are absent, not where they queue.

Apply it