LaravelでLighthouseを使ってGraphQLサーバをホスティングしている。
Mackerelでトレーシング機能が提供されてから「そのうちトレースしよう」と思っていたのだけれど、ついにやったとこ重い腰を上げてトレースを送った。
Laravel本体には自動計装ライブラリがあるが、Lighthouseにはないので何となくGraphQLの処理の具合を見られるようにしたのでメモっておく。
OpenTelemetryは色々従うべき仕様や推奨される実装があるっぽいが、その辺を読み込んでいると年が明けるので「何となくGraphQLの処理の具合を見られる」が満たされれば良しとした。
第三者に提供するライブラリではない場合はこのくらいでよいのが気楽だ。
Lighthouseにはトレース用の仕組みが用意されているので、OpenTelemetryでのTrace用のSpanを構築するDriverを実装して使うようにした。
結果、何となくGraphQLの処理の具合を見られるようになった。
なんとなくトレースできてる様子
PHP、Laravelのトレースはできている前提で、LaravelがロードするService ProviderにNuwave\Lighthouse\Tracing\TracingServiceProvider::class
を追加、config/lighthouse.php
に実装したDriverを使用するように設定すればよい。
lighthouse/src/lighthouse.php at d9fb0ee2f00c52dd7af0d3ecff073b9fb9c95d87 · nuwave/lighthouse · GitHub
<?php declare(strict_types=1);
return [
'tracing' => [
'driver' => App\GraphQL\OTelTracing::class,
],
];
実装にあたっての参考はこの辺り。
※追記: Subscriptionを使っているとhandleStartRequest
が呼ばれずにexecutionされるパスがあるようで、そうするとエラーするスニペットになっている(後で直すかも)
<?php
namespace App\GraphQL;
use Illuminate\Support\Carbon;
use Nuwave\Lighthouse\Events\BuildExtensionsResponse;
use Nuwave\Lighthouse\Events\StartExecution;
use Nuwave\Lighthouse\Events\StartRequest;
use Nuwave\Lighthouse\Execution\ExtensionsResponse;
use Nuwave\Lighthouse\Execution\ResolveInfo;
use Nuwave\Lighthouse\Tracing\Tracing;
use Nuwave\Lighthouse\Tracing\TracingUtilities;
use OpenTelemetry\API\Globals;
use OpenTelemetry\API\Trace\SpanInterface;
use OpenTelemetry\API\Trace\SpanKind;
use OpenTelemetry\API\Trace\TracerInterface;
use OpenTelemetry\SemConv\TraceAttributes;
class OTelTracing implements Tracing
{
use TracingUtilities;
private TracerInterface $tracer;
private SpanInterface $rootSpan;
private StartRequest $startRequest;
private int|float $executionStartPrecise;
private float $executionStartUnixtime;
public function handleStartRequest(StartRequest $startRequest): void
{
$this->startRequest = $startRequest;
$this->executionStartPrecise = $this->timestamp();
$this->executionStartUnixtime = microtime(true);
$tracerProvider = Globals::tracerProvider();
$this->tracer = $tracerProvider->getTracer('graphql-server');
}
public function handleStartExecution(StartExecution $startExecution): void
{
$this->rootSpan = $this->tracer
->spanBuilder("GraphQL Execution")
->setSpanKind(SpanKind::KIND_INTERNAL)
->setAttributes([
TraceAttributes::GRAPHQL_OPERATION_NAME => $startExecution->operationName,
TraceAttributes::GRAPHQL_DOCUMENT => $this->startRequest->request->getContent(),
])
->startSpan();
}
public function handleBuildExtensionsResponse(BuildExtensionsResponse $buildExtensionsResponse): ?ExtensionsResponse
{
$this->rootSpan->end();
return null;
}
public function record(ResolveInfo $resolveInfo, float|int $start, float|int $end): void
{
if ($this->diffTimeInNanoseconds($start, $end) < 10 * 1000 + 1000) {
return;
}
$this->tracer
->spanBuilder("GraphQL Resolver")
->addLink($this->rootSpan->getContext())
->setSpanKind(SpanKind::KIND_INTERNAL)
->setAttributes([
'graphql.resolver' => $resolveInfo->parentType . '#' . $resolveInfo->fieldName,
])
->setStartTimestamp($this->toNano($this->executionStartUnixtime) + $this->diffTimeInNanoseconds($this->executionStartPrecise, $start))
->startSpan()
->end($this->toNano($this->executionStartUnixtime) + $this->diffTimeInNanoseconds($this->executionStartPrecise, $end));
}
private function toNano(float $value): int
{
return (int) ($value * 1000 * 1000 * 1000);
}
}