PHP 中使用 opentelemetry-auto-laravel 进行链路追踪时间片段不连续的问题

V2EX = way to explore

V2EX 是一个关于分享和探索的地方

现在注册

已注册用户请登录

这是一个创建于 754 天前的主题，其中的信息可能已经有所发展或是发生改变。

先上正菜

PHP项目上了opentelemetry的时候发现有部分片段时间不连续

<details> <summary>接入配置(如有需要, 点击这里查看详情)</summary>

接入

安装扩展 (自动上报需要PHP8)
- https://opentelemetry.io/docs/languages/php/automatic/
- opentelemetry扩展
  - 容器中可以使用install-php-extensions opentelemetry安装
  - windows官方没有, 可以到这里下载ddl文件https://phpext.phptools.online/extension/php/opentelemetry-261
- composer扩展
  - composer install open-telemetry/opentelemetry-auto-laravel

配置

TEL_PHP_AUTOLOAD_ENABLED=true TEL_SERVICE_NAME=test TEL_TRACES_EXPORTER=otlp TEL_METRICS_EXPORTER=none TEL_LOGS_EXPORTER=none TEL_EXPORTER_OTLP_PROTOCOL=grpc TEL_EXPORTER_OTLP_ENDPOINT=http:// TEL_EXPORTER_OTLP_HEADERS=Authentication=xxx TEL_EXPORTER_OTLP_TIMEOUT=1000 TEL_EXPORTER_OTLP_TRACES_TIMEOUT=1000

运行

open-telemetry/opentelemetry-auto-laravel这个项目通过composer.json的_register.php让Laravel自动加载https://github.com/open-telemetry/opentelemetry-php-contrib/blob/main/src/Instrumentation/Laravel/composer.json#L39

{ "files": [ "_register.php" ] }

默认会收集request, cache,log,http client https://github.com/open-telemetry/opentelemetry-php-contrib/blob/main/src/Instrumentation/Laravel/src/LaravelInstrumentation.php
会根据以下解析出一个BatchProcessSpan
- https://github.com/open-telemetry/opentelemetry-php/blob/main/src/SDK/Common/Configuration/Defaults.php#L115默认配置batch
- https://github.com/open-telemetry/opentelemetry-php/blob/main/src/SDK/SdkAutoloader.php注册各种默认配置

public static function autoload(): bool { if (!self::isEnabled() || self::isExcludedUrl()) { return false; } Globals::registerInitializer(function (Configurator $configurator) { $propagator = (new PropagatorFactory())->create(); if (Sdk::isDisabled()) { //@see https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/configuration/sdk-environment-variables.md#general-sdk-configuration return $configurator->withPropagator($propagator); } $emitMetrics = Configuration::getBoolean(Variables::OTEL_PHP_INTERNAL_METRICS_ENABLED); $resource = ResourceInfoFactory::defaultResource(); $exporter = (new ExporterFactory())->create(); $meterProvider = (new MeterProviderFactory())->create($resource); // 主要关注这一行, 这里我们会创建出一个 BatchSpanProcessor $spanProcessor = (new SpanProcessorFactory())->create($exporter, $emitMetrics ? $meterProvider : null); $tracerProvider = (new TracerProviderBuilder()) ->addSpanProcessor($spanProcessor) ->setResource($resource) ->setSampler((new SamplerFactory())->create()) ->build(); $loggerProvider = (new LoggerProviderFactory())->create($emitMetrics ? $meterProvider : null, $resource); ShutdownHandler::register($tracerProvider->shutdown(...)); ShutdownHandler::register($meterProvider->shutdown(...)); ShutdownHandler::register($loggerProvider->shutdown(...)); return $configurator ->withTracerProvider($tracerProvider) ->withMeterProvider($meterProvider) ->withLoggerProvider($loggerProvider) ->withPropagator($propagator) ; }); return true; }

</details>

案例代码

自定义一个类

<?php namespace App\Service\Tracing; use OpenTelemetry\API\Globals; use OpenTelemetry\API\Trace\SpanInterface; use OpenTelemetry\API\Trace\TracerInterface; class Tracer { protected TracerInterface $tracer; protected ?SpanInterface $lastSpan = null; protected ?SpanInterface $rootSpan = null; /** * @var array Span */ protected array $spanMap = []; public function __construct() { $this->tracer = Globals::tracerProvider() ->getTracer('io.opentelemetry.contrib.php.laravel'); } /** * 请查看 AppServiceProvider 注册为 scoped, 适用于 Octane *@return Tracer */ public static function getInstance(): Tracer { return app(Tracer::class); } public function startRootSpan($name): void { $span = $this->startSpan($name); $this->rootSpan = $span; } public function startAndEndLastSpan($name): SpanInterface { $this->endLastSpan(); return $this->startSpan($name); } public function startSpan($name): SpanInterface { $span = $this->tracer->spanBuilder($name)->startSpan(); $this->spanMap[$name] = $span; $this->lastSpan = $span; return $span; } public function endRootSpan(): void { $this->endSpan($this->rootSpan); } /** * @return void 方便的 end 上一个 span */ public function endLastSpan(): void { $this->endSpan($this->lastSpan); } public function endSpan(?SpanInterface $span): void { if (is_null($span)) { return; } $span->end(); } }

把Tracer类注册到服务提供者app/Providers/AppServiceProvider.php
- 由于我们使用常驻内存运行https://github.com/laravel/octane
- 服务提供者请使用scoped来注册

<?php namespace App\Providers; use App\Utils\Tracing\Tracer; use Illuminate\Support\ServiceProvider; class AppServiceProvider extends ServiceProvider { /** * Register any application services. * * @return void */ public function register() { // 整个生命周期只注册一次 $this->app->scoped(Tracer::class, function () { return new Tracer(); }); } /** * Bootstrap any application services. * * @return void */ public function boot() { // } }

在控制器使用

<?php namespace App\Http\Controllers; use App\Service\Tracing; class IndexAlbumsController extends Controller { public function index() { $tracer = Tracer::getInstance(); // 步骤 0 $tracer->startRootSpan('xxxx'); // 步骤 1 $tracer->startSpan('s1'); // 业务代码 xxx // 结束步骤 1, 并开启步骤 2 $tracer->startAndEndLastSpan('s2'); // 业务代码 xxx // 结束步骤 2 $tracer->endLastSpan(); // 结束 root $tracer->endRootSpan(); } }

问题

代码很简单, 就追踪几个函数, 看耗时, 不出意外的话, 意外还是发生了
线上偶尔会在$span->end()的时候耗时几百毫秒, 百思不得其解

查看`end()`的实现

实际上会走到BatchSpanProcessor类的onEnd方法

class BatchSpanProcessor { public function onEnd(ReadableSpanInterface $span): void { if ($this->closed) { return; } if (!$span->getContext()->isSampled()) { return; } if ($this->queueSize === $this->maxQueueSize) { $this->dropped++; return; } $this->queueSize++; $this->batch[] = $span->toSpanData(); $this->nextScheduledRun ??= $this->clock->now() + $this->scheduledDelayNanos; if (count($this->batch) === $this->maxExportBatchSize) { $this->enqueueBatch(); } if ($this->autoFlush) { // flush $this->flush(); } } }