Skip to content

Measuring Queue Wait and Service Time Separately

A single latency histogram cannot tell you whether a service is slow because the work got harder or because there is more of it than you can do. Those need opposite responses — fix the dependency, or add capacity — and the number that distinguishes them costs one extra timestamp. Measured on a worker pool with a capacity of 800 jobs per second: at 700 per second, wait was 0 ms and service 5.3 ms; at 1,200 per second, service was still 5.3 ms and wait had grown to 471 ms. Every millisecond of the degradation was queueing, and a total-latency chart would have shown only that "it got slower".

Prerequisites

Where the two timestamps go 5 stages from enqueue to done. Where the two timestamps go enqueue stamp t0 queued wait = t1 - t0 worker starts stamp t1 work runs service = t2 - t1 done stamp t2 The item carries its own enqueue time; nothing else has to be tracked.

1. Stamp the item, not the worker

The item carries its own enqueue time, so no external bookkeeping is needed:

@dataclass
class Job:
    payload: dict
    enqueued_at: float = field(default_factory=time.perf_counter)


async def worker(queue: asyncio.Queue) -> None:
    while True:
        job = await queue.get()
        started = time.perf_counter()
        QUEUE_WAIT.observe(started - job.enqueued_at)              # the first number
        try:
            await handle(job)
        finally:
            SERVICE_TIME.observe(time.perf_counter() - started)    # the second
            queue.task_done()

perf_counter() rather than time.time(), because it is monotonic and you are measuring a duration. For work that crosses a process boundary — a database job row, a broker message — use a wall-clock timestamp instead and accept the clock skew, or have the consumer compare against the broker's own timestamp.

Two histograms, not one, and the buckets differ: wait can be seconds under saturation, while service should cluster around a known value. Give wait wider buckets.

Verify: the two histograms sum, per item, to the total latency you were already recording.

2. Read the pair, not either alone

The diagnostic power is entirely in the combination:

wait service what it means
flat, near zero flat healthy — capacity exceeds demand
rising flat saturation: add workers, or shed
flat rising the work itself got slower; look downstream
rising rising a dependency is slow and you are now behind

The measured run walks the first two rows exactly. At 200, 500 and 700 jobs per second against 800 of capacity, wait p50 was 0.0 ms. At 900 it was 202 ms, and at 1,200 it was 471 ms with 516 items still queued at the end — the queue was growing faster than it drained. Service time never moved: 5.3 ms at every rate.

The third row is the one that makes this worth instrumenting. When a database gets slower, service time rises and wait follows a moment later; an alert on total latency fires for both cases and tells you nothing about which you are in.

Verify: during a load test, service time stays flat while wait rises — if service also rises, the load test is affecting the dependency.

Wait and service time as load crosses capacity 4 bars comparing 200/s offered with the others. Wait and service time as load crosses capacity 200/s offered wait ~0 ms 700/s offered wait ~0 ms 900/s offered wait 202 ms 1,200/s offered wait 471 ms Four workers doing 5 ms of work each: capacity is 800 jobs per second. Service time stayed at 5.3 ms throughout; every millisecond of the increase was waiting.

3. Alert on wait, and know what it implies

Queue wait is the better alert because it has a direct interpretation: it is how long an item sat doing nothing, and it is zero in a healthy system regardless of traffic. Total latency has no such baseline — it depends on what the work is.

It also has a direct relationship to capacity. Little's law says queue_length = arrival_rate × wait, so a queue of 516 items draining at 942 per second implies about half a second of wait, which matches the measurement. Two practical consequences:

  • Queue depth alone is a poor alert. A depth of 1,000 is fine at 10,000 items per second and catastrophic at 10.
  • Wait tells you how much capacity you are missing. If wait is 500 ms and service is 5 ms, you need roughly 100 times the concurrency to absorb the current burst — which usually means the answer is shedding, not scaling.

That last point is the link to load shedding: the same measured wait that makes the alert is the value that policy sheds on. Instrument it once, use it twice.

Verify: your alert is on wait exceeding a threshold, not on depth or on total latency.

Reading the two numbers together A grid of 4 rows by 2 columns. Reading the two numbers together wait service means flat, near zero flat healthy: capacity exceeds demand rising flat saturation: add workers or shed load flat rising the work got slower: look downstream rising rising a dependency is slow AND you are now behind Total latency alone cannot distinguish these, which is why it is the wrong alert.

4. Measure at every queue, including the invisible ones

Explicit asyncio.Queue objects are easy to instrument. The queues that cause incidents are usually the implicit ones:

  • A semaphore limiting concurrency — the wait is the time inside async with semaphore before the body starts.
  • A connection pool — the wait to acquire is queue wait by another name, and rising pool-acquire time is the classic symptom of an undersized pool.
  • The executor — asyncio.to_thread queues when all threads are busy, as covered in timing out blocking calls in threads.
  • The event loop itself — a ready callback waiting behind a long-running one; that is loop lag.
acquire_started = time.perf_counter()
async with pool.acquire() as conn:
    POOL_WAIT.observe(time.perf_counter() - acquire_started)
    ...

Each of these has the same two-number decomposition, and each answers the same question: is this component short of capacity, or is the work behind it slow?

Verify: every bounded resource in the request path exports an acquire-wait histogram.

5. Use the split for capacity planning

Once wait and service are separate, capacity becomes arithmetic rather than guesswork:

capacity = concurrency / service_time

Four workers at 5 ms gives 800 jobs per second — which is exactly where wait started rising in the measurements. Knowing that number lets you answer "how many workers do we need for Black Friday" with a calculation instead of a load test, and it makes the effect of a slower dependency immediately visible: if service time doubles, capacity halves, and the queue starts growing at the same traffic you handled yesterday.

It also sets the shedding threshold. If service is 5 ms and the client's timeout is 250 ms, then anything that has waited more than about 200 ms cannot be served in time and should be rejected immediately — the policy measured in load shedding, where it took goodput from 308 to 1,556 requests per second.

Verify: your stated capacity matches concurrency / service_time and matches where wait starts to rise under test.

Queue wait is rising: what now? A decision on What is service time doing with 3 outcomes. Queue wait is rising: what now? What is service time doing? flat, and capacity is cheap add workers the queue is simply too short flat, and capacity is fixed shed load reject what you cannot serve in time rising too fix the dependency more workers will make it worse Adding workers when service time is rising sends more concurrent work to the thing that is slow.

Verification

The split is correctly instrumented when:

  • Every queued item carries its enqueue timestamp.
  • Wait and service are separate histograms with appropriate buckets.
  • Wait is near zero under normal load, at every percentile.
  • Alerts are on wait, not on depth or total latency.
  • Implicit queues are instrumented too: semaphores, pools, executors.
  • Capacity is derived from concurrency divided by service time, and checked against a load test.

Pitfalls & edge cases

  • Stamping when the worker starts. That measures only service time, which is exactly the number that does not move under saturation.
  • time.time() for durations. Non-monotonic; use perf_counter() within a process.
  • One histogram for both. The buckets that suit 5 ms service time cannot represent 500 ms of wait.
  • Unbounded queues. Wait grows without limit and the metric becomes a memory-growth indicator rather than a latency one.
  • Ignoring pool acquire time. The most common hidden queue in an async service.
  • Averaging wait. The distribution is heavily skewed under saturation; use percentiles.

Frequently Asked Questions

Why measure queue wait separately from service time?

Because they mean different things. Measured against a capacity of 800 jobs per second, service time stayed at 5.3 ms at every load while wait went from 0 ms at 700 per second to 471 ms at 1,200. Rising wait means add capacity or shed; rising service time means the work itself got slower.

How do I measure queue wait time in asyncio?

Record time.perf_counter() when the item is enqueued, store it on the item, and subtract it from the time the worker starts processing. Record the service time separately from start to finish. Two histograms, and their sum is the total latency you were already reporting.

Should I alert on queue depth or queue wait?

Wait. Depth has no fixed meaning — 1,000 items is trivial at 10,000 per second and an outage at 10 — while wait is directly interpretable and is zero in a healthy system at any traffic level. Little's law relates the two: depth equals arrival rate times wait.

What does rising service time with flat queue wait mean?

The work got slower but you still have capacity for it — typically a dependency degrading. Adding workers in that state makes things worse by sending more concurrent requests to the thing that is already slow. Investigate downstream instead.

How do I calculate a worker pool's capacity?

Concurrency divided by service time: four workers each taking 5 ms is 800 jobs per second, which is precisely where queue wait began to rise in testing. That number also sets your shedding threshold, since anything waiting longer than the client's remaining budget cannot be served in time.