分散トレーシングで Backend For Frontend サーバの見通しを良くする

Photo by Kent Pilcher on Unsplash

こんにちは。Wantedly Visit のフロントエンドエンジニアをしている山田 (GitHub: yamadayuki) です。本記事では Node.js で実装されたサーバの分散トレーシング対応について紹介します。

先日公開された記事で紹介されていますが、Wantedly では GraphQL を導入しています。

上記記事で詳しく紹介されていますが、GraphQL を用いた Backend For Frontend サーバ (BFF) では複数のバックエンドサービスに REST API や gRPC による RPC でリソースを取得したり更新をしたりしています。

この BFF と他の Microservices の間の結合部分の observability を担保しないことには開発の効率が落ち、場合によっては障害時の原因調査が難しくなるのが容易に想像できます。僕たち Wantedly の BFF では "/graphql" のような単一のエンドポイントに様々な種類のリクエストが呼び出されるので、どの query / mutation が呼び出された時にどれくらいのレイテンシなのか、この時どのサービスにどんなリクエストが送られているのか等を計測・可視化しておかなければなりません。

今回 Node.js で実装された BFF のサーバの observability を担保するために分散トレーシングを対応しました。

分散トレーシングの概要

分散トレーシングはある一つのリクエストを起点として、それに関与する様々な操作の因果関係を理解可能な形に落とし込むテクニックの一つです。

上の図はある機能の Trace を簡単に示した図になります。ここからわかることは、ある機能はどのようなサービスやミドルウェアに依存しているか、どの順序で呼び出されるか、それぞれの操作にどれくらいの時間がかかるか、そしてそれらの操作が失敗しているのかどうかなどがわかるようになります。

簡単に分散トレーシングの terminology を説明すると以下のようになります。

• Trace とはあるリクエストの開始から終了までに実行された操作の集まりである。
• Trace は複数の Span を持つことができる。その Span が実行された操作を示す。
• Span は木構造のようにネストすることができる。このネストがそれぞれの操作の因果関係を示す。
• Span は関数呼び出しや HTTP や gRPC のようなリモートプロシージャコール (RPC) などにより生成される。
• Span は名前、開始時間と終了時間を持っている。また任意のアノテーションを持つことができる。

このようなメトリクスを取得する手法として確立されたのが OpenCensus になります。今回は Node.js のサーバを主眼に話を進めていくので、利用するのは OpenCensus の Node.js 実装になります。

OpenCensus の Node.js 実装

OpenCensus の Node.js 実装については次の GitHub リポジトリで開発されています。

opencensus-node は lerna を利用し monorepo アーキテクチャで管理されていて、複数のパッケージに分かれて実装されています。このリポジトリで提供されているパッケージは大体以下のように分類されます。

• Trace のデータを取得する plugin (a.k.a. instrumentation)
• • HTTP や gRPC の情報をアノテーションとして Span に載せる
  • e.g. @opencensus/instrumentation-http / @opencensus/instrumentation-grpc
• Trace のデータを収集し伝搬する部分 (a.k.a. propagation)
• • サーバ間で伝搬するためにフォーマットに合わせて serialize / deserialize する
  • e.g. @opencensus/propagation-tracecontext / @opencensus/propagation-b3
• Trace のデータをログ収集や可視化ツールに書き出す部分 (a.k.a. exporter)
• • in-coming なリクエストや out-going なリクエストが発生した時などにサービスに export する
  • e.g. @opencensus/exporter-zipkin / @opencensus/exporter-stackdriver
• コアのロジックやそれぞれのパッケージをひとまとめにして使えるようにしたパッケージ
• • e.g. @opencensus/core / @opencensus/nodejs

それぞれのパッケージを組み合わせたりデフォルトで全ての plugin が有効になっているパッケージを利用したりして分散トレーシングをサポートできます。リポジトリの examples には色々なパターンの例が用意されていて、自分でパッケージを組み合わせる時に参考にすることができます。

ちなみに現時点ではほとんどのメンテナが OpenTelemetry の実装に取り掛かっているため、そこまで活発にメンテナンスされているというわけではありません。Security Patch がある場合に更新される方針です。
OpenTelemetry の方にも OpenCensus と同様の機能を後方互換性を保ちながら機能追加されていきます。これからは OpenTelemetry の対応に期待です。

Wantedly での利用例

ここからは上記で示したパッケージ等をどのように利用しながら分散トレーシングを対応するのか実装について例示しつつ、どのように GraphQL サーバの単一エンドポイント (POST /graphql) のトレーシングをしているのか紹介します。

まず初めに @opencensus/core と @opencensus/nodejs-base をインストールします。@opencensus/nodejs-base とは別に @opencensus/nodejs というパッケージが提供されていますが、それには全ての plugin が導入されています。しかし僕たち Wantedly での利用シーンには余分な plugin が導入されているためここでは @opencensus/nodejs-base というパッケージを利用します。

$ yarn add @opencensus/core @opencensus/nodejs-base

そして tracer オブジェクトを管理する Tracing クラスを実装していきます。

import { CoreTracer, Tracer } from "@opencensus/core";
import { TracingBase } from "@opencensus/nodejs-base";

class Tracing extends TracingBase {
  public readonly tracer: Tracer;

  constructor() {
    super([]); // Default list of target modules to be instrumented
    this.tracer = new CoreTracer();
  }
}

できました。簡単ですね。
ここで 8 行目の super に空配列を渡しています。この配列にはデフォルトの plugin を指定することができます。特に plugin の設定をする必要がない場合はこの配列に http などの文字列を渡すことで自動的に plugin を設定させることができます。この時 @opencensus/instrumentation-http などのパッケージも同様にインストールしてある必要があります。

import { CoreTracer, Tracer } from "@opencensus/core";
import { TracingBase } from "@opencensus/nodejs-base";

class Tracing extends TracingBase {
  public readonly tracer: Tracer;

  constructor() {
    super(["http"]); // You have to install `@opencensus/instrumentation-http`
    this.tracer = new CoreTracer();
  }
}

次に Trace を開始する関数を実装していきます。
僕たち Wantedly では伝搬する時のフォーマットとして Trace Context フォーマットを採用しているので @opencensus/propagation-tracecontext を使います。また export 先に Google Stackdriver を利用しているので @opencensus/exporter-stackdriver を使います。もしこの記事を参考にされる場合は適宜利用するツールに応じてパッケージを変更してください。
Wantedly で利用している GraphQL を用いた BFF の裏側は REST API などの普通の HTTP リクエストだけではなく gRPC のリクエストも存在しているので、対応するパッケージも一緒にインストールします。

$ yarn add \
    @opencensus/propagation-tracecontext \
    @opencensus/exporter-stackdriver \
    @opencensus/instrumentation-http \
    @opencensus/instrumentation-https \
    @opencensus/instrumentation-http2 \
    @opencensus/instrumentation-grpc

そして Trace を開始する関数として startTracing という関数を実装します。ここの関数の中で Propagation / Exporter / Plugin の設定をしていきます。

import { StackdriverTraceExporter } from "@opencensus/exporter-stackdriver";
import { TraceContextFormat } from "@opencensus/propagation-tracecontext";

function startTracing() {
  const propagation = new TraceContextFormat();

  const encoded = process.env.JSON_KEY_BASE64;
  const projectId = process.env.PROJECT_ID;
  let exporter;

  if (encoded && projectId) {
    const credentials = JSON.parse(Buffer.from(encoded, "base64").toString());
    exporter = new StackdriverTraceExporter({ projectId, credentials });
  }

  const tracing = Tracing.instance;

  tracing.start({
    propagation,
    exporter,
    plugins: {
      http: "@opencensus/instrumentation-http",
      https: "@opencensus/instrumentation-https",
      http2: "@opencensus/instrumentation-http2",
      grpc: "@opencensus/instrumentation-grpc",
    },
  });

  return tracing;
}

export const tracing = startTracing();

とりあえず実装できました。最初に Trace Context フォーマットの Propagation を初期化し、同様に Stackdriver への Exporter も初期化します。その後 Tracing.instance でシングルトンなオブジェクトが取得できるので、そのオブジェクトの start 関数を呼び出すことで分散トレーシングを開始することができます。この start 関数の引数として初期化した propagation / exporter を渡し、plugins というフィールドで利用する plugin と対応するパッケージ名を指定してあげることで設定は完了です。

@opencensus/exporter-stackdriver が提供する StackdriverTraceExporter はアプリケーションのデフォルト認証情報 (ADC) と呼ばれる方式を採用していて、環境変数に GOOGLE_APPLICATION_CREDENTIALS があればそれを利用します。この手法では GOOGLE_APPLICATION_CREDENTIALS にファイルパスが設定されている必要があるのですが、他の言語実装を見てみると Stackdriver に export する時の認証情報を別の方法で指定することができます。
Node.js 実装では当初必ず GOOGLE_APPLICATION_CREDENTIALS を要求するようになっていたのですが、社内の方針として ADC の方式を採用していないため credentials パラメータを受け取れるようにする Pull Request を送りました。無事にマージされたので StackdriverTraceExporter の初期化時に Base64 エンコードされた文字列を環境変数から取得・デコードし credentials に設定するようにしています。

ADC 方式とは別に credentials パラメータで StackdriverTraceExporter の認証情報を設定できるようにしたいという提案の Issue 。

上記の credentials パラメータの対応をした Pull Request 。

http や grpc の plugin の設定は @opencensus/nodejs-base の内部で plugin loader が存在し、指定された @opencensus/instrumentation-http のような文字列から自動的に plugin が有効になります。これら @opencensus/instrumentation-XXX の名前のついたパッケージでは shimmer を利用して module (e.g. http, grpc) が require されたタイミングで module や関数を wrap します。これにより Express.js や axios のようなライブラリを使っていても自動的に in-coming / out-going なリクエストの Tracing ができます。

ここからもう少し Trace の設定をしていきたいと思います。ウェブサーバの Healthcheck の一環としてサーバが生きているかどうか (Liveness) を測るために /ping というエンドポイントで GET リクエストを受けられる部分を必ず実装するとしましょう。この GET /ping は毎秒呼び出されウェブサーバが稼働しているかどうかを確認しますが、このエンドポイントは他のサーバにリクエストするわけではないので GET /ping は Trace の情報として残す必要はないですね。Trace のデータとしてノイズになり得る可能性があるので無視できるのであれば無視をしたいと思います。

function startTracing() {
  // ...

  const httpConfig = {
    ignoreIncomingPaths: ["/ping"],
  };

  tracing.start({
    propagation,
    exporter,
    plugins: {
      http: {
        module: "@opencensus/instrumentation-http",
        config: httpConfig,
      },
      https: {
        module: "@opencensus/instrumentation-https",
        config: httpConfig,
      },
      http2: {
        module: "@opencensus/instrumentation-http2",
        config: httpConfig,
      },
      grpc: "@opencensus/instrumentation-grpc",
    },
  });

  // ...
}

plugins に指定されるオブジェクトの value 部分には package 名の文字列とは別に `module` と `config` と呼ばれるフィールドを持つオブジェクトが渡せます。httpConfig オブジェクトを生成し、http / https / http2 の場合は httpConfig を config フィールドに渡します。この config には ignoreIncomingPaths / ignoreOutgoingUrls / applyCustomAttributesOnSpan を指定できます。 @opencensus/instrumentation-http の実装を利用して @opencensus/instrumentation-https / @opencensus/instrumentation-http2 も実装されているので同様の設定ができます。

interface HttpPluginConfig {
  ignoreIncomingPaths?: Array<IgnoreMatcher<IncomingMessage>>;
  ignoreOutgoingUrls?: Array<IgnoreMatcher<ClientRequest>>;
  applyCustomAttributesOnSpan?: HttpCustomAttributeFunction;
}

c.f. https://github.com/census-instrumentation/opencensus-node/blob/ef5712fd3b279b0e80494322231232047b06f9e6/packages/opencensus-instrumentation-http/src/types.ts#L33-L37

この ignoreIncomingPaths を使って /ping を無視することで対応は完了です。ignoreIncomingPaths に指定できるのは文字列、正規表現、url と IncommingMessage を引数に受け取って boolean を返す関数のどれかになります。今回は /ping にマッチすれば良いので文字列で /ping を指定しています。

次にいよいよ GraphQL のエンドポイントの詳しいメトリクスを Trace のデータとして付加していきます。GraphQL の query や mutation につけられた Operation Name を attribute として追加します。これによりどの query が実行された時にどれくらいの時間がかかっているか、どのサービスにどれくらいのリクエストが発行されているかを検索して見ることができるためです。

GraphQL の Operation Name を取得する関数を実装します。今回はウェブアプリケーションフレームワークとして Express.js をクライアントライブラリとして Apollo Client を利用した想定で実装します。 /graphql のエンドポイントが呼び出された時に in-comming なリクエストの body から Operation Name を取得します。ただしウェブアプリケーションフレームワークやクライアントライブラリによって Operation Name の取得の仕方が変わります。

import { Request } from "express";

function getOperationName(req: Request): string | undefined {
  if (req.baseUrl === "/graphql" && req.method === "POST") {
    return req.body.operationName;
  }
}

今回は Request オブジェクト (req) の body から operationName が取得できます。 /graphql のエンドポイントに POST メソッドのリクエストがあった場合は operationName を取得します。

次にこの関数を利用して Trace に attribute に付与します。先ほど追加した httpConfig の applyCustomAttributesOnSpan というフィールドに関数を与えることができます。その関数で Trace に載せる Span の attribute として operation_name を付与します。

const httpConfig = {
  ignoreIncomingPaths: ["/ping"],
  applyCustomAttributesOnSpan(span, req, _res) {
    if (req) {
      const operationName = getOperationName(req);
      if (operationName) {
        span.addAttribute("graphql.operation_name", operationName);
      }
    }
  },
};

applyCustomAttributesOnSpan は以下のようなシグネチャを持っています。

export interface HttpCustomAttributeFunction extends CustomAttributeFunction {
  (
    span: Span,
    request: ClientRequest | IncomingMessage,
    response: IncomingMessage | ServerResponse
  ): void;
}

c.f. https://github.com/census-instrumentation/opencensus-node/blob/ef5712fd3b279b0e80494322231232047b06f9e6/packages/opencensus-instrumentation-http/src/types.ts#L25-L31

express.Request 自体も IncomingMessage を継承しているので型エラーになるなどの問題はありません。 applyCustomAttributesOnSpan 関数の第一引数の span オブジェクトに addAttribute という関数が存在し、attribute 名とその値を渡すことで Trace にデータを付与できます。

今回は Operation Name のみを attribute に付与するだけでしたが、必要があれば同じような方法で Operation 全体を attribute に載せられると思います。observability をあげる目的では Trace のデータとして有用な情報を付与するようにしましょう。

もう少し情報を増やす取り組みをしていきます。
Trace のデータを伝搬していく Span context には一連のリクエストの流れが追えるように Trace ID が存在します。この Trace ID をアクセスログだったりエラー監視のコンテキストに挿入していたとして、この Trace ID で検索して Stackdriver などのサービス上で見れるようにします。
tracing.tracer というオブジェクトには registerSpanEventListener という関数が存在します。Span が開始するタイミングで実行される onStartSpan と Span が終了するタイミングで実行される onEndSpan を利用してフックを差し込むことができます。onStartSpan で Span に request_id という attribute 名で Trace ID を挿入します。

tracing.tracer.registerSpanEventListener({
  onStartSpan(span) {
    span.addAttribute("request_id", span.traceId);
  },
  onEndSpan(_span) {
    // noop
  },
});

また、実環境の情報として環境変数などから今動いている環境の情報などが取得できるのであれば attributes に追加した方が良いでしょう。例えばデプロイされているものと commit hash を一対一対応させている、かつその commit hash が環境変数として設定されているのであれば、環境変数から COMMIT_HASH を取得して attributes に追加してみましょう。
分散トレーシングを開始する start 関数のコンフィグの defaultAttributes というプロパティにオブジェクトを指定するとその key と value を利用してデフォルトの attributes が指定することができます。今回は実行中変わらない attribute なので defaultAttributes を利用して設定してみることにします。

tracing.start({
  // ...
  defaultAttributes: { commit_hash: process.env.COMMIT_HASH },
  // ...
});

このように attribute にいろいろな情報を付与することで、開発環境時でも Production に出した後でも調査をする際の選択肢を増やすことができます。Wantedly ではあらゆる Microservices が Kubernetes のクラスタの上で動いていて、どの namespace で動いているサーバなのか deploy した人は誰かなど、ある場合には重要な情報が実行環境の環境変数として存在しているのでそれを Trace の情報として挿入することにしています。これにより QA 環境で可視化した情報からデバッグのしやすさにつながっています。

以上で OpenCensus の対応をすることができました。ここまでで実装した startTracing の関数とその実行した戻り値の tracing オブジェクトを export し、ウェブサーバのエントリーポイントになるファイルで import することで、OpenCensus による分散トレーシングの対応ができます。全体を見たい方は次の Gist で見れるので参考にしてみてください。

https://gist.github.com/yamadayuki/203fe2772e57fd9b2f83522f4e33eea8

このように Wantedly では GraphQL を導入した BFF サーバの分散トレーシングを実現しています。この結果 Stackdriver では次のようにリクエストが可視化されるようになりました。

まとめ

Wantedly Visit のマイクロサービス化を進めている中で Web Frontend の開発スピードを下げないために如何にして BFF サーバの observability を担保するか、Wantedly では OpenCensus を利用して解決しています。GraphQL というツールを利用する上でのモニタリングやメトリクスの収集の一環としての分散トレーシングをサポートすることで、 BFF の後ろに立つ Microservices へのリクエストがしっかりと可視化できます。その結果開発中のデバッグのしやすさや問題が発生した時の情報収集に役立っています。