How do I tell whether a slow request spent its time waiting in line or actually being worked on?

A request's time in line is the total elapsed time, measured where the request arrived, minus the time anything was actually computing on its behalf. If that subtraction leaves most of the elapsed time unaccounted for, the request spent it queued, and no amount of tuning the model will help.

Take three timestamps at the edge: connection accepted, first word out, last word out. The first and last give the total. To get the serving part, count the tokens. Reading the prompt costs an amount proportional to its length, and each produced word costs an amount set by how fast the model's numbers can be read out of memory. Those two costs are measurable once on an idle service and then stay put; everything above them is waiting.

Suppose a word costs forty milliseconds on your model and reading the prompt costs eighty. A request that finishes 4800 milliseconds after it arrived, having produced 92 words, contains 92 × 40 = 3680 milliseconds of word production, plus 80 for the prompt, so 3760 milliseconds of work. The remaining 4800 − 3760 = 1040 milliseconds, a little over a fifth of the total, was queue. Run the same subtraction on the slowest request in the log and on the fastest and you have your answer per request, not just on average.

The natural guess is that the service's own latency metric will tell you, and it will not. A service that starts its timer when the request is dequeued is measuring only $s$, the half that does not degrade. Its graph reads forty milliseconds all through the incident while users wait four hundred. The same blindness applies to the machine's CPU graph: nothing is being computed during the wait, so the hardware looks healthy precisely when the queue is at its worst.

Queue depth closes the loop and needs no per-request timing at all. The number inside the service equals the arrival rate times the average time each request spends there:

At 200 arrivals per second and a steady depth of 60, the average request is inside for $60/200 = 0.3$ seconds, or 300 milliseconds. Of those 60, the ones actually being served number $200 \times 0.04 = 8$, so 52 are waiting. Against a 40 millisecond serving time, 300 milliseconds of total is almost entirely queue, and you learned it from a depth gauge rather than a stopwatch. Run backwards, it lets you promise: 400 arrivals per second at half a second each means the service must hold $400 \times 0.5 = 200$ requests in flight.

The split stops being clean in two places. As $U$ approaches one the formula diverges, and arrivals are no longer steady either, so a burst raises both terms at once and the tidy subtraction overstates the queue. And batching or memory contention can make $s$ itself grow with the number of requests served alongside yours, at which point the two terms move together and a single total can no longer be attributed to either. It also stops being useful if the clock starts anywhere but the edge: a timer inside the service omits exactly the term you are trying to measure.

Watch two clocks rather than one, because they have different causes. The pause before the first word is dominated by the queue and by prompt length; the rate of words afterwards is dominated by the model and by how many others are being decoded next to you. A service can report a respectable average while every user stares at an empty box.