👨🏼‍💻

Cloud Traceでボトルネックを追ってみるぞ

島袋恵

2023/05/12に公開

はじめに

この記事は Cloud Trace を導入したときに調べたことをまとめたものです。Cloud Trace は、Google Cloud の分散トレーシングシステムで、アプリケーションのパフォーマンス問題を特定、解析できるサービスです。

例えば、リクエストを受け取った後にシステム内で行われる各処理にどれぐらいの時間がかかったか、どんなクエリが実行されたかなどを知ることができます。GCP のコンソールの画面では、以下のように各処理の時間を知ることができます。

/posts のエンドポイントにリクエストがあったときにリクエスト内で行われる処理時間

以下、導入までに調べたことをまとめていきます。

Cloud Trace とは

分散トレースシステムです。

Google Cloud の分散トレースシステムである Cloud Trace を使用すると、ユーザーや他のアプリケーションからの受信リクエストをアプリケーションが処理するのにかかる時間や、リクエストの処理時に実行されるオペレーション（RPC 呼び出しなど）が完了するのにかかる時間を知ることができます。

Cloud Trace ができること

アプリケーションからトレースを受け取ることで、以下のようなことを知ることができます。

ユーザーや他のアプリケーションからの受信リクエストをアプリケーションが処理するのにかかる時間
リクエストの処理時に実行されるオペレーション（RPC 呼び出しなど）が完了するのにかかる時間

トレースとは

トレースは、アプリケーションに対してリクエストが行われたときに、1 つのオペレーションを完了させるまでのひとまとまりを表しています。トレースは 1 つ以上のスパンから構成されます。
スパンは、トレース内の各種処理のことで、スパンのまとまりがトレースになります。

引用元: https://reflectoring.io/spring-boot-tracing/

アプリケーションからトレースを受け取る方法

Cloud Trace がアプリケーションからトレースを受け取るためには、アプリケーションを計測可能な状態にする必要があります。計測可能な状態にする方法に、OpenTelemetry を使う方法があります。

OpenTelemetry とは

OpenTelemetry とは、オブザーバビリティの三本柱といわれるログ、メトリクス、トレースの計装と収集、エクスポートを標準化した OSS のライブラリです。

オブザーバビリティとは、システム内がどれだけ観測可能な状態になっているかの尺度のことです。例えば、システムのバグや不具合調査をする際に新しいコードを追加しデプロイすることなく、その不具合を把握することが、どれぐらい可能かといった尺度になります。

OpenTelemetry の解説としてこちらの記事がわかりやすかったです。

Node.js のアプリケーションからトレースを受け取る方法

実際に OpenTelemetry のライブラリを使って、アプリケーションからトレース情報を受け取る方法をまとめていきます。

OpenTelemetry は、さまざまなプログラミング言語をサポートしており、今回は、Node.js のアプリケーションからトレースを収集したかったので、Google Cloud と Opentelemetry の以下のドキュメントを参考にしました。

Node.js のアプリケーションのフレームワークには、 NestJS を利用したので以下の記事も参考になりました。

試しに実装してみたサンプルが以下のリポジトリにあります。

以下、主要部分の抜粋です。

tracing.ts

import { Resource } from "@opentelemetry/resources";
import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http";
import { SemanticResourceAttributes } from "@opentelemetry/semantic-conventions";
import * as opentelemetry from "@opentelemetry/sdk-node";
import { getNodeAutoInstrumentations } from "@opentelemetry/auto-instrumentations-node";
import {
  ConsoleSpanExporter,
  BatchSpanProcessor,
  SpanExporter,
  SpanProcessor,
  SimpleSpanProcessor,
} from "@opentelemetry/sdk-trace-base";
import { TraceExporter } from "@google-cloud/opentelemetry-cloud-trace-exporter";
import { PrismaInstrumentation } from "@prisma/instrumentation";

let traceExporter: SpanExporter;
let spanProcessor: SpanProcessor;
// 実行環境に応じて適切なトレースエクスポーターとスパンプロセッサーを設定する
if (process.env.NODE_ENV === "production") {
    // 本番環境では、Google CloudのTraceExporterとBatchSpanProcessorを使用
  traceExporter = new TraceExporter();
  spanProcessor = new BatchSpanProcessor(traceExporter);
} else {
    // 開発環境では、OTLPTraceExporterとSimpleSpanProcessorを使用
  traceExporter = new OTLPTraceExporter({
    url: "http://127.0.0.1:4318/v1/traces",
  });
  spanProcessor = new SimpleSpanProcessor(traceExporter);
}

const resource = Resource.default().merge(
  new Resource({
    [SemanticResourceAttributes.SERVICE_NAME]: "nestjs-prisma-sample",
    [SemanticResourceAttributes.SERVICE_VERSION]: "0.0.1",
  })
);
const sdk = new opentelemetry.NodeSDK({
  traceExporter,
  instrumentations: [
    // 全てのノード自動計測器を有効にする
    getNodeAutoInstrumentations({
        // 特定のノードの自動計測器を無効にしたい場合は以下のようにenabledをfalseにする
      "@opentelemetry/instrumentation-fs": {
        enabled: false,
      },
    }),
    // Prismaの自動計測器
    // schema.prisma の previewFeatures = ["tracing"] も必要
    new PrismaInstrumentation(),
  ],
  spanProcessor,
  resource,
});

// プリケーションが終了する際にOpenTelemetry SDKを適切にシャットダウンするように設定します。
// これは、すべてのデータが正常にフラッシュされ、エクスポーターが適切にシャットダウンされることを保証
process.on("SIGTERM", () => {
  sdk
    .shutdown()
    .then(() => console.log("Tracing terminated"))
    .catch((error: any) => console.log("Error terminating tracing", error))
    .finally(() => process.exit(0));
});

export default sdk;

main.ts

import tracing from "./tracing";
import { NestFactory } from "@nestjs/core";
import { AppModule } from "./app.module";
import { ConfigService } from "@nestjs/config";

async function bootstrap() {
  // Start SDK before nestjs factory create
  tracing.start();
  const app = await NestFactory.create(AppModule);
  app.enableShutdownHooks();
  const configService = app.get(ConfigService);
  const port = configService.get("PORT") || 3000;

  await app.listen(port);
}
bootstrap();

ここまで実装した後に、アプリケーションを Cloud Run にデプロイしてリクエストを送ってみると、Cloud Trace のコンソールの画面で、送られたトレースを確認することができました。

ちょっとした注意事項

以下、導入してて少し躓いた部分です。

権限が足りなくてトレースが送れない場合

今回の導入では、トレースする対象のアプリケーションを Cloud Run で動かしていたので、アプリケーションに Cloud Trace への認証情報の提供などは特に必要ありませんでした。ただ、Cloud Trace にトレースを送るためには、Cloud Run のサービスアカウントに Cloud Trace へアクセスする権限が必要でした。

もし権限が十分でない場合は、必要に応じて、IAM の設定で Cloud Run のサービスアカウントに Cloud Trace へアクセスする権限を付与する必要があります。

サービスアカウントに Cloud Trace のトレースへアクセスする権限を付与する必要

認証情報が不要については以下のドキュメントに記載があります。

Google Cloud 上で実行する場合、一般的にアプリケーションに認証情報を提供したり、アプリケーションで Google Cloud プロジェクト ID を指定する必要はありません。一部の言語では、Google Cloud 上で実行されている場合でも、Google Cloud プロジェクト ID を指定する必要があります。

全てのリクエストをトレースしたい場合

トレースを眺めていると、リクエストしてるのにトレースが取得できてない？と思ったことがあったのですが、Cloud Run の場合、すべてのリクエストに対してトレースを取得しているわけではなく、特定のレートでサンプリングされているようでした。

Cloud Run では、すべてのリクエストに対してトレースがサンプリングされるわけではありません。Cloud Run で使用する場合、リクエストは各コンテナインスタンスにつき 1 秒あたり最大 0.1 リクエストのレートでサンプリングされます。特定のリクエストを強制的にトレースすることもできます。

強制的に全てのリクエストに対するトレースをサンプリングする方法もあって、X-Cloud-Trace-Context ヘッダーを付与することで可能です。
ヘッダーの仕様としては "X-Cloud-Trace-Context: TRACE_ID/SPAN_ID;o=TRACE_TRUE" です。

このリクエストをトレースするには、TRACE_TRUE を 1 に設定する必要があります。リクエストをトレースしない場合は 0 を指定します。

例
curl "http://www.example.com" --header "X-Cloud-Trace-Context:
  105445aa7843bc8bf206b12000100000/1;o=1"

また、OpenTelemetry のライブラリでは、サンプリングレートの構成がサポートされており、全てのリクエストに対して X-Cloud-Trace-Context ヘッダーを付与し強制的にトレースをサンプリングするためには sampler: new AlwaysOnSampler() を追加することで全てのリクエストに対してトレースをサンプリングすることができます。

export const provider = new NodeTracerProvider({
  sampler: new AlwaysOnSampler(),
  resource: new Resource({
    [SemanticResourceAttributes.SERVICE_NAME]: processName,
  }),
  //...
});

以下の記事と issue が参考になりました。

結果

以下、記事冒頭に貼った Cloud Trace のコンソールの画面です。あらためてみてみると、リクエストを受けてから、ミドルウェア、NestJS のコントローラー、Prisma による DB アクセスなどリクエストの各処理のタイムラインが確認できていて、とても便利ですね。ここから、リクエストの処理時間や、リクエスト内の各処理でどの処理に時間がかかっているのかなどを確認することができます。

/posts のエンドポイントにリクエストがあったときにリクエスト内で行われる処理時間

Cloud Trace の料金

料金についても確認しておきます。

トレースの取り込み
100 万スパンごとに $0.20

料金
100 万スパンごとに $0.20

毎月の無料割り当て量
最初の 250 万スパン

ダッシュボードから確認できます。

ローカルで分散トレースシステムを動かしたい場合

ここまで Cloud Trace にトレースをエクスポートする手順を紹介してきましたが、ローカルで分散トレースシステムを動かしたい場合は、手元の環境で Jaeger などを動かして、エクスポート先を Jaeger に変更することで可能です。

DockerHub に公開されたビルド済みの jaeger のイメージをローカルで起動します。

# https://www.jaegertracing.io/docs/1.45/getting-started/#all-in-one
$ docker run -d --name jaeger \
  -e COLLECTOR_ZIPKIN_HOST_PORT=:9411 \
  -e COLLECTOR_OTLP_ENABLED=true \
  -p 6831:6831/udp \
  -p 6832:6832/udp \
  -p 5778:5778 \
  -p 16686:16686 \
  -p 4317:4317 \
  -p 4318:4318 \
  -p 14250:14250 \
  -p 14268:14268 \
  -p 14269:14269 \
  -p 9411:9411 \
  jaegertracing/all-in-one:1.45

上述した tracing.ts からの抜粋ですが、ローカルで Jaeger を動かしている場合は、以下のようにエクスポート先を Jaeger collector の URL を指定します。

tracing.ts

// Cloud Traceにエクスポートする場合
if (process.env.NODE_ENV === "production") {
  traceExporter = new TraceExporter();
  spanProcessor = new BatchSpanProcessor(traceExporter);
} else {
  // ローカルで Jaeger にエクスポートする場合
  traceExporter = new OTLPTraceExporter({
    url: "http://127.0.0.1:4318/v1/traces", // OpenTelemetry Protocol (OTLP) over HTTP, if enabled
  });
  spanProcessor = new SimpleSpanProcessor(traceExporter);
}

ローカルでトレース対象のアプリケションを少し操作してみたあと、jager の UI に http://localhost:16686/search アクセスすると、以下のようにトレースのタイムラインが確認できます。

おわりに

今回 Cloud Trace を導入してみて、アプリケーションの挙動でなんかもっさりしてて動きが遅いと思っていたところのボトルネックの特定、改善できた体験がすごく良かったので、オブザーバビリティを高めていけるよう引き続き取り組んでいきたい。

参考

Cloud Run Casual Talk! おもしろい

GitHubで編集を提案

株式会社モニクルPublication

株式会社モニクルは、「金融の力で、安心を届ける。」をミッションとする金融サービステック企業です。金融の専門知識がなくても、正しい意思決定ができる社会へ。そのために必要なのは、人によるサービスとテクノロジーの掛け合わせ。既存のフィンテックとは異なる挑戦に取り組んでいます。