Add debug scope to warn on incorrect scope usage (#823)

* Add debug scope to warn on incorrect scope usage

* Enable assertions in unit tests

.github/workflows/php.yml

@@ -63,7 +63,7 @@ jobs:
       run: vendor/bin/phpstan analyse --error-format=github
 
     - name: Run PHPUnit (unit tests)
-      run: vendor/bin/phpunit --coverage-text --coverage-clover=coverage.clover --testsuite unit
+      run: php -dzend.assertions=1 vendor/bin/phpunit --coverage-text --coverage-clover=coverage.clover --testsuite unit
 
     - name: Run PHPUnit (integration tests)
       run: vendor/bin/phpunit --testsuite integration

src/Context/Context.php

@@ -4,6 +4,8 @@
 
 namespace OpenTelemetry\Context;
 
+use function assert;
+
 /**
  * @see https://github.com/open-telemetry/opentelemetry-specification/blob/v1.6.1/specification/context/context.md#overview
  */
@@ -92,7 +94,11 @@ public function withContextValue(ImplicitContextKeyedInterface $value): self
      */
     public function activate(): ScopeInterface
     {
-        return self::storage()->attach($this);
+        $scope = self::storage()->attach($this);
+        /** @psalm-suppress RedundantCondition */
+        assert((bool) $scope = new DebugScope($scope));
+
+        return $scope;
     }
 
     /**

src/Context/DebugScope.php

@@ -0,0 +1,94 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\Context;
+
+use function basename;
+use function count;
+use function debug_backtrace;
+use const DEBUG_BACKTRACE_IGNORE_ARGS;
+use function sprintf;
+use function trigger_error;
+
+/**
+ * @internal
+ */
+final class DebugScope implements ScopeInterface
+{
+    private const DEBUG_TRACE_CREATE = '__debug_trace_create';
+    private const DEBUG_TRACE_DETACH = '__debug_trace_detach';
+
+    private ContextStorageScopeInterface $scope;
+
+    public function __construct(ContextStorageScopeInterface $node)
+    {
+        $this->scope = $node;
+        $this->scope[self::DEBUG_TRACE_CREATE] = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
+    }
+
+    public function detach(): int
+    {
+        $this->scope[self::DEBUG_TRACE_DETACH] ??= debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
+
+        $flags = $this->scope->detach();
+
+        if (($flags & ScopeInterface::DETACHED) !== 0) {
+            trigger_error(sprintf(
+                'Scope: unexpected call to Scope::detach() for scope #%d, scope was already detached %s',
+                spl_object_id($this),
+                self::formatBacktrace($this->scope[self::DEBUG_TRACE_DETACH]),
+            ));
+        } elseif (($flags & ScopeInterface::MISMATCH) !== 0) {
+            trigger_error(sprintf(
+                'Scope: unexpected call to Scope::detach() for scope #%d, scope successfully detached but another scope should have been detached first',
+                spl_object_id($this),
+            ));
+        } elseif (($flags & ScopeInterface::INACTIVE) !== 0) {
+            trigger_error(sprintf(
+                'Scope: unexpected call to Scope::detach() for scope #%d, scope successfully detached from different execution context',
+                spl_object_id($this),
+            ));
+        }
+
+        return $flags;
+    }
+
+    public function __destruct()
+    {
+        if (!isset($this->scope[self::DEBUG_TRACE_DETACH])) {
+            trigger_error(sprintf(
+                'Scope: missing call to Scope::detach() for scope #%d, created %s',
+                spl_object_id($this->scope),
+                self::formatBacktrace($this->scope[self::DEBUG_TRACE_CREATE]),
+            ));
+        }
+    }
+
+    private static function formatBacktrace(array $trace): string
+    {
+        $s = '';
+        for ($i = 0, $n = count($trace) + 1; ++$i < $n;) {
+            $s .= "\n\t";
+            $s .= 'at ';
+            if (isset($trace[$i]['class'])) {
+                $s .= strtr($trace[$i]['class'], ['\\' => '.']);
+                $s .= '.';
+            }
+            $s .= strtr($trace[$i]['function'] ?? '{main}', ['\\' => '.']);
+            $s .= '(';
+            if (isset($trace[$i - 1]['file'])) {
+                $s .= basename($trace[$i - 1]['file']);
+                if (isset($trace[$i - 1]['line'])) {
+                    $s .= ':';
+                    $s .= $trace[$i - 1]['line'];
+                }
+            } else {
+                $s .= 'Unknown Source';
+            }
+            $s .= ')';
+        }
+
+        return $s . "\n";
+    }
+}

tests/Unit/Context/ContextTest.php

@@ -17,8 +17,13 @@ public function test_activate(): void
     {
         $context = Context::getRoot();
 
-        $context->activate();
-        $this->assertSame($context, Context::getCurrent());
+        $scope = $context->activate();
+
+        try {
+            $this->assertSame($context, Context::getCurrent());
+        } finally {
+            $scope->detach();
+        }
     }
 
     public function test_ctx_can_store_values_by_key(): void
@@ -132,13 +137,17 @@ public function test_ctx_value_not_found_returns_null(): void
     public function test_attach_and_detach_set_current_ctx(): void
     {
         $key = new ContextKey();
-        Context::getRoot()->with($key, '111')->activate();
+        $scope = Context::getRoot()->with($key, '111')->activate();
 
-        $token = Context::getRoot()->with($key, '222')->activate();
-        $this->assertSame(Context::getValue($key), '222');
+        try {
+            $token = Context::getRoot()->with($key, '222')->activate();
+            $this->assertSame(Context::getValue($key), '222');
 
-        $token->detach();
-        $this->assertSame(Context::getValue($key), '111');
+            $token->detach();
+            $this->assertSame(Context::getValue($key), '111');
+        } finally {
+            $scope->detach();
+        }
     }
 
     public function test_instance_set_and_static_get_use_same_ctx(): void
@@ -147,9 +156,13 @@ public function test_instance_set_and_static_get_use_same_ctx(): void
         $val = 'foobar';
 
         $ctx = Context::getRoot()->with($key, $val);
-        $ctx->activate();
+        $scope = $ctx->activate();
 
-        $this->assertSame(Context::getValue($key, $ctx), $val);
-        $this->assertSame(Context::getValue($key, null), $val);
+        try {
+            $this->assertSame(Context::getValue($key, $ctx), $val);
+            $this->assertSame(Context::getValue($key, null), $val);
+        } finally {
+            $scope->detach();
+        }
     }
 }

tests/Unit/Context/DebugScopeTest.php

@@ -0,0 +1,68 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\Tests\Unit\Context;
+
+use OpenTelemetry\Context\Context;
+use PHPUnit\Framework\TestCase;
+
+/**
+ * @covers \OpenTelemetry\Context\DebugScope
+ */
+final class DebugScopeTest extends TestCase
+{
+    public function test_detached_scope_detach(): void
+    {
+        $scope1 = Context::getCurrent()->activate();
+
+        $scope1->detach();
+
+        $this->expectNotice();
+        $this->expectNoticeMessage('already detached');
+        $scope1->detach();
+    }
+
+    public function test_order_mismatch_scope_detach(): void
+    {
+        $scope1 = Context::getCurrent()->activate();
+        $scope2 = Context::getCurrent()->activate();
+
+        try {
+            $this->expectNotice();
+            $this->expectNoticeMessage('another scope');
+            $scope1->detach();
+        } finally {
+            $scope2->detach();
+        }
+    }
+
+    public function test_inactive_scope_detach(): void
+    {
+        $scope1 = Context::getCurrent()->activate();
+
+        Context::storage()->fork(1);
+        Context::storage()->switch(1);
+
+        try {
+            $this->expectNotice();
+            $this->expectNoticeMessage('different execution context');
+            $scope1->detach();
+        } finally {
+            Context::storage()->switch(0);
+            Context::storage()->destroy(1);
+        }
+    }
+
+    public function test_missing_scope_detach(): void
+    {
+        try {
+            $this->expectNotice();
+            $this->expectNoticeMessage('missing call');
+            Context::getCurrent()->activate();
+        } finally {
+            /** @psalm-suppress PossiblyNullReference */
+            Context::storage()->scope()->detach();
+        }
+    }
+}

tests/Unit/Context/ScopeTest.php

@@ -51,15 +51,16 @@ public function test_detached_scope_detach(): void
         $scope1 = Context::getCurrent()->activate();
 
         $this->assertSame(0, $scope1->detach());
-        $this->assertSame(ScopeInterface::DETACHED, $scope1->detach() & ScopeInterface::DETACHED);
+        /** @phpstan-ignore-next-line */
+        $this->assertSame(ScopeInterface::DETACHED, @$scope1->detach() & ScopeInterface::DETACHED);
     }
 
     public function test_order_mismatch_scope_detach(): void
     {
         $scope1 = Context::getCurrent()->activate();
         $scope2 = Context::getCurrent()->activate();
 
-        $this->assertSame(ScopeInterface::MISMATCH, $scope1->detach() & ScopeInterface::MISMATCH);
+        $this->assertSame(ScopeInterface::MISMATCH, @$scope1->detach() & ScopeInterface::MISMATCH);
         $this->assertSame(0, $scope2->detach());
     }
 
@@ -78,13 +79,14 @@ public function test_order_mismatch_scope_detach_depth(): void
         $this->assertSame(0, $scope4->detach());
         $this->assertSame(0, $scope1->detach());
     }
+
     public function test_inactive_scope_detach(): void
     {
         $scope1 = Context::getCurrent()->activate();
 
         Context::storage()->fork(1);
         Context::storage()->switch(1);
-        $this->assertSame(ScopeInterface::INACTIVE, $scope1->detach() & ScopeInterface::INACTIVE);
+        $this->assertSame(ScopeInterface::INACTIVE, @$scope1->detach() & ScopeInterface::INACTIVE);
 
         Context::storage()->switch(0);
         Context::storage()->destroy(1);