Dependency Latency Tracing

The dashboard shows checkout p99 at 1.4 s. The SLO is 1.0 s. The on-call engineer opens a recent slow trace and sees three dependency calls: a Postgres read at 12 ms, an HTTP call to the pricing service at 83 ms, and a payment charge at 1.31 s. The metric said the system is slow. The trace said which call is slow. The fix path is now three clicks instead of three hours.

This lesson is the discipline of reading the per-dependency cost out of a single trace, the parent / child math that makes the numbers add up, and the per-dependency SLO that catches a slow downstream before the user-visible latency follows.

What it is

A trace gives you the wall-clock time of every span in the request. Grouping spans by what they call rather than by what service they belong to is the first operation. The standard OpenTelemetry semantic conventions tag every dependency span with the kind of dependency it represents and the target it represents:

• HTTP client spans carry http.request.method, url.full, http.response.status_code, and the standard server.address / server.port attributes.
• Database client spans carry db.system (postgresql, mysql, redis, mongodb, …), db.operation (SELECT, INSERT, …), db.statement, and the standard server.address.
• Messaging client spans carry messaging.system, messaging.destination.name, and the standard operation attribute.
• RPC client spans carry rpc.system (grpc, grpc-dotnet, …), rpc.service, and rpc.method.

These attributes are the pivot. The span tree gives you the shape; the attributes give you the dependency. The combination gives you the cost.

Why a sysadmin cares

Aggregate latency hides the cause. A trace that says “checkout took 1.4 s” is uninformative. A trace that says “checkout took 1.4 s, of which 1.31 s was the payment-svc call and 0.083 s was the pricing-svc call” is the basis for an action.

Three operational pains are specific to running without dependency-level visibility:

1. The dependency that no one owns. A service depends on three downstream systems. None of those systems belongs to the team. Without per-dependency latency, the team cannot tell the dependency team which of the three calls is the regression. The dependency team cannot prioritise.
2. The “fast” service with a slow call. A service’s own median latency is 30 ms. One of its dependencies p99 is 800 ms. The service is “fast” by the headline number; the user is not fast by their experience. Per-dependency latency surfaces the gap between the team’s metric and the user’s reality.
3. The cascade that one slow call triggers. A load balancer has 1000 concurrent connections; the database starts queueing; the application threads block on the database; the load balancer’s queue grows. The first symptom is the slowest dependency; the cascade is the symptom everyone else sees.

How it works

The mental model is one trace tree per request, with each leaf span labelled by the dependency it called.

Trace: 8f1d...a3c  (POST /checkout, 1.42 s)
|
+-- span api-gateway.checkout           1.42 s   (root)
      |
      +-- span checkout.cart.read        0.012 s  pg, SELECT
      +-- span checkout.pricing.lookup   0.083 s  HTTP, pricing-svc
      +-- span checkout.payment.charge   1.31 s   HTTP, payment-svc
      +-- span checkout.receipt.write    0.014 s  pg, INSERT

Reading the tree, the engineer answers “where did the time go” without arithmetic: the payment-svc call accounts for 92% of the request. Reading the attributes answers “which dependency was slow”: the http.url attribute on that span names the call target; the http.response.status_code confirms whether the call returned or timed out.

Parent / child latency math

The math is the same one a wall clock performs. A parent span’s duration is the wall-clock time from the parent’s start to the parent’s end. During that time, the parent’s children run in some order — sometimes sequentially, sometimes in parallel.

Parent.duration  >=  sum(Child.duration for sequential)
Parent.duration  >=  max(Child.duration for parallel)

For sequential children, the parent duration is at least the sum. For parallel children, the parent duration is at least the longest single child. In practice, the parent duration is the longer of the two bounds plus any non-child work the parent itself did.

The same trace tree can be summarised as a dependency-cost table:

Dependency                  Span                Duration   Share
--------------------------  ------------------  --------   -----
postgresql (checkout)       cart.read           0.012 s    0.8 %
http (pricing-svc)          pricing.lookup      0.083 s    5.8 %
http (payment-svc)          payment.charge      1.31  s   92.3 %
postgresql (checkout)       receipt.write       0.014 s    1.0 %
                            -----               -----
                            sum of children     1.42  s    100 %
                            -----               -----
parent (api-gateway)        checkout            1.42  s   ~100 %

The parent duration and the sum of child durations match because the children ran sequentially. If the children ran in parallel, the parent duration would be shorter than the sum.

Per-dependency SLO

The dependency-cost table is the data source for a per-dependency SLO. The rule is that the slowest dependency budget, plus the sequential work outside dependencies, must be less than the caller’s SLO.

checkout SLO: 1.00 s p99

   payment-svc     0.80 s  budget  (80% of the SLO)
   pricing-svc     0.10 s  budget  (10% of the SLO)
   postgresql      0.05 s  budget  ( 5% of the SLO; budget for
                                 both reads and writes combined)
   own work        0.05 s  budget  ( 5% of the SLO; exclusive
                                 time of the root span)
                --------
   sum             1.00 s

The per-dependency budget is the rule the dependency team operates against. If the payment-svc budget is 0.80 s and the service is at 1.0 s p99, the checkout service’s SLO has failed because of the payment-svc dependency, not because of anything the checkout service did.

Under the hood

How to configure it

A per-dependency metric built from spans is the durable record of dependency latency. Tempo does not produce metrics directly; the OpenTelemetry Collector emits metrics from spans through the spanmetrics connector, which derives a histogram of span duration per service.name and span name:

# /etc/alloy/config.alloy
otelcol.connector.spanmetrics "default" {
  histogram {
    explicit {
      buckets = ["2ms", "10ms", "50ms", "100ms", "250ms", "1s", "2s", "5s"]
    }
  }
  output {
    metrics = [otelcol.exporter.prometheus.mimir.input]
  }
}

otelcol.exporter.prometheus "mimir" {
  forward_to = [prometheus.remote_write.mimir.receiver]
}

prometheus.remote_write "mimir" {
  endpoint {
    url = "https://mimir.internal.example.com/api/v1/push"
  }
}

The connector emits a metric named traces_spanmetrics_latency (milliseconds) with the labels service.name, span.name, span.kind, and status_code. In Grafana, the panel formula histogram_quantile(0.99, sum by (le, span_name) (rate(traces_spanmetrics_latency_bucket\{span_name=~".+charge.+"\}[5m]))) produces the per-dependency p99.

The equivalent query in TraceQL for ad-hoc investigation is:

{ resource.service.name = "checkout" && name =~ ".+charge.+" }
  | quantile_over_time(duration, 5m)

The TraceQL aggregator is the right shape for an answer that needs the dependency named and the timestamp aligned. The metric view is the right shape for an alert.

How to validate it

Two checks confirm the dependency view is live.

# READ-ONLY: confirm the spanmetrics connector is emitting.
curl -s http://localhost:8889/metrics \
  | grep traces_spanmetrics_latency_bucket \
  | head -3

traces_spanmetrics_latency_bucket{service_name="checkout",span_name="checkout.payment.charge",le="1.0"} 4127
traces_spanmetrics_latency_bucket{service_name="checkout",span_name="checkout.payment.charge",le="2.5"} 4198
traces_spanmetrics_latency_bucket{service_name="checkout",span_name="checkout.payment.charge",le="5.0"} 4199

A counter that advances means the connector is producing data. The next check is the latency distribution by dependency:

# READ-ONLY: confirm the per-dependency p99 is in budget.
promql 'histogram_quantile(0.99,
  sum by (le, span_name) (
    rate(traces_spanmetrics_latency_bucket{service_name="checkout"}[5m])
  )
)'

{span_name="checkout.cart.read"}          0.018
{span_name="checkout.pricing.lookup"}     0.110
{span_name="checkout.payment.charge"}     1.250
{span_name="checkout.receipt.write"}      0.024

The payment-svc p99 of 1.25 s is above the 0.80 s budget. The dependency team has a target. The TraceQL trace lookup that proves the trace-level cause:

{ resource.service.name = "checkout"
  && name = "checkout.payment.charge"
  && duration > 1s }

returns the traces over the budget; the slowest one names the leaf span and the failing dependency in a single view.

How it can fail

Five failure modes specific to the dependency view.

1. The dependency whose span has no http.url or db.system attribute. Symptom: TraceQL queries that filter by db.system or http.url return empty. Cause: the instrumentation is auto-generated for the HTTP client but the application uses a non-standard HTTP wrapper that the OTel library does not instrument.
2. The dependency whose span name is the function name rather than the dependency call. Symptom: every span is named get_user_by_id or process_payment; the TraceQL filter { db.system = "postgresql" } returns nothing. Cause: a developer wrapped the database call in a custom span whose name is the function name. The semantic convention was not applied.
3. The dependency that fans out into parallel calls. A span starts ten goroutines, each of which calls the dependency. The parent span’s duration is the longest single call, not the sum. Symptom: the parent duration is fine, but the dependency-side histogram shows ten times the traffic. Cause: the parallel calls each have their own span; the parent does not reflect the fan-out cost in its own duration.
4. The dependency that times out at the SDK, not at the service. Symptom: span attributes show http.response.status_code = 200 but the duration is 5 s. Cause: the SDK recorded the response status before the timeout fired; the timeout is recorded in an event but not in the status. The on-call engineer sees a “successful” call that the user experienced as a timeout.
5. The dependency whose own service is not instrumented. Symptom: the trace shows the outbound HTTP span at 1.3 s but no child span inside the payment-svc service. Cause: the downstream service is not running the OTel SDK. The trace is a black box on the far side of the hop.

How to troubleshoot it

When a dependency is slow but the trace is unclear, the order matters.

1. Confirm the span has the dependency attribute. Without http.url or db.system, the span is an opaque call; the dependency is not named. Fix the instrumentation first; do not chase latency on a span that does not say what it is.
2. Check the attribute set on the slowest child. TraceQL {} | select(name, http.url, http.status_code, duration) on a recent slow trace names the dependency and confirms the response. A span with no http.status_code and a long duration is a timeout, not a slow response.
3. Walk the parent chain. A span that appears at the same level as a fast span is one of several siblings; a span whose parent is the root is the single dependency that blocked the request. The chain tells you whether the slowness is one of many or the only thing in the way.
4. Compare against the dependency-side metric. The trace shows this request was slow on payment-svc. The metric up{job="payment-svc"} or payment_request_duration_seconds shows whether the dependency was slow across the population. A trace-only slow call is a per-request problem; a metric-and-trace slow call is a service-wide problem.
5. Check the SDK retry settings. A slow call that succeeded on the second attempt shows two sibling spans with one error status. The dependency metric counts the successful retry as a normal request; the trace shows both.

Security implications

Per-dependency traces expose call targets. A trace with http.url = "https://payment-svc.internal:443/v1/charge" is useful for latency; it is also a map of the internal network. Three rules:

• Use DNS names, not IPs, in server.address. The semantic convention supports both; the DNS name is the stable identifier, the IP is the dynamic one.
• Redact query strings in http.url and db.statement before export. A URL with ?email=user@example.com is a leak; the OTel HTTP instrumentation supports an attribute hook for exactly this redaction.
• Treat the dependency list as semi-sensitive. An attacker who knows the dependencies knows the failure modes. The trace backend’s read ACL should match the data classification of the most-sensitive downstream call.

Performance implications

The per-dependency metric from the spanmetrics connector costs roughly the same as the spans themselves. The connector is a stream processor in the collector: it consumes the same spans, derives a histogram, and exports the histogram as a metric. The cost scales with the number of distinct service.name × span.name pairs and the number of histogram buckets.

• Bucket choice dominates cost. Eight buckets per histogram is the right starting point; thirty buckets triples the cardinality for marginal quantile precision.
• The connector does not store the underlying spans. It forwards them downstream and the metric export is in addition. The storage cost is separate.

Production guidance

• Set the per-dependency budget and publish it. The dependency team needs a number. The number is the dependency’s share of the caller’s SLO. Without the number, the dependency has no investment in latency reduction that improves a specific caller.
• Alert on the slowest dependency, not the caller. The caller alert fires when the SLO fails. The dependency alert fires when the dependency’s own latency exceeds its share. The dependency alert pages the dependency team, not the caller team. The caller alert is the last to fire.
• Standardise span names with the OTel semantic conventions. A non-standard span name is invisible to every team’s query except the team’s that wrote it. The standard names are stable across versions.
• Sample at the head, not the tail. Sampling at the collector means every application pays the SDK cost to emit every span. Head-based sampling inside the SDK reduces the SDK cost as well as the backend cost.

Verification

You should now be able to answer:

• What two OTel attributes name the dependency called by an HTTP client span, and what two name the dependency called by a database client span?
• Why is a parent span’s duration sometimes longer and sometimes shorter than the sum of its children’s durations?
• How does the per-dependency budget relate to the caller’s SLO?
• What TraceQL aggregator returns the per-span p99 over a time window?
• What is the first attribute to inspect when a slow span has no obvious cause?

Quiz