Node.js でトレースと指標を生成する

このドキュメントでは、オープンソースの OpenTelemetry フレームワークを使用してトレースと指標データを収集するように Node.js JavaScript アプリを変更する方法と、構造化 JSON ログを標準出力に出力する方法について説明します。このドキュメントでは、インストールして実行できる Node.js サンプルアプリについても説明します。このアプリは Fastify ウェブフレームワークを使用し、指標、トレース、ログを生成するように構成されています。

計測について詳しくは、次のドキュメントをご覧ください。

手動計測と自動計測について

この言語について、OpenTelemetry は自動計測を、コードを変更せずにライブラリとフレームワークからテレメトリーを収集する手法と定義しています。ただし、モジュールをインストールし、環境変数を設定する必要があります。

このドキュメントでは、自動計測については説明しません。このトピックについては、Node の自動計測をご覧ください。

一般的な情報については、Node の OpenTelemetry 計測をご覧ください。

始める前に

Enable the Cloud Logging, Cloud Monitoring, and Cloud Trace APIs.

Enable the APIs

アプリを計測してトレース、指標、ログを収集する

アプリを計測して、トレースと指標データを収集し、構造化 JSON を標準出力に出力するには、このドキュメントの以降のセクションで説明する手順を実施します。

OpenTelemetry を構成する
OpenTelemetry 構成をプリロードするようにアプリを構成する
構造化ロギングを構成する
構造化ログを書き込む

OpenTelemetry を構成する

OpenTelemetry Node.js SDK のデフォルト構成では、OTLP プロトコルを使用してトレースをエクスポートします。また、トレースコンテキストの伝播に W3C トレースコンテキスト形式を使用するように OpenTelemetry を構成します。この構成により、トレース内でスパンが正しい親子関係を持つことが保証されます。

次のコードサンプルでは、OpenTelemetry を設定するための JavaScript モジュールを示します。

サンプル全体を表示するには、（その他）をクリックして、[GitHub で表示] を選択します。


diag.setLogger(
  new DiagConsoleLogger(),
  opentelemetry.core.getEnv().OTEL_LOG_LEVEL
);

const sdk = new opentelemetry.NodeSDK({
  instrumentations: getNodeAutoInstrumentations({
    // Disable noisy instrumentations
    '@opentelemetry/instrumentation-fs': {enabled: false},
  }),
  resourceDetectors: getResourceDetectorsFromEnv(),
  metricReader: getMetricReader(),
});

try {
  sdk.start();
  diag.info('OpenTelemetry automatic instrumentation started successfully');
} catch (error) {
  diag.error(
    'Error initializing OpenTelemetry SDK. Your application is not instrumented and will not produce telemetry',
    error
  );
}

// Gracefully shut down the SDK to flush telemetry when the program exits
process.on('SIGTERM', () => {
  sdk
    .shutdown()
    .then(() => diag.debug('OpenTelemetry SDK terminated'))
    .catch(error => diag.error('Error terminating OpenTelemetry SDK', error));
});

上記のコードサンプルでは、OTLP プロトコルを使用して指標をエクスポートするように OpenTelemetry を構成し、@opentelemetry/auto-instrumentations-node パッケージを使用して、使用可能なすべての Node.js の計測を構成しています。

アプリがシャットダウンする前に、保留中のすべてのテレメトリーがフラッシュされ、接続が正常に終了するように、SIGTERM ハンドラは shutdown を呼び出します。

詳細と構成オプションについては、OpenTelemetry Node.js 自動計測をご覧ください。

OpenTelemetry 構成をプリロードするようにアプリを構成する

構造化ログを書き込み、OpenTelemetry を使用して指標とトレースデータを収集するようにアプリを構成するには、Node.js --require フラグを使用して計測モジュールをプリロードするようにアプリの呼び出しを更新します。--require フラグを使用すると、アプリの起動前に OpenTelemetry が初期化されます。詳細については、OpenTelemetry Node.js スタートガイドをご覧ください。

次のコードサンプルは、--require フラグを渡す Dockerfile を示しています。

CMD node --require ./build/src/instrumentation.js build/src/index.js 2>&1 | tee /var/log/app.log

構造化ロギングを構成する

標準出力に書き込まれる JSON 形式のログにトレース情報を含めるには、構造化ログを JSON 形式で出力するようにアプリを構成します。Fastify は Pino ログフレームワークを使用し、各リクエストハンドラにロガーを提供します。次のコードサンプルは、JSON 構造化ログを出力するようにアプリを構成する Pino LoggerOptions オブジェクトを示しています。


// Expected attributes that OpenTelemetry adds to correlate logs with spans
interface LogRecord {
  trace_id?: string;
  span_id?: string;
  trace_flags?: string;
  [key: string]: unknown;
}

// https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#logseverity
const PinoLevelToSeverityLookup: Record<string, string | undefined> = {
  trace: 'DEBUG',
  debug: 'DEBUG',
  info: 'INFO',
  warn: 'WARNING',
  error: 'ERROR',
  fatal: 'CRITICAL',
};

export const loggerConfig = {
  messageKey: 'message',
  // Same as pino.stdTimeFunctions.isoTime but uses "timestamp" key instead of "time"
  timestamp(): string {
    return `,"timestamp":"${new Date(Date.now()).toISOString()}"`;
  },
  formatters: {
    log(object: LogRecord): Record<string, unknown> {
      // Add trace context attributes following Cloud Logging structured log format described
      // in https://cloud.google.com/logging/docs/structured-logging#special-payload-fields
      const {trace_id, span_id, trace_flags, ...rest} = object;

      return {
        'logging.googleapis.com/trace': trace_id,
        'logging.googleapis.com/spanId': span_id,
        'logging.googleapis.com/trace_sampled': trace_flags
          ? trace_flags === '01'
          : undefined,
        ...rest,
      };
    },
    // See
    // https://getpino.io/#/docs/help?id=mapping-pino-log-levels-to-google-cloud-logging-stackdriver-severity-levels
    level(label: string) {
      return {
        severity:
          PinoLevelToSeverityLookup[label] ?? PinoLevelToSeverityLookup['info'],
      };
    },
  },
} satisfies LoggerOptions;

前の構成では、アクティブなスパンに関する情報がログメッセージから抽出され、抽出された情報が JSON 構造化ログに属性として追加されます。これらの属性を使用して、ログをトレースに関連付けることができます。

logging.googleapis.com/trace: ログエントリに関連付けられているトレースのリソース名。
logging.googleapis.com/spanId: ログエントリに関連付けられているトレースのスパン ID。
logging.googleapis.com/trace_sampled: このフィールドの値は true または false にする必要があります。

これらのフィールドの詳細については、LogEntry 構造体をご覧ください。

Fastify で Pino 構成を使用するには、Fastify アプリの作成時にロガー構成オブジェクトを渡します。

// Create the Fastify app providing the Pino logger config
const fastify = Fastify({
  logger: loggerConfig,
});

構造化ログを書き込む

トレースにリンクする構造化ログを書き込むには、Fastify が提供する Pino ロガーを使用します。たとえば、次のステートメントは Logger.info() メソッドを呼び出す方法を示しています。

request.log.info({subRequests}, 'handle /multi request');

OpenTelemetry は、OpenTelemetry Context で現在アクティブなスパンのスパンコンテキストを Pino ログエントリに自動的に入力します。このスパンコンテキストは、構造化ロギングを構成するで説明されているように、JSON ログに含まれます。

テレメトリーを収集するように構成されたサンプルアプリを実行する

サンプルアプリでは、ログに JSON、指標とトレースに OTLP を使用し、さらに Fastify フレームワークを使用するなど、ベンダーに依存しない形式を使用しています。テレメトリーを Google Cloud にルーティングするため、このサンプルでは Google エクスポータで構成された OpenTelemetry Collector を使用します。このアプリには 2 つのエンドポイントがあります。

/multi エンドポイントは、handleMulti 関数によって処理されます。アプリの負荷生成ツールが /multi エンドポイントにリクエストを発行します。このエンドポイントは、リクエストを受信すると、ローカルサーバーの /single エンドポイントに 3～7 件のリクエストを送信します。

/**
 * handleMulti handles an http request by making 3-7 http requests to the /single endpoint.
 *
 * OpenTelemetry instrumentation requires no changes here. It will automatically generate a
 * span for the handler body.
 */
fastify.get('/multi', async request => {
  const subRequests = randInt(3, 8);
  request.log.info({subRequests}, 'handle /multi request');

  for (let i = 0; i < subRequests; i++) {
    await axios.get(`http://localhost:${port}/single`);
  }
  return 'ok';
});

/single エンドポイントは、handleSingle 関数によって処理されます。このエンドポイントは、リクエストを受信すると、少しの間スリープしてから、文字列で応答します。

/**
 * handleSingle handles an http request by sleeping for 100-200 ms. It writes the number of
 * milliseconds slept as its response.
 */
fastify.get('/single', async request => {
  // Sleep between 100-200 milliseconds
  const sleepMillis = randInt(100, 200);
  request.log.info({sleepMillis}, 'Going to sleep');
  await sleep(sleepMillis);
  return `slept ${sleepMillis}\n`;
});

アプリをダウンロードしてデプロイする

サンプルを実行するには、次の操作を行います。

In the Google Cloud console, activate Cloud Shell.

Activate Cloud Shell

At the bottom of the Google Cloud console, a Cloud Shell session starts and displays a command-line prompt. Cloud Shell is a shell environment with the Google Cloud CLI already installed and with values already set for your current project. It can take a few seconds for the session to initialize.

リポジトリのクローンを作成します。

git clone https://github.com/GoogleCloudPlatform/opentelemetry-operations-js

サンプルディレクトリに移動します。

cd opentelemetry-operations-js/samples/instrumentation-quickstart

サンプルをビルドして実行します。
```
docker compose up --abort-on-container-exit
```
Cloud Shell で実行していない場合は、認証情報ファイルを指す GOOGLE_APPLICATION_CREDENTIALS 環境変数を使用してアプリケーションを実行します。アプリケーションのデフォルト認証情報は、$HOME/.config/gcloud/application_default_credentials.json にある認証情報ファイルを提供します。
```
# Set environment variables
export GOOGLE_CLOUD_PROJECT="PROJECT_ID"
export GOOGLE_APPLICATION_CREDENTIALS="$HOME/.config/gcloud/application_default_credentials.json"
export USERID="$(id -u)"

# Run
docker compose -f docker-compose.yaml -f docker-compose.creds.yaml up --abort-on-container-exit
```

指標を表示する

サンプルアプリの OpenTelemetry 計測は、Metrics Explorer で表示可能な Prometheus 指標を生成します。

Prometheus/http_server_duration_milliseconds/histogram は、サーバーリクエストの所要時間を記録し、結果をヒストグラムに保存します。
Prometheus/http_client_duration_milliseconds/histogram は、クライアントリクエストの所要時間を記録し、結果をヒストグラムに保存します。

サンプルアプリによって生成された指標を表示する手順は次のとおりです。

Google Cloud コンソールで、[Metrics explorer] ページに移動します。
Metrics Explorer に移動

検索バーを使用してこのページを検索する場合は、小見出しが [Monitoring] の結果を選択します。
[指標] 要素の [指標を選択] メニューを開いてフィルタバーに「http_server」と入力し、サブメニューを使用して特定のリソースタイプと指標を選択します。
1. [有効なリソース] メニューで、[Prometheus Target] を選択します。
2. [有効な指標カテゴリ] メニューで、[Http] を選択します。
3. [ACTIVE METRICS] メニューで指標を選択します。
4. [適用] をクリックします。
データの表示方法を構成します。
指標の測定値が累積の場合、Metrics Explorer はアライメント期間ごとに測定データを自動的に正規化し、グラフに率を表示します。詳細については、種類、タイプ、変換をご覧ください。

2 つの counter 指標など、integer 値または double 値が測定されると、Metrics Explorer はすべての時系列を自動的に合計します。HTTP ルート /multi と /single のデータを表示するには、[集計] エントリの最初のメニューを [なし] に設定します。

グラフの構成の詳細については、Metrics Explorer 使用時の指標の選択をご覧ください。

トレースを表示する

トレースデータを表示するには、次の操作を行います。

Google Cloud コンソールで、[Trace エクスプローラ] ページに移動します。
[Trace エクスプローラ] に移動

このページは、検索バーを使用して見つけることもできます。
散布図で、URI が /multi のトレースを選択します。
[トレースの詳細] パネルのガントチャートで、/multi というラベルのスパンを選択します。

パネルが開き、HTTP リクエストに関する情報が表示されます。詳細には、メソッド、ステータスコード、バイト数、呼び出し元のユーザーエージェントが含まれます。
このトレースに関連付けられているログを表示するには、[ログとイベント] タブを選択します。

このタブには、個々のログが表示されます。ログエントリの詳細を表示するには、ログエントリを開きます。[ログを表示] をクリックし、ログエクスプローラを使用してログを表示することもできます。

Cloud Trace エクスプローラの使用方法について詳しくは、トレースを検索して調査するをご覧ください。

ログを表示する

ログエクスプローラではログを調査できます。また、関連するトレース（存在する場合）を確認することもできます。

Google Cloud コンソールで、[ログエクスプローラ] ページに移動します。
[ログエクスプローラ] に移動

検索バーを使用してこのページを検索する場合は、小見出しが「Logging」の結果を選択します。
handle /multi request の説明を含むログを見つけます。

ログの詳細を表示するには、ログエントリを開きます。
「handle /multi request」メッセージを含むログエントリの [ トレース] をクリックし、[トレースの詳細表示] を選択します。

[トレースの詳細] パネルが開き、選択したトレースが表示されます。

ログエクスプローラの使用方法については、ログエクスプローラを使用してログを表示するをご覧ください。