OSS監視ツールを活用してWebアプリのボトルネックを可視化してみた

夏休み自由研究連載 2026 の5本目です。

はじめに

こんにちは、2026年7月にキャリア入社した高嶋です。夏休みの自由研究企画ということで、フューチャーに入社して初めてのブログを書きます。今回は、私が特に好きなテーマであるオブザーバビリティや興味のあったトレーシング技術を使って遊んでみました。

題材としてはISUCON10予選を使わせていただいています。選定理由は以下の3点です。

1. ソースコードやAMIが公開されていて構築が容易
2. ボトルネックが作りこまれており可視化するのが楽しい
3. Webサーバ・アプリケーション・DBのシンプルな構成

本記事ではオープンソースの監視ツールを用いてボトルネックを可視化した結果をご紹介します。

可視化対象のアーキテクチャ

ベンチサーバとアプリサーバの2台構成で、アプリサーバにはnginx・Go・MySQLが載っています。また、ベンチを実行するとベンチサーバから各種エンドポイントへリクエストが投げられます。

今回はアプリサーバを対象に可視化を行いました。

インスタンス等の詳細です。matsuu/aws-isucon が公開しているISUCON10予選のAMIを使っています。

可視化内容の選定

トレーシングでミドルウェア間の遅延を見えるようにしたいと考えていたものの、遅延状況はアプリのエンドポイントによってまちまちです。そこでエンドポイントを横断した可視化と、特定のエンドポイントについてのトレーシングの2段構成で見ていくことにしました。

①エンドポイント別の遅延可視化

以下のようなグラフを作成しました。

• X軸：レスポンスタイムの95パーセンタイル値（p95）
• Y軸：そのエンドポイントのリクエスト数
• 丸のサイズ：そのエンドポイントのレスポンスタイムの合計

3項目の関係がわかりやすいようにバブルチャートで表現しています。

丸のサイズは合計レスポンスタイム、つまりシステム全体の処理時間に対する影響を表しており、サイズの大きなエンドポイントほどチューニングした際の効果が大きいとみなせます。

たとえば一番右の丸は突出して遅いですが、リクエスト数はそこまで多くありません。一方で赤い丸はレスポンスタイムはそこそこですがリクエスト回数が多く、合計レスポンスタイムは大きくなっています。この場合、赤い丸を優先してチューニングすると良さそうです。

実アプリに置き換えて考えてみても、閲覧頻度が低くてとても遅いページを改善するより、閲覧頻度が高くそこそこ遅いページのチューニングをした方が全体的な満足度は上がりそうな気がします。

アーキテクチャ

nginxのアクセスログをprometheus-nginxlog-exporterを用いて時系列メトリクスに変換し、Prometheusに取り込んでいます。またグラフはGrafanaで描いています。

ポイントは以下です。

exporter側でパス正規化を行う

• /api/estate/1234 のようなIDを含むパスをそのまま扱うと、1走行で1800種類以上のパスが出てバブルが数千個になってしまいます。prometheus-nginxlog-exporterのrelabel設定で /api/estate/:id のように畳むと15パスまで減りました。

②トレーシングで各ミドルウェアでの経過時間を可視化

エンドポイント別の可視化で特に影響が大きいことが読み取れた /api/estate/search というエンドポイントについてトレーシングしてみました。

すると、GoからMySQLへ2回クエリを投げており、それらの実行時間が支配的であることがわかりました。ここで投げられているクエリのチューニングをすることで高速化ができそうです。

他のエンドポイントについてもみてみましょう。右のほうにある突出して遅いエンドポイント /api/estate/nazotte をトレーシングします。

すると、GoからMySQLへ大量のクエリを投げていることがわかりました（図だと途中までしか映っていませんが、この下にもずっとSQLのスパンが続きます）。1つ1つのクエリにかかる時間は短いですが、件数が多いためトータルで見ると時間がかかっています。1回で済むはずのデータ取得が、ループの中で1件ずつ追加のクエリを発行してしまうことで「1 + N回」のクエリになってしまう、N+1問題と呼ばれるアンチパターンが発生しているように見えます。

このようにトレーシングを行うことで、nginx・Go・MySQLのどこにボトルネックがあるのかを直感的に確認できました。

アーキテクチャ

GoアプリケーションをOpenTelemetryで計装し、Tempoへスパンを送信しています。トレースの表示はGrafanaで行っています。

Go側に追加したモジュールは、数が多くなるので役割ごとに3つだけ挙げます。

ポイントは以下です。

nginxのスパンはGoが代理で作る

• nginx 1.14はOpenTelemetryに対応していないので、そのままではnginxのバーが出ません。Goへリクエストをプロキシするときに X-Request-Start というヘッダで時刻を渡し、Go側でその時刻を開始時刻とするスパンを作成しています。
  • nginx 1.25.3から公式のOpenTelemetryモジュールが使えるためバージョンを上げてもよかったかもしれません…

MySQLのスパンもGoが代理で作る

• SQLドライバを XSAM/otelsql でラップするとSQL1本ごとにスパンが作られます。ただしotelsqlは渡された context から親スパンを探すため、db.Get のようなcontextを取らない呼び出しを db.GetContext(ctx, ...) のように書き換えました。
  • MySQLもEnterprise Edition 8.1.0以降であればOpenTelemetryに対応していますが、Community Editionには無い機能です。

注意

ISUCON10予選アプリのGoは1.14.7で現行のOpenTelemetry SDKがビルドできないため、Go 1.27に上げてから計装しています。また、Echo v3系では公式の計装ライブラリ otelecho（v4専用）が使えないため、HTTPのスパンを作るミドルウェアを自作しました。

正直なところ、自分で実装するのであればここまで手を入れなければならない時点で挫折していましたが、今回はClaude Codeが頑張ってくれました。ミドルウェアのバージョンによってはもっと楽になると思います。

さいごに

やはり見えなかったものが見えるようになるのはとても気持ちがいいと思いました！本記事ではミドルウェア内の話や、トレーシングに現れないボトルネック、時間経過での変化については触れませんでした。今後、それらについても可視化したいと考えています。

また、対象の設計や特性を知ること、どのような状態を検知したいのかという目的を明確にすることの重要性を改めて認識しました。ボトルネックの可視化を目的にするのであれば、ボトルネックとなりやすい箇所やそれを示す指標、それがどのような粒度で現れるのかを知っておく必要があります。これは今回の目的に限らず監視全般に言えることだと思います。

参考

• ISUCON10 予選（isucon/isucon10-qualify）
• matsuu/aws-isucon — 歴代ISUCONの公開AMI
• prometheus-nginxlog-exporter
• OpenTelemetry Go
• XSAM/otelsql
• Grafana Tempo