CakePHP OpenTelemetry Pluginを作った話

最近(というかここ1,2年はずっと)私の部署では、Azure Container Apps+StaticWebAppでマイクロサービスっぽい感じでいろんなアプリやAPIを書いています。まだ一部のサービス以外は開発中なのですが、今後増えていくAPIを運用していくにあたってオブザーバビリティを高めないと破綻しそうな予感しかないので、APMを導入したいと考えていました。

そんな中、コミュニティイベントなどでOpenTelemetryの話を色々聞く機会があったのと、Azure Container Appsにマネージド OpenTelemetry エージェントが追加されたこともあり、CakePHP用の汎用プラグインとして実装してみることにしました。その経緯と実装についてまとめます。

コードは以下のリポジトリで公開しています。

github.com

なぜOpenTelemetryなのか

マイクロサービスや複数のバックエンドサービスが絡む構成では、障害調査やパフォーマンス分析の際に「どのリクエストがどこで何をしていたか」を追跡できることが非常に重要です。

OpenTelemetryは、分散トレーシング・メトリクス・ログを統一的に扱うためのオブザーバビリティフレームワークで、CNCF（Cloud Native Computing Foundation）のプロジェクトとして広く採用が進んでいます。

バックエンド非依存のOTLP（OpenTelemetry Protocol）でテレメトリを送信するため、Datadog、New Relic、Grafana Tempo、Azure Application Insightsなど、OTLP対応の任意のバックエンドで利用できます。

プラグインの概要

今回作成した kaz29/cakephp-otel-plugin は、CakePHP 5アプリケーションにコード変更なしでOpenTelemetryの自動トレースを追加するプラグインです。

PHPのext-opentelemetry PECL拡張が提供するzend_observerフックを使い、Controller / ORM操作のスパンを自動生成します。アプリケーションのコードを一切変更することなく、プラグインを追加するだけでトレースが取れるようになります。

トレース対象

以下の操作に対して自動的にスパンが生成されます。

フック対象	スパン名の例	SpanKind
`Controller::invokeAction`	`App\Controller\UsersController::index`	SERVER
`Table::find`	`Users.find(all)`	CLIENT
`Table::save`	`Users.save`	CLIENT
`Table::delete`	`Users.delete`	CLIENT

Controllerのスパンが親スパンとなり、その中で実行されるORMの各操作が子スパンとして記録されるため、1つのリクエストの中でどのDBクエリにどれだけ時間がかかっているかが一目でわかります。

その他の機能

OtelErrorLoggingMiddleware — 5xxエラーをOpenTelemetryのログとして送信するPSR-15ミドルウェア
TraceAwareLogger — 既存のPSR-3ロガーをラップし、ログにtrace_id / span_idを自動付与するデコレーター

なぜログを全部送らないのか

うちの環境ではすでにAzure Monitorでアプリケーションログを収集しています。OpenTelemetry経由でログも全部送ると二重取りになりますし、ログの量に応じてそれなりのコストが発生します。

そこで、通常のログは既存のログ基盤にそのまま流しつつ、TraceAwareLoggerで trace_id を埋め込んでトレースとの紐付けだけできるようにしました。障害調査のときはトレースからtrace_idを拾って、ログ基盤側で検索すれば関連ログを追えます。

一方、5xxエラーだけはトレース画面からすぐに確認できると調査が格段に楽になるので、OtelErrorLoggingMiddlewareで例外ログだけをOpenTelemetryに送るようにしています。全部送るか・何を送るかはコストとのバランスなので、このあたりは環境に合わせて調整してもらえればと思います。

セットアップ

必要な環境

PHP 8.1以上
CakePHP 5.x
ext-opentelemetry PECL拡張

インストール

composer require kaz29/cakephp-otel-plugin

プラグインの有効化

Application.php の bootstrap() メソッドで、プラグインを追加します。

public function bootstrap(): void
{
    parent::bootstrap();
    $this->addPlugin('OtelInstrumentation');
}

エラーログをOTelで送信したい場合は、ミドルウェアも追加します。ErrorHandlerMiddleware の後に追加してください。

public function middleware(MiddlewareQueue $middlewareQueue): MiddlewareQueue
{
    $middlewareQueue
        ->add(new ErrorHandlerMiddleware(Configure::read('Error'), $this))
        ->add(new OtelErrorLoggingMiddleware())
        // ... 他のミドルウェア
    ;
    return $middlewareQueue;
}

環境変数の設定

OpenTelemetry PHP SDKの設定は環境変数で行います。

OTEL_PHP_AUTOLOAD_ENABLED=true
OTEL_SERVICE_NAME=my-cakephp-app
OTEL_TRACES_EXPORTER=otlp
OTEL_EXPORTER_OTLP_PROTOCOL=http/protobuf
OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4318

これだけで、アプリケーションのControllerアクションやDBクエリが自動的にトレースされるようになります。

実装の詳細

Controllerのフック

Controller::invokeAction に zend_observer フックを設定し、リクエスト処理全体をひとつのスパンとして記録します。

\OpenTelemetry\API\Instrumentation\hook(
    Controller::class,
    'invokeAction',
    pre: static function (Controller $controller, array $params, ...) use ($instrumentation) {
        $request = $controller->getRequest();
        $spanBuilder = $instrumentation->tracer()
            ->spanBuilder(get_class($controller) . '::' . $request->getParam('action'))
            ->setSpanKind(SpanKind::KIND_SERVER)
            ->setAttribute('http.method', $request->getMethod())
            ->setAttribute('http.url', (string)$request->getUri())
            ->setAttribute('cake.controller', get_class($controller))
            ->setAttribute('cake.action', $request->getParam('action'));

        $span = $spanBuilder->startSpan();
        Context::storage()->attach($span->storeInContext(Context::getCurrent()));
    },
    post: static function (Controller $controller, array $params, $returnValue, ?Throwable $exception) {
        $scope = Context::storage()->scope();
        $span = Span::fromContext($scope->context());

        if ($exception !== null) {
            $span->recordException($exception);
            $span->setStatus(StatusCode::STATUS_ERROR, $exception->getMessage());
        } else {
            $span->setStatus(StatusCode::STATUS_OK);
        }

        $span->end();
        $scope->detach();
    }
);

SpanKind::KIND_SERVER を設定しているため、トレースのビューアでHTTPリクエストとして認識されます。

ORMのフック

Table::find / Table::save / Table::delete にフックを設定し、DB操作を SpanKind::KIND_CLIENT のスパンとして記録します。

ポイントは Table::save() のエラーハンドリングです。CakePHPの save() はバリデーション失敗時に例外を投げずに false を返す仕様のため、戻り値のチェックも行っています。

post: static function (Table $table, array $params, $returnValue, ?Throwable $exception) {
    // ...
    if ($exception !== null) {
        $span->recordException($exception);
        $span->setStatus(StatusCode::STATUS_ERROR, $exception->getMessage());
    } elseif ($returnValue === false) {
        $span->setStatus(StatusCode::STATUS_ERROR, 'save() returned false');
    } else {
        $span->setStatus(StatusCode::STATUS_OK);
    }
    // ...
}

DbSystemResolver

ORMのフックでは、OpenTelemetryのセマンティック規約に準拠した db.system 属性を設定する必要があります。CakePHPのドライバークラス名からこの値を解決するユーティリティを用意しました。

public static function resolveFromDriverClass(string $driverClass): string
{
    return match (true) {
        str_contains($driverClass, 'Mysql') => 'mysql',
        str_contains($driverClass, 'Postgres') => 'postgresql',
        str_contains($driverClass, 'Sqlite') => 'sqlite',
        str_contains($driverClass, 'Sqlserver') => 'mssql',
        default => 'other_sql',
    };
}

DB接続が取得できない場合は other_sql にフォールバックし、トレース処理自体が失敗しないようにしています。

TraceAwareLogger

既存のPSR-3ロガーをラップし、アクティブなスパンがあれば trace_id と span_id をログのコンテキストに自動付与します。

public function log($level, \Stringable|string $message, array $context = []): void
{
    $spanContext = Span::getCurrent()->getContext();
    $traceId = $spanContext->getTraceId();

    if ($traceId !== '00000000000000000000000000000000') {
        $context['trace_id'] = $traceId;
        $context['span_id'] = $spanContext->getSpanId();
    }

    $this->logger->log($level, $message, $context);
}

ログは OTel で送信するのではなく、trace_idをログに埋め込んでログ基盤側でトレースと突合する方式を採用しています。これにより、既存のログ基盤をそのまま使いつつ、トレースとの紐付けが可能になります。

テスト

テストでは InMemoryExporter + SimpleSpanProcessor を使い、実際にエクスポートされるスパンを検証しています。

# Unitテスト（DB不要）
vendor/bin/phpunit --testsuite unit

# Integrationテスト（PostgreSQL必要）
vendor/bin/phpunit --testsuite integration

CIはGitHub Actionsで PHP 8.3 / 8.4 / 8.5 のマトリクステストを実行しています。PostgreSQLサービスコンテナを使ってIntegrationテストも回しているので、実際のDB接続を含めた動作を継続的に検証できています。

テストアプリ

プラグインの動作確認用に、Posts / Commentsの CRUD を持つテストアプリも含めています。

cd testapp
docker compose up -d
docker compose exec app composer install
docker compose exec app bin/cake migrations migrate

アプリ: http://localhost:8080
Jaeger UI: http://localhost:16686

Jaeger UIで実際のトレースを確認できるので、プラグインの動作を試すのに便利です。

フロントエンドとの分散トレーシング

OpenTelemetry PHP SDKはデフォルトでW3C TraceContextプロパゲーターを使用するため、フロントエンド側でW3C対応のOpenTelemetry SDK（opentelemetry-jsなど）を使えば、追加設定なしでフロントエンドからバックエンドまでの分散トレーシングが実現できます。

おわりに

CakePHP OpenTelemetry Pluginを作成しました。ext-opentelemetry の zend_observer フックを使うことで、アプリケーションコードを変更せずにControllerとORM操作の自動トレースが実現できています。

CakePHPでOpenTelemetryを導入したいけどフックのコードを自分で書くのは面倒、という方はぜひ試してみてください。フィードバックやPRもお待ちしています！

また、Azure Container AppsからTTelで、Application Insghtsに連携する設定なども、若干はまりどころありつつ完了しているので、別の記事を書く予定です。