Instrumenting Laravel artisan commands with OpenTelemetry

Question

I'm using OpenTelemetry to instrument a Laravel application, and struggling with how to create root spans for console commands (though Laravel artisan). I have noticed that the framework dispatches CommandStarting and CommandFinished events when it's starting and finishing a command, which I'm attempting to listen for to construct my root span:

<?php

namespace App\OpenTelemetry\Instrumentation;

use Illuminate\Console\Events\CommandFinished;
use Illuminate\Console\Events\CommandStarting;
use OpenTelemetry\API\Trace\Span;
use OpenTelemetry\API\Trace\SpanKind;
use OpenTelemetry\API\Trace\TracerInterface;
use OpenTelemetry\Context\Context;

class ArtisanInstrumentation implements Instrumentation
{
    public function register(): void
    {
        app('events')->listen(CommandStarting::class, [$this, 'recordStartOfCommand']);
        app('events')->listen(CommandFinished::class, [$this, 'recordEndOfCommand']);
    }

    public function recordStartOfCommand(CommandStarting $event): void
    {
        /** @var TracerInterface $tracer */
        $tracer = app(TracerInterface::class);

        $span = $tracer
            ->spanBuilder($event->command)
            ->setSpanKind(SpanKind::KIND_SERVER)
            ->startSpan();
        $span->activate();
    }

    public function recordEndOfCommand(CommandFinished $event): void
    {
        $scope = Context::storage()->scope();
        $span = Span::fromContext($scope->context());
        $scope->detach();
        $span->end();
    }
}

As you can see I'm attempting to start a span when the command starts running, and end it later when the command finishes. From the above code though I get the following error about a missing call to detach a scope:

  Scope: missing call to Scope::detach() for scope #3776, created 
        at OpenTelemetry.Context.Context.activate(Context.php:87)
        at OpenTelemetry.API.Trace.Span.activate(Span.php:51)
        at App.OpenTelemetry.Instrumentation.ArtisanInstrumentation.recordStartOfCommand(ArtisanInstrumentation.php:32)

The span that I'm retrieving with Span::fromContext($scope->context()) is the correct span, which I have confirmed by dumping it out and inspecting its name. But calling detach() on the scope is obviously not detaching it properly.

I think I'm just a bit lost in generate as to how to scopes work in general and how to retrieve a span's scope somewhere else in the codebase. All of the examples in OpenTelemetry's documentation show using a scope in the context that you created it in, not dynamically retrieving it from unrelated code.

Through trial-and-error I have made it work by storing the result of $span->activate() in a property on the class, and then deactivating it in the recordEndOfCommand method like so:

$scope = Context::storage()->scope();
$span = Span::fromContext($scope->context());
$this->scope->detach();
$span->end();

but I'm not sure if this is preferred over retrieving the scope from context?

Answer 1

You're encountering a warning from DebugScope, which is an OpenTelemetry feature that's active in assertion-enabled PHP, which exists to help you identify when a Scope is not properly detached (which the one in recordStartOfCommand is not - it immediately goes out of scope when that function ends, gets GC'd, and triggers the error you see). You can disable this feature with the environment variable OTEL_PHP_DEBUG_SCOPES_DISABLED=true, or by turning off PHP assertions.

If you don't want to keep track of the scope between the pre and post function, you can instead manage it this way:

public function recordStartOfCommand(CommandStarting $event): void
{
    $tracer = app(TracerInterface::class);
    $span = $tracer
        ->spanBuilder($event->command)
        ->setSpanKind(SpanKind::KIND_SERVER)
        ->startSpan();
    // do not `activate()` the span, but instead:
    Context::storage()->attach($span->storeInContext(Context::getCurrent()));
}

public function recordEndOfCommand(CommandFinished $event): void
{
    $scope = Context::storage()->scope();
    $scope->detach();
    Span::fromContext($scope->context())->end();
}