Discontinuous Time Segments in Tracing with opentelemetry-auto-laravel in PHP

The Main Course

Found discontinuous time segments when implementing opentelemetry tracing in PHP projects

Integration Configuration (Click to expand details)

Integration

Install extensions (Automatic reporting requires PHP8)
- https://opentelemetry.io/docs/languages/php/automatic/
- opentelemetry extension
  - Container installation: install-php-extensions opentelemetry
  - Windows DLL: https://phpext.phptools.online/extension/php/opentelemetry-261
- Composer package:
  - composer install open-telemetry/opentelemetry-auto-laravel

Configuration

### Debugging reporting logs
OTEL_LOG_LEVEL=debug
OTEL_PHP_LOG_DESTINATION=stdout

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

Implementation

open-telemetry/opentelemetry-auto-laravel auto-loads via _register.php in composer.json
Default instrumentation: request, cache, log, http client
Uses BatchSpanProcessor by default from SDK configuration

Sample Code

Custom tracer class

<?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;
    protected array $spanMap = [];

    public function __construct()
    {
        $this->tracer = Globals::tracerProvider()
            ->getTracer('io.opentelemetry.contrib.php.laravel');
    }

    // Methods for span management
    public static function getInstance(): Tracer { /*...*/ }
    public function startRootSpan($name): void { /*...*/ }
    public function startAndEndLastSpan($name): SpanInterface { /*...*/ }
    public function startSpan($name): SpanInterface { /*...*/ }
    public function endRootSpan(): void { /*...*/ }
    public function endLastSpan(): void { /*...*/ }
    public function endSpan(?SpanInterface $span): void { /*...*/ }
}

Controller usage

class IndexAlbumsController extends Controller
{
    public function index()
    {
        $tracer = Tracer::getInstance();
        $tracer->startRootSpan('root');
        // Business logic with spans
        $tracer->endRootSpan();
    }
}

The Problem

Occasional hundreds of milliseconds delay during $span->end()
Missing time segments in tracing data

Root Cause Analysis

The BatchSpanProcessor’s flush() method causes blocking during span export

class BatchSpanProcessor {
    public function onEnd(ReadableSpanInterface $span): void
    {
        // Batch export logic
        if ($this->autoFlush) {
            $this->flush(); // Blocking operation
        }
    }
}

Solutions

Multithreading for flushing (Not feasible for most PHP projects)
Use OpenTelemetry Collector as proxy
~~Pretend you didn’t see it~~ Optimize batch configuration

# Adjust batch parameters
OTEL_BSP_SCHEDULE_DELAY=5000
OTEL_BSP_EXPORT_TIMEOUT=30000
OTEL_BSP_MAX_QUEUE_SIZE=2048
OTEL_BSP_MAX_EXPORT_BATCH_SIZE=512