open-telemetry / open-telemetry/opentelemetry-php

[opentelemetry-php-contrib] Symfony: a throwing kernel.view listener splits one request into two traces and loses http.route

Open
#2,020 1 comment 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
PHP
Stars
912
Forks
232
Avg merge
7d 16h
Merged PRs (30d)
4

Description

Package

open-telemetry/opentelemetry-auto-symfony 1.4.0 (latest release)

Environment
  • Symfony 5.4.45, PHP 8.2, php-fpm
  • open-telemetry/sdk 1.15.0, open-telemetry/api 1.10.0, ext-opentelemetry
  • Exporter: OTLP http/protobuf → Grafana Alloy → Tempo
What happens

When a request fails with a 500 raised from a kernel.view listener, one HTTP request is
exported as two error spans in two different traces, and neither is complete:

span kind name http.route http.response.status_code events
A SERVER DELETE absent absent exception
B INTERNAL DELETE api_customer_records_delete_item present 500 none

The two spans carry different trace_ids.

Counts match failures 1:1 — over 24h on two clusters: 2 failing requests produced 2 A-spans
and 2 B-spans; 1 failing request produced 1 and 1. Successful requests are unaffected: a
single SERVER span, correctly named {method} {route}.

Why it matters
  • Span-derived RED metrics (traces_spanmetrics_calls_total) bucket every 5xx under the
    bare HTTP method, so server errors cannot be attributed to an endpoint.
  • The span holding the exception is not the span holding the status code, and they are not
    in the same trace, so no single trace shows a complete picture of the failure.
Where it appears to come from

In SymfonyInstrumentation::register() a scope is attached in the handle pre hook for
every request type, but detached in only two places:

  • handle post — returns early without detaching when $exception === null
    (the normal path, including a request that produced a 500 response);
  • terminate post — pops exactly one scope, and that is where http.route and the
    status code are stamped.

When the error is rendered through a sub-request, a second scope is attached and the stack
ends up unbalanced, so terminate appears to stamp the route and status onto the
sub-request span rather than the main SERVER span.

Caveat

The table above is measured; the explanation is inferred from reading
SymfonyInstrumentation.php — I have not stepped through the hook ordering to confirm it.
Happy to put together a minimal reproducer if that would help.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start in SymfonyInstrumentation.php, especially SymfonyInstrumentation::register() and the handle and terminate pre/post hooks. Trace the scope stack through a throwing kernel.view listener and sub-request to confirm the inferred hook ordering. Done means one request produces one complete SERVER span with the route, status code, and exception in the same trace.

Written by the indexing model from the issue text.

Assessment

Tech stack
php, symfony
Domain
observability
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Quiet
Clarity
Mostly clear
Newbie friendliness
52/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.