diff --git a/UPGRADING.md b/UPGRADING.md index 334209e..53c4e5c 100644 --- a/UPGRADING.md +++ b/UPGRADING.md @@ -2,6 +2,18 @@ There are some breaking changes you should be aware of. We've categorized them so you can prioritize. This guide covers the most common cases. Edge cases may not be covered, and PRs to improve it are welcome. +## From v3.0 to v3.1 + +`Tracer::currentTraceId()`, `currentSpanId()`, and `traceParent()` now return `?string`, with `null` when no trace is active. Recorders skip silently without an active trace instead of recording orphan spans. + +If you use `spatie/laravel-flare` no changes are needed. For framework agnostic apps, replace `registerFlareHandlers()` with `$flare->start()`, which also opens the lifecycle: + +```php +$flare = Flare::make($config)->start(); +``` + +For subtask mode (queue workers, long-running processes), keep using `$flare->lifecycle->startSubtask()` per work unit. + ## From v2 to v3 The new version of the package adds better support for logging and tracing lifetimes. We don't expect upgrading to require a lot of code changes for typical applications. diff --git a/src/Flare.php b/src/Flare.php index 1a2fed0..d5775f1 100755 --- a/src/Flare.php +++ b/src/Flare.php @@ -64,6 +64,41 @@ public static function make( return $container->get(Flare::class); } + public function start( + ?int $timeUnixNano = null, + array $attributes = [], + ?string $traceparent = null, + ): self { + if ($this->lifecycle->usesSubtasks) { + throw new Exception( + 'Flare::start() is for the main lifecycle. In subtask mode, use $flare->lifecycle->startSubtask() per work unit.' + ); + } + + $this->reporter->registerFlareHandlers(); + $this->lifecycle->start($timeUnixNano, $attributes, $traceparent); + + return $this; + } + + public function end( + ?int $timeUnixNano = null, + array $additionalTerminationAttributes = [], + array $additionalApplicationAttributes = [], + ): void { + if ($this->lifecycle->usesSubtasks) { + throw new Exception( + 'Flare::end() is for the main lifecycle. In subtask mode, use $flare->lifecycle->endSubtask() per work unit.' + ); + } + + $this->lifecycle->terminated( + $timeUnixNano, + $additionalTerminationAttributes, + $additionalApplicationAttributes, + ); + } + public function registerFlareHandlers(): self { $this->reporter->registerFlareHandlers(); diff --git a/src/Recorders/SpansRecorder.php b/src/Recorders/SpansRecorder.php index d35157a..76952c3 100644 --- a/src/Recorders/SpansRecorder.php +++ b/src/Recorders/SpansRecorder.php @@ -86,6 +86,12 @@ final protected function startSpan( return null; } + $currentTraceId = $this->tracer->currentTraceId(); + + if ($currentTraceId === null) { + return null; + } + if ($nameAndAttributes !== null) { ['name' => $name, 'attributes' => $attributes] = $nameAndAttributes(); } else { @@ -98,7 +104,7 @@ final protected function startSpan( $spanId = $this->tracer->nextSpanId(); $span = new Span( - traceId: $this->tracer->currentTraceId(), + traceId: $currentTraceId, spanId: $spanId, parentSpanId: $parentSpanId, name: $name, diff --git a/src/Support/Lifecycle.php b/src/Support/Lifecycle.php index be69983..8724342 100644 --- a/src/Support/Lifecycle.php +++ b/src/Support/Lifecycle.php @@ -324,6 +324,8 @@ public function terminated( $this->stage = LifecycleStage::Terminated; if ($this->tracer->sampling === false) { + $this->tracer->endTrace(); + return; } diff --git a/src/Tracer.php b/src/Tracer.php index 8e5227b..c014dd0 100644 --- a/src/Tracer.php +++ b/src/Tracer.php @@ -36,11 +36,11 @@ class Tracer /** @var array @param array{max_spans: int, max_attributes_per_span: int, max_span_events_per_span: int, max_attributes_per_span_event: int}|null */ public readonly array $limits; - protected string $currentTraceId; + protected ?string $currentTraceId = null; - protected string $currentSpanId; + protected ?string $currentSpanId = null; - protected bool $currentSpanIdAvailable; + protected bool $currentSpanIdAvailable = true; /** * @param array{max_spans: int, max_attributes_per_span: int, max_span_events_per_span: int, max_attributes_per_span_event: int}|null $limits @@ -64,10 +64,6 @@ public function __construct( public readonly bool $disabled = false, protected Closure|null $gracefulSpanEnderClosure = null, ) { - $this->currentTraceId = $this->ids->trace(); - $this->currentSpanId = $this->ids->span(); - $this->currentSpanIdAvailable = true; - $this->limits = [ 'max_spans' => $limits['max_spans'] ?? self::DEFAULT_MAX_SPANS_LIMIT, 'max_attributes_per_span' => $limits['max_attributes_per_span'] ?? self::DEFAULT_MAX_ATTRIBUTES_PER_SPAN_LIMIT, @@ -81,35 +77,38 @@ public function startTrace( ?string $spanId = null, ?string $traceParent = null, ): bool { - if ($this->disabled === true) { - return false; + if ($this->currentTraceId !== null) { + return $this->sampling; } - if ($this->sampling) { - return $this->sampling; + if (($traceId === null) !== ($spanId === null)) { + throw new Exception('If one of traceId or spanId is provided, both must be provided.'); } $parentSampled = null; + $currentSpanAvailable = true; - if ($traceParent !== null) { - $parsed = $this->ids->parseTraceparent($traceParent); + $parsedTraceParent = $traceParent !== null + ? $this->ids->parseTraceparent($traceParent) + : null; - if ($parsed !== null) { - $traceId = $parsed['traceId']; - $spanId = $parsed['parentSpanId']; - $parentSampled = $parsed['sampling']; - } + if ($traceId !== null && $spanId !== null) { + $currentSpanAvailable = false; } - if (($traceId === null) !== ($spanId === null)) { - throw new Exception('If one of traceId or spanId is provided, both must be provided.'); + if ($parsedTraceParent) { + $traceId = $parsedTraceParent['traceId']; + $spanId = $parsedTraceParent['parentSpanId']; + $parentSampled = $parsedTraceParent['sampling']; + $currentSpanAvailable = false; } - if ($traceId !== null && $spanId !== null) { - $this->currentTraceId = $traceId; - $this->currentSpanId = $spanId; - $this->currentSpanIdAvailable = false; - $this->spans = []; + $this->currentTraceId = $traceId ?? $this->ids->trace(); + $this->currentSpanId = $spanId ?? $this->ids->span(); + $this->currentSpanIdAvailable = $currentSpanAvailable; + + if ($this->disabled === true) { + return false; } return $this->sampling = $this->sampler->shouldSample( @@ -124,12 +123,8 @@ public function endTrace(): void $this->sampler->reset(); } - if ($this->sampling === false) { - return; - } - - $this->currentTraceId = $this->ids->trace(); - $this->currentSpanId = $this->ids->span(); + $this->currentTraceId = null; + $this->currentSpanId = null; $this->currentSpanIdAvailable = true; $this->sampling = false; @@ -173,11 +168,8 @@ public function unsample(): void } $this->paused = false; - - if ($this->sampling === false) { - return; - } - + $this->currentTraceId = null; + $this->currentSpanId = null; $this->currentSpanIdAvailable = true; $this->sampling = false; $this->spans = []; @@ -213,12 +205,12 @@ public function isSamplingPaused(): bool return $this->paused; } - public function currentTraceId(): string + public function currentTraceId(): ?string { return $this->currentTraceId; } - public function currentSpanId(): string + public function currentSpanId(): ?string { return $this->currentSpanId; } @@ -232,7 +224,7 @@ public function currentParentSpanId(): ?string public function nextSpanId(): string { - if ($this->sampling && $this->currentSpanIdAvailable === true) { + if ($this->sampling && $this->currentSpanIdAvailable === true && $this->currentSpanId !== null) { $this->currentSpanIdAvailable = false; return $this->currentSpanId; @@ -241,11 +233,15 @@ public function nextSpanId(): string return $this->ids->span(); } - public function traceParent(): string + public function traceParent(): ?string { + if ($this->currentTraceId === null || $this->currentSpanId === null) { + return null; + } + return $this->ids->traceParent( - $this->currentTraceId ?? '', - $this->currentSpanId ?? '', + $this->currentTraceId, + $this->currentSpanId, $this->isSampling(), ); } @@ -283,6 +279,10 @@ public function hasCurrentSpan(?FlareSpanType $spanType = null): bool public function currentSpan(): ?Span { + if ($this->currentSpanId === null) { + return null; + } + return $this->spans[$this->currentSpanId] ?? null; } @@ -312,12 +312,16 @@ public function startSpan( ?int $time = null, array $attributes = [], ): Span|AddSpanResult { + if ($this->currentTraceId === null) { + throw new Exception('Cannot start a span without an active trace.'); + } + // Order of operations is important here, do not inline! $parentSpanId = $this->currentParentSpanId(); $spanId = $this->nextSpanId(); $span = new Span( - traceId: $this->currentTraceId ?? $this->ids->trace(), + traceId: $this->currentTraceId, spanId: $spanId, parentSpanId: $parentSpanId, name: $name, diff --git a/tests/FlareTest.php b/tests/FlareTest.php index b7ee07b..20170c9 100644 --- a/tests/FlareTest.php +++ b/tests/FlareTest.php @@ -43,6 +43,16 @@ ); }); +it('can start and end a flare lifecycle', function () { + $flare = setupFlare(alwaysSampleTraces: true)->start(); + + expect($flare->tracer->isSampling())->toBeTrue(); + + $flare->end(); + + expect($flare->tracer->isSampling())->toBeFalse(); +}); + it('can reset queued exceptions', function () { $flare = setupFlare(fn (FlareConfig $config) => $config->collectContext()); @@ -375,6 +385,8 @@ it('can add queries', function () { $flare = setupFlare(fn (FlareConfig $config) => $config->collectQueries()); + $flare->tracer->startTrace(); + $flare->query()->record( 'select * from users where id = ?', TimeHelper::milliseconds(250), @@ -423,6 +435,8 @@ it('can begin and commit transactions', function () { $flare = setupFlare(fn (FlareConfig $config) => $config->collectTransactions()); + $flare->tracer->startTrace(); + $flare->transaction()->recordBegin(); FakeTime::setup('2019-01-01 12:34:57'); // One second later 1546346097000000 @@ -446,6 +460,8 @@ it('can begin and rollback transactions', function () { $flare = setupFlare(fn (FlareConfig $config) => $config->collectTransactions()); + $flare->tracer->startTrace(); + $flare->transaction()->recordBegin(); FakeTime::setup('2019-01-01 12:34:57'); // One second later 1546346097000000 @@ -831,6 +847,8 @@ ]) ); + $flare->tracer->startTrace(); + $flare->recorder('spans')->record('Hi', duration: TimeHelper::milliseconds(300)); $throwable = new RuntimeException('This is a test'); diff --git a/tests/Recorders/QueryRecorder/QueryRecorderTest.php b/tests/Recorders/QueryRecorder/QueryRecorderTest.php index 45eacf5..fc9e9d1 100644 --- a/tests/Recorders/QueryRecorder/QueryRecorderTest.php +++ b/tests/Recorders/QueryRecorder/QueryRecorderTest.php @@ -235,6 +235,8 @@ ] ); + $flare->tracer->startTrace(); + $recorder->record('select * from users where id = ?', TimeHelper::milliseconds(299), ['id' => 1], 'users', 'mysql'); expect($recorder->getSpans())->toHaveCount(1); diff --git a/tests/Recorders/SpanEventsRecorderTest.php b/tests/Recorders/SpanEventsRecorderTest.php index 572ed04..659b789 100644 --- a/tests/Recorders/SpanEventsRecorderTest.php +++ b/tests/Recorders/SpanEventsRecorderTest.php @@ -124,6 +124,8 @@ 'with_traces' => true, ]); + $flare->tracer->startTrace(); + $span = $flare->tracer->startSpan( 'root span' ); @@ -236,6 +238,8 @@ public function record(string $message): ?SpanEvent 'find_origin' => false, ]); + $flare->tracer->startTrace(); + $span = $flare->tracer->startSpan('Parent Span'); $recorder->record('Hello World'); diff --git a/tests/Recorders/SpansRecorderTest.php b/tests/Recorders/SpansRecorderTest.php index bc0ab7f..351fed7 100644 --- a/tests/Recorders/SpansRecorderTest.php +++ b/tests/Recorders/SpansRecorderTest.php @@ -42,6 +42,8 @@ 'with_traces' => false, ]); + $flare->tracer->startTrace(); + $recorder->record('Span', 100); $spans = $recorder->getSpans(); @@ -65,6 +67,8 @@ 'max_items_with_errors' => 35, ]); + $flare->tracer->startTrace(); + foreach (range(1, 40) as $i) { $recorder->pushSpan("Span - Hello {$i}"); $recorder->popSpan(); @@ -83,6 +87,8 @@ 'max_items_with_errors' => null, ]); + $flare->tracer->startTrace(); + foreach (range(1, 250) as $i) { $recorder->pushSpan("Hello {$i}"); $recorder->popSpan(); @@ -164,6 +170,8 @@ public function recordMessage(string $message): ?Span $flare = setupFlare(alwaysSampleTraces: true); + $flare->tracer->startTrace(); + expect(fn () => (new TestConcreteSpanRecorderExecution($flare->tracer, $flare->backTracer, config: [ 'with_traces' => true, 'with_errors' => true, diff --git a/tests/TracerTest.php b/tests/TracerTest.php index b286534..7db0298 100644 --- a/tests/TracerTest.php +++ b/tests/TracerTest.php @@ -241,17 +241,16 @@ expect($span->spanId)->not()->toBeNull(); }); -it('can unsample a trace and all its spans', function () { +it('can unsample a trace and clear its state', function () { $tracer = setupFlare(alwaysSampleTraces: true)->tracer; $tracer->startTrace(); - - $span = $tracer->startSpan('Some span'); + $tracer->startSpan('Some span'); $tracer->unsample(); - expect($tracer->currentTraceId())->toBe($span->traceId); - expect($tracer->currentSpanId())->toBe($span->spanId); + expect($tracer->currentTraceId())->toBeNull(); + expect($tracer->currentSpanId())->toBeNull(); expect($tracer->sampling)->toBeFalse(); expect($tracer->currentTrace())->toBeEmpty(); }); @@ -387,27 +386,70 @@ expect($span->events[0]->name)->toEqual('Some event'); }); -it('will always have a trace and span id even when a trace start call has not happened yet', function () { +it('has no trace and span id before startTrace is called', function () { $tracer = setupFlare()->tracer; - expect($tracer->currentTraceId())->not()->toBeNull(); - expect($tracer->currentSpanId())->not()->toBeNull(); + expect($tracer->currentTraceId())->toBeNull(); + expect($tracer->currentSpanId())->toBeNull(); }); -it('will use the initial trace and span id until a trace is started', function () { +it('clears the trace and span id when a sampled trace ends', function () { $tracer = setupFlare(alwaysSampleTraces: true)->tracer; - expect($tracer->currentTraceId())->not()->toBeNull(); - expect($tracer->currentSpanId())->not()->toBeNull(); + $tracer->startTrace(); + $tracer->startSpan('Some span'); + $tracer->endSpan(); + $tracer->endTrace(); + + expect($tracer->currentTraceId())->toBeNull(); + expect($tracer->currentSpanId())->toBeNull(); +}); - $currentTraceId = $tracer->currentTraceId(); - $currentSpanId = $tracer->currentSpanId(); + +it('preserves the active trace when startTrace is called again on an unsampled trace', function () { + $tracer = setupFlare(fn (FlareConfig $config) => $config->sampler(NeverSampler::class))->tracer; $tracer->startTrace(); - $span = $tracer->startSpan('Some span'); - expect($span->traceId)->toBe($currentTraceId); - expect($span->spanId)->toBe($currentSpanId); + $firstTraceId = $tracer->currentTraceId(); + $firstSpanId = $tracer->currentSpanId(); + + $tracer->startTrace(); + + expect($tracer->currentTraceId())->toBe($firstTraceId); + expect($tracer->currentSpanId())->toBe($firstSpanId); +}); + +it('adopts an inbound traceparent even when the tracer is disabled so logs stay correlated', function () { + $tracer = setupFlare(fn (FlareConfig $config) => $config->trace = false)->tracer; + + $tracer->startTrace(traceParent: '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01'); + + expect($tracer->sampling)->toBeFalse(); + expect($tracer->currentTraceId())->toBe('0af7651916cd43dd8448eb211c80319c'); + expect($tracer->currentSpanId())->toBe('b7ad6b7169203331'); +}); + +it('returns a null traceparent when there is no active trace context', function () { + $tracer = setupFlare()->tracer; + + expect($tracer->traceParent())->toBeNull(); +}); + +it('returns a traceparent with the local sampling flag when a trace context exists', function () { + $tracer = setupFlare(alwaysSampleTraces: true)->tracer; + + $tracer->startTrace(); + + expect($tracer->traceParent())->toMatch('/^00-[0-9a-f]{32}-[0-9a-f]{16}-01$/'); +}); + +it('propagates an inherited traceparent for downstream services even when not sampling locally', function () { + $tracer = setupFlare(fn (FlareConfig $config) => $config->trace = false)->tracer; + + $tracer->startTrace(traceParent: '00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01'); + + expect($tracer->traceParent())->toMatch('/^00-0af7651916cd43dd8448eb211c80319c-[0-9a-f]{16}-00$/'); }); it('can include the peak memory usage when ending a span', function () {