The longest span is not the culprit

In one line

Fixing the longest span in a trace is usually wasted effort. The only spans that reduce response time are those that have a large self time and are on the critical path.

Why this matters

The p50 of the order API was 290 milliseconds. When they opened a trace, a 158-millisecond bar was right at the top of the screen — the inventory lookup. Two people spent three days adding a cache to that lookup, and when they looked at the dashboard the day after deploying, p50 was 289 milliseconds. One millisecond.

The cause was simple. The inventory lookup starts at the same time as the price calculation. By the time the inventory lookup finished at 158 milliseconds, the price calculation was still running, and the gateway waits for both to finish. Whichever finishes later decides the response time. Even if you make the inventory lookup 0, the gateway still waits for the price calculation.

The screen is largely to blame for this illusion. A waterfall view shows spans ordered by length, and the human eye goes first to the longest bar. But the length of a bar answers 'how long did this section take', not 'if I shorten this section, does the total shrink'. The two questions are different, and answering the second requires a calculation.

How it works

Two calculations give the answer.

Self time is the time that span spent directly, without handing it to its children. You subtract from the total time the time taken by the children. There is one slip here: you must not simply add up the children's time and subtract it. If there are children running in parallel, the sum exceeds the parent's total time and the self time becomes negative. You must subtract the length of the union of the child intervals.

The critical path is built by sweeping backward from the end of the root. You skip children that end later than the time you are currently looking at, and descend into the child that ends latest. After climbing up to the time that child started, you move on to the sibling that ended before it. This way the root is covered from start to end with no gaps, and each piece has an owner. The sum of the pieces is exactly equal to the root's duration — this equality is the check that tells you the calculation was right.

Combine the two calculations and the ranking flips. In the incident above, the inventory lookup was first in total time and first in self time, but its critical path contribution was 0. Conversely, the pricing rules evaluation was third in total time but had an overwhelming critical path contribution of 142 milliseconds. What needed fixing was the one in third place.

One more thing comes with this: N+1. If dozens of sibling spans with the same name line up in a row, each one is 3 milliseconds and does not make the ranking. But add up sixteen and it is 45 milliseconds, and if you batch them into one query, 42 milliseconds of that disappears. You only see it by looking at the group, not at individual spans.

The traces documentation of OpenTelemetry defines a span as a unit of work and a trace as the path a request took. A span contains a start time, a duration, and the identifier of its parent span, and those three are all you need for the critical path calculation. That means you can compute it with the standard library even without any tool.

What it looks like in the field

Four things repeat.

First, the critical paths of p50 and p99 are different. Normally the price calculation finishes last, but the moment the inventory database stalls, the inventory lookup becomes the last. If you fix things by looking only at p50, p99 stays the same. So you need the habit of pulling out two traces and comparing their critical paths.

Second, the data is messy. If the collector loses pieces, orphan spans whose parent is not in the file remain, and traces whose root is missing entirely appear. If you mix such traces into the calculation as they are, the totals quietly go wrong. Before calculating, a step that selects only 'traces with a single root and no orphans' is absolutely necessary.

Third, how many traces you choose to compute on changes the conclusion. Latency is one of the four golden signals, and to improve that metric you first have to decide which trace to take as representative. If you decide the critical path from just one trace, you easily mistake that one trace's coincidence for a bottleneck. Conversely, if you average thousands, the parallel structures cancel each other out and nothing stands out anywhere. The realistic compromise is to group traces with the same entry point (the same root span name), pick a few representative points of the duration distribution and compute each, and then see whether the span names on the paths overlap. If the names overlap, it is a structural bottleneck, and if they diverge, it is a bottleneck that varies with conditions, so the way to fix it differs too.

Fourth, an improvement without a recorded expected saving is not verified. "I think this will get faster if I fix it" has no way of being checked after deployment. If you write down "the root drops by 142 milliseconds" as a number before fixing, it remains whether you were right or wrong after deployment. If you were wrong, the model was wrong, and that corrects your next judgment.

What you will do in the next lab

You analyze the 3,454 spans (150 traces) in the Pod with the standard library only. You reconnect parents and children and attach depth, compute self time by handling overlapping children as a union, and compute the critical path and check that the sum of the pieces equals the root duration. Then you confirm in a table that the 'longest spans' list, the 'top self time' list, and the 'top critical path contribution' list are different from each other, and compute the saving when you find and batch an N+1. Finally, you compare the critical paths of the p50 and p99 traces and submit, as a file, what you will fix together with the expected saving in time.