Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions src/Instrumentation/Symfony/composer.json
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
"phpstan/phpstan": "^1.1",
"phpstan/phpstan-phpunit": "^1.0",
"psalm/plugin-phpunit": "^0.19.2",
"open-telemetry/opentelemetry-propagation-traceresponse": "^0.3",
"open-telemetry/sdk": "^1.8",
"phpunit/phpunit": "^9.5",
"vimeo/psalm": "6.4.0",
Expand Down
29 changes: 26 additions & 3 deletions src/Instrumentation/Symfony/src/SymfonyInstrumentation.php
Original file line number Diff line number Diff line change
Expand Up @@ -94,18 +94,41 @@ public static function register(): void
?\Throwable $exception
): void {
$scope = Context::storage()->scope();
if (null === $scope || null === $exception) {
if (null === $scope) {
return;
}

$type = $params[1] ?? HttpKernelInterface::MAIN_REQUEST;
$isSubRequest = ($type === HttpKernelInterface::SUB_REQUEST);

// A MAIN_REQUEST that didn't throw is ended by the `terminate` hook.
if (!$isSubRequest && null === $exception) {
return;
}

$span = Span::fromContext($scope->context());
$scope->detach();
$span->recordException($exception);
$span->setStatus(StatusCode::STATUS_ERROR, $exception->getMessage());

if (null !== $exception) {
$span->recordException($exception);
$span->setStatus(StatusCode::STATUS_ERROR, $exception->getMessage());
}

if ($isSubRequest && null !== $response) {
$span->setAttribute(TraceAttributes::HTTP_RESPONSE_STATUS_CODE, $response->getStatusCode());
Comment on lines +117 to +118

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 Badge Mark 5xx sub-request spans as errors

When a Symfony error-controller sub-request returns a 500 response without throwing, this new post-hook path is now the only place that completes that sub-request span, but it only records http.response.status_code before ending it. The terminate() path still marks 5xx responses with STATUS_ERROR, so moving sub-request completion here causes exported 500 error-controller spans to have an unset status and lose the error signal.

Useful? React with 👍 / 👎.

}

// We only reach this point for sub-requests or when an exception propagated
// out of handle(); neither is ever passed to `terminate()`, so the span must
// be ended here. Leaving a sub-request span open leaks its scope onto the
// context stack and prevents the main-request root span from being ended and
// exported (#1905). Only a MAIN_REQUEST that returned normally is left for
// `terminate()`, and that path already returned above.
$span->end();
}
);

/** @psalm-suppress UnusedFunctionCall */
hook(
HttpKernel::class,
'terminate',
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@

use OpenTelemetry\API\Trace\SpanKind;
use OpenTelemetry\API\Trace\StatusCode;
use OpenTelemetry\Contrib\Propagation\TraceResponse\TraceResponsePropagator;
use OpenTelemetry\SemConv\TraceAttributes;
use Symfony\Component\EventDispatcher\EventDispatcher;
use Symfony\Component\EventDispatcher\EventDispatcherInterface;
Expand Down Expand Up @@ -143,8 +144,9 @@ public function test_http_kernel_handle_subrequest(): void
$request = new Request();
$request->attributes->set('_controller', 'ErrorController');

$response = $kernel->handle($request, HttpKernelInterface::SUB_REQUEST);
$kernel->terminate($request, $response);
// Sub-requests are never passed to terminate() by Symfony; their span is ended
// by the handle post-hook, so it is exported as soon as handle() returns.
$kernel->handle($request, HttpKernelInterface::SUB_REQUEST);

$this->assertCount(1, $this->storage);

Expand All @@ -160,25 +162,22 @@ public function test_http_kernel_handle_subrequest_with_various_controller_types
// String controller
$request = new Request();
$request->attributes->set('_controller', 'SomeController::index');
$response = $kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$kernel->terminate($request, $response);
$kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$this->assertSame('GET SomeController::index', $this->storage[0]->getName());
$this->storage->exchangeArray([]);

// Array: [object, method]
$controllerObj = new class() {};
$request = new Request();
$request->attributes->set('_controller', [$controllerObj, 'fooAction']);
$response = $kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$kernel->terminate($request, $response);
$kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$this->assertSame('GET ' . get_class($controllerObj) . '::fooAction', $this->storage[0]->getName());
$this->storage->exchangeArray([]);

// Array: [class, method]
$request = new Request();
$request->attributes->set('_controller', ['SomeClass', 'barAction']);
$response = $kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$kernel->terminate($request, $response);
$kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$this->assertSame('GET SomeClass::barAction', $this->storage[0]->getName());
$this->storage->exchangeArray([]);
}
Expand All @@ -194,15 +193,14 @@ public function test_http_kernel_handle_subrequest_with_null_and_object_controll
$controllerObj2 = new class() {};
$request = new Request();
$request->attributes->set('_controller', $controllerObj2);
$response = $kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$kernel->terminate($request, $response);
$kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$this->assertSame('GET sub-request', $this->storage[0]->getName());
$this->storage->exchangeArray([]);

// Null/other controller (should fallback to 'sub-request')
$request = new Request();
$request->attributes->set('_controller', null);
$response = $kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$kernel->terminate($request, $response);
$kernel->handle($request, \Symfony\Component\HttpKernel\HttpKernelInterface::SUB_REQUEST);
$this->assertSame('GET sub-request', $this->storage[0]->getName());
}

Expand Down Expand Up @@ -237,6 +235,64 @@ public function test_http_kernel_handle_5xx_response_is_error(): void
$this->assertSame(500, $span->getAttributes()->get(TraceAttributes::HTTP_RESPONSE_STATUS_CODE));
}

public function test_http_kernel_sub_request_scope_does_not_leak_main_span(): void
{
// Simulates Symfony's internal error-controller dispatch: a MAIN_REQUEST handle()
// call whose exception is caught internally, followed by a nested SUB_REQUEST
// handle() call that renders the error response successfully (no exception).
$kernel = $this->getHttpKernel(new EventDispatcher(), fn () => new Response('error page'));
$this->assertCount(0, $this->storage);

$mainRequest = new Request();
$mainRequest->attributes->set('_route', 'main_route');
$kernel->handle($mainRequest, HttpKernelInterface::MAIN_REQUEST, false);

// The sub-request is dispatched while the main request span's scope is still on
// the context storage stack, exactly as Symfony's ErrorListener does it.
$subRequest = new Request();
$subRequest->attributes->set('_controller', 'ErrorController');
$subResponse = $kernel->handle($subRequest, HttpKernelInterface::SUB_REQUEST);

// The sub-request span must be ended and exported immediately: it never reaches
// `terminate()`, so leaving its scope attached would leak it and block the main
// request span from ever being reached again.
$this->assertCount(1, $this->storage);
$this->assertSame('GET ErrorController', $this->storage[0]->getName());
$this->assertSame(SpanKind::KIND_INTERNAL, $this->storage[0]->getKind());

// `terminate()` must now see the main request's scope, not a leaked sub-request one.
$kernel->terminate($mainRequest, $subResponse);

$this->assertCount(2, $this->storage);
$mainSpan = $this->storage[1];
$this->assertSame('GET main_route', $mainSpan->getName());
$this->assertSame(SpanKind::KIND_SERVER, $mainSpan->getKind());
}

public function test_http_kernel_records_exception_on_main_span_during_sub_request_error_handling(): void
{
$kernel = $this->getHttpKernel(new EventDispatcher(), fn () => new Response('error page'));

$mainRequest = new Request();
$kernel->handle($mainRequest, HttpKernelInterface::MAIN_REQUEST, false);

// Symfony's HttpKernel::handleThrowable() records the exception on whatever span
// is currently active before it dispatches the internal error sub-request; at
// that point the only span on the stack is the main request's.
\OpenTelemetry\API\Trace\Span::getCurrent()->recordException(new \RuntimeException('boom'));

$subRequest = new Request();
$subRequest->attributes->set('_controller', 'ErrorController');
$subResponse = $kernel->handle($subRequest, HttpKernelInterface::SUB_REQUEST);
$kernel->terminate($mainRequest, $subResponse);

$this->assertCount(2, $this->storage);
$mainSpan = $this->storage[1];
$this->assertSame(SpanKind::KIND_SERVER, $mainSpan->getKind());
$this->assertCount(1, $mainSpan->getEvents());
$this->assertSame('exception', $mainSpan->getEvents()[0]->getName());
}

private function getHttpKernel(EventDispatcherInterface $eventDispatcher, $controller = null, ?RequestStack $requestStack = null, array $arguments = []): HttpKernel
{
$controller ??= fn () => new Response('Hello');
Expand Down
Loading