LATENCY · WORK VERSUS WAITING
Debugging latency: inspect work and waiting
Four requests arrive together. Inspect the fourth request’s trace and separate the time spent working from the time spent waiting for workers and connections.
Your experiment
Each request routes in 200 ms, calls the model for 1,200 ms and runs three tools that each do 100 ms of work plus a database query of 200, 350 or 500 ms. The objective is 2,500 ms for every request. Start with two workers, sequential tools and one connection, then find where the fourth request’s time goes.
Play replays the computed run over sixty inspection seconds; Next event steps, Restart rewinds, Speed changes the pace and Inspection time scrubs. Any input change recomputes the run and rewinds it without autoplay.
Event trace
Computed data
Final metrics
Deterministic model of one burst: four requests arrive at once and all take the same time; tools need one connection each for their query and wait for a free one; the model call never waits. Real traces add variance, retries, garbage collection and network time, but the split between work and waiting is read the same way.
Four requests, one slow trace
Four requests arrive together and you inspect the fourth, R4. Each request routes in 200 ms, calls the model for 1,200 ms and runs three tools, each 100 ms of work plus a database query of 200, 350 or 500 ms. With 2 workers and sequential tools one request takes 2,750 ms, so R4 waits 2,750 ms for a worker and finishes after 5,500 ms: TOO SLOW against the 2,500 ms objective. Half of R4’s latency is waiting in a queue, which no span of its own work shows.
Parallel tools meet the connection pool
Set Tool calls to In parallel. The three tools start together, but with one database connection the queries take turns: inventory waits 200 ms and shipping 550 ms for the connection, so the tool phase is 1,150 ms rather than 600. Database connections in the pool applies only to parallel tools: with 2 connections the phase is 800 ms and R4 takes 4,400 ms; with 3 it is 600 ms and R4 takes 4,000 ms. Parallelism without capacity just moves the wait.
Workers decide the queue
With sequential tools, raising Request workers to 4 removes the queue and R4 takes 2,750 ms, still 250 ms over. 1 worker makes R4 wait for three requests: 11,000 ms. 3 workers are no better than 2 for R4, which is still behind one request. Combine 4 workers with parallel tools: one connection gives 2,550 ms, 50 ms over; two connections give 2,200 ms and three give 2,000 ms: WITHIN OBJECTIVE.
Read waiting separately from work
In every setting the work is the same 2,750 ms of routing, model and tool time; what changes is how much of it overlaps and how long R4 waits. A trace that shows a long tool span cannot tell you whether the tool was slow or waited for a connection, unless the wait is recorded as its own span or attribute. Instrument queue time and pool acquisition time explicitly.
Reading the run and its limits
Play, Next event, Restart, Speed and Inspection time step through the queue, routing, model call, each tool and the analysis across sixty seconds; the table lists start, end and waiting for every tool. All requests take the same time and arrive in one burst, and the model call never waits; real systems add variance, so use percentiles of queue and pool wait rather than one trace.