Skip to content
Effect日本語版ドキュメント

Effectにおけるトレーシングの導入

個々のサービスの挙動を理解するためにログやメトリクスは有用ですが、分散システムにおけるリクエストのライフサイクル全体を把握するには不十分です。

分散システムでは、リクエストが複数のサービスにまたがることができ、各サービスはリクエストを満たすために他のサービスに対して複数のリクエストを行うことがあります。このようなシナリオでは、リクエストのライフサイクルを複数のサービスに渡って追跡し、どのサービスがボトルネックになっているのか、リクエストがどこで最も時間を使っているのかを診断する必要があります。

スパン

スパンは作業や操作の単位を表します。リクエストが行った特定の操作を追跡し、その操作が実行されている間に何が起こったかを描写します。

一般的なスパンには以下の情報が含まれます：

  • 名前: 追跡している操作を説明します。

  • 時間関連データ: 操作が開始された時刻とその所要時間を測定するためのタイムスタンプ。

  • 構造化されたログメッセージ: 操作中に必要な情報を記録します。

  • メタデータ（属性）: 操作に関するコンテキストを提供する追加データ。

トレース

トレースは、リクエストがマルチサービスアーキテクチャ（マイクロサービスやサーバーレスアプリケーションなど）を通過する際に取られた経路を記録します。

トレーシングがないと、分散システムにおけるパフォーマンス問題の原因を特定することは困難です。

トレースは 1 つまたはそれ以上のスパンで構成されます。最初のスパンはルートスパンを表し、各ルートスパンはリクエストの開始から終了までを表現します。親スパンの下にあるスパンは、リクエスト中に何が起こるか（またはリクエストを構成するステップ）について、より深いコンテキストを提供します。

多くのオブザーバビリティバックエンドは、トレースを滝の図として視覚化します。以下のようになります：

サンプルトレース

滝の図は、ルートスパンとその子スパンの親子関係を示します。あるスパンが別のスパンをカプセル化すると、これはネストされた関係を表します。

スパンの作成

スパンを使用してエフェクトに計測を施すには、Effect.withSpan API を使用します。以下のように行います：

import { Effect } from "effect";


const program = Effect.void.pipe(Effect.delay("100 millis"));


const instrumented = program.pipe(Effect.withSpan("myspan"));

エフェクトに計測を施すことは、その型を変更しません。Effect<void>から始まり、最終的にもEffect<void>を得ることになります。

スパンの出力

次に、スパンをコンソールに出力します。これを実現するには、以下の特定のツールが必要です：

  • @effect/opentelemetry
  • @opentelemetry/sdk-metrics
  • @opentelemetry/sdk-trace-base
  • @opentelemetry/sdk-trace-node
  • @opentelemetry/sdk-trace-web

これらを配置することで、アプリケーション内のスパンを視覚化し、理解することができます。

以下は、必要な環境を設定し、スパンをコンソールに出力する方法を示すコードスニペットです：

import { Effect } from "effect";
import { NodeSdk } from "@effect/opentelemetry";
import {
  ConsoleSpanExporter,
  BatchSpanProcessor,
} from "@opentelemetry/sdk-trace-base";


const program = Effect.void.pipe(Effect.delay("100 millis"));


const instrumented = program.pipe(Effect.withSpan("myspan"));


const NodeSdkLive = NodeSdk.layer(() => ({
  resource: { serviceName: "example" },
  spanProcessor: new BatchSpanProcessor(new ConsoleSpanExporter()),
}));


Effect.runPromise(instrumented.pipe(Effect.provide(NodeSdkLive)));
/*
出力例:
{
  traceId: 'd0f730abfc366205806469596092b239',
  parentId: undefined,
  traceState: undefined,
  name: 'myspan',
  id: 'ab4e42592e7f1f7c',
  kind: 0,
  timestamp: 1697040012664380.5,
  duration: 2895.769,
  attributes: {},
  status: { code: 1 },
  events: [],
  links: []
}
*/

出力の内訳は以下の通りです：

フィールド説明
traceIdトレース全体のための一意の識別子で、リクエストや操作がアプリケーション内を移動する際のトレースを助けます。
parentId現在のスパンの親スパンを識別し、親スパンがない場合は出力においてundefinedとして表示され、ルートスパンとなります。
nameスパンの名前を説明し、追跡している操作を示します（例： “myspan”）。
id現在のスパンの一意の識別子で、トレース内の他のスパンと区別します。
timestampスパンが開始された時刻を表すタイムスタンプで、Unix エポックからのマイクロ秒で計測されます。
durationスパンの所要時間を示し、操作を完了するのにかかった時間（例：2895.769マイクロ秒）を表します。
attributesスパンには属性が含まれる場合があり、それは追加のコンテキストや操作に関する情報を提供するキーバリューペアです。この出力では、特定の属性がないことを示す空のオブジェクトとなっています。
statusスパンの状態に関する情報を提供するフィールドです。この場合、ステータスコードは 1 で、通常は OK 状態を示します（コード 2 はエラーステータスを示します）。
eventsスパンには、スパンのライフサイクル中の特定の瞬間の記録であるイベントを含めることができます。この出力では、特定のイベントが記録されていないことを示す空の配列となっています。
linksリンクは、このスパンを他のトレース内の他のスパンと関連付けるために使用されます。出力では、特定のリンクがないことを示す空の配列となっています。

エラーが発生したエフェクトの出力を確認してみましょう：

import { Effect } from "effect";
import { NodeSdk } from "@effect/opentelemetry";
import {
  ConsoleSpanExporter,
  BatchSpanProcessor,
} from "@opentelemetry/sdk-trace-base";


const program = Effect.fail("ああ、いけない！").pipe(
  Effect.delay("100 millis"),
  Effect.withSpan("myspan")
);


const NodeSdkLive = NodeSdk.layer(() => ({
  resource: { serviceName: "example" },
  spanProcessor: new BatchSpanProcessor(new ConsoleSpanExporter()),
}));


Effect.runPromiseExit(program.pipe(Effect.provide(NodeSdkLive))).then(
  console.log
);
/*
出力例:
{
  traceId: '760510a3f9a0881a09de990c87ec1cef',
  parentId: undefined,
  traceState: undefined,
  name: 'myspan',
  id: 'a528e38e82e848a5',
  kind: 0,
  timestamp: 1697091363002970.5,
  duration: 110371.664,
  attributes: {},
  status: { code: 2, message: 'エラー: ああ、いけない！' },
  events: [],
  links: []
}
{
  _id: 'Exit',
  _tag: 'Failure',
  cause: { _id: 'Cause', _tag: 'Fail', failure: 'ああ、いけない！' }
}
*/

注釈の追加

Effect.annotateCurrentSpan関数を利用することで、スパンに追加の情報を提供できます。このツールを使用すると、キーと値のペアを関連付けることができ、スパンの実行に関するより多くのコンテキストを提供します。

import { Effect } from "effect";
import { NodeSdk } from "@effect/opentelemetry";
import {
  ConsoleSpanExporter,
  BatchSpanProcessor,
} from "@opentelemetry/sdk-trace-base";


const program = Effect.void.pipe(
  Effect.delay("100 millis"),
  Effect.tap(() => Effect.annotateCurrentSpan("key", "value")),
  Effect.withSpan("myspan")
);


const NodeSdkLive = NodeSdk.layer(() => ({
  resource: { serviceName: "example" },
  spanProcessor: new BatchSpanProcessor(new ConsoleSpanExporter()),
}));


Effect.runPromise(program.pipe(Effect.provide(NodeSdkLive)));
/*
出力例:
{
  traceId: '869c9d74d9db14a4ba4393ca8e0f61db',
  parentId: undefined,
  traceState: undefined,
  name: 'myspan',
  id: '31eb49570d197f8d',
  kind: 0,
  timestamp: 1697045981663321.5,
  duration: 109563.353,
  attributes: { key: 'value' },
  status: { code: 1 },
  events: [],
  links: []
}
*/

ログをイベントとして扱う

ログは「スパンイベント」として知られるものに変換されます。これらのイベントは、アプリケーション内の出来事の構造化された情報とタイムラインを提供します。

import { Effect } from "effect";
import { NodeSdk } from "@effect/opentelemetry";
import {
  ConsoleSpanExporter,
  BatchSpanProcessor,
} from "@opentelemetry/sdk-trace-base";


const program = Effect.log("こんにちは").pipe(
  Effect.delay("100 millis"),
  Effect.withSpan("myspan")
);


const NodeSdkLive = NodeSdk.layer(() => ({
  resource: { serviceName: "example" },
  spanProcessor: new BatchSpanProcessor(new ConsoleSpanExporter()),
}));


Effect.runPromise(program.pipe(Effect.provide(NodeSdkLive)));
/*
出力例:
{
  traceId: 'ad708d58c15f9e5c7b5cca2eeb6838a2',
  parentId: undefined,
  traceState: undefined,
  name: 'myspan',
  id: '4353fd47423e786a',
  kind: 0,
  timestamp: 1697043230170724.2,
  duration: 112052.514,
  attributes: {},
  status: { code: 1 },
  events: [
    {
      name: 'こんにちは',
      attributes: { 'effect.fiberId': '#0', 'effect.logLevel': 'INFO' },
      time: [ 1697043230, 280923805 ],
      droppedAttributesCount: 0
    }
  ],
  links: []
}
*/

スパンにはイベントが含まれることがあり、それはスパンのライフサイクル中の特定の瞬間の記録です。この出力には、名前が'こんにちは'という 1 つのイベントが含まれています。それに伴う属性、たとえば'effect.fiberId'や'effect.logLevel'は、ログされたイベントに関する情報を提供します。timeフィールドは、イベントが発生した時刻を表します。

スパンのネスト

スパンはネストすることができ、操作の階層を作り出します。この概念を以下のコードで示します：

import { Effect } from "effect";
import { NodeSdk } from "@effect/opentelemetry";
import {
  ConsoleSpanExporter,
  BatchSpanProcessor,
} from "@opentelemetry/sdk-trace-base";


const child = Effect.void.pipe(
  Effect.delay("100 millis"),
  Effect.withSpan("child")
);


const parent = Effect.gen(function* () {
  yield* Effect.sleep("20 millis");
  yield* child;
  yield* Effect.sleep("10 millis");
}).pipe(Effect.withSpan("parent"));


const NodeSdkLive = NodeSdk.layer(() => ({
  resource: { serviceName: "example" },
  spanProcessor: new BatchSpanProcessor(new ConsoleSpanExporter()),
}));


Effect.runPromise(parent.pipe(Effect.provide(NodeSdkLive)));
/*
出力例:
{
  traceId: '92fe81f1454d9c099198568cf867dc59',
  parentId: 'b953d6c7d37ad93d',
  traceState: undefined,
  name: 'child',
  id: '2fd19c8c23ebc7e8',
  kind: 0,
  timestamp: 1697043815321888.2,
  duration: 106536.264,
  attributes: {},
  status: { code: 1 },
  events: [],
  links: []
}
{
  traceId: '92fe81f1454d9c099198568cf867dc59',
  parentId: undefined,
  traceState: undefined,
  name: 'parent',
  id: 'b953d6c7d37ad93d',
  kind: 0,
  timestamp: 1697043815292133.2,
  duration: 149724.295,
  attributes: {},
  status: { code: 1 },
  events: [],
  links: []
}
*/

ご覧の通り、b953d6c7d37ad93dの値は、これらのスパン間の親子関係を維持する上で重要な役割を果たしています。スパンがネストされ、トレースを作成することで、開発者がアプリケーション内の操作のフローと階層を理解するのに役立ちます。

チュートリアル: Docker、Prometheus、Grafana、Tempo を使ったトレースの視覚化

このチュートリアルでは、サンプルとして計測された Node.js アプリケーションを使用してトレースをシミュレーションおよび視覚化する方法を説明します。Docker、Prometheus、Grafana、Tempo を使用してトレースを作成、収集、および視覚化します。

ツールの説明

使用するツールを簡単に理解してみましょう：

  • Docker: Docker を使用すると、アプリケーションをコンテナ内で実行できます。コンテナは、アプリケーションがホストシステムに関係なく一貫して実行できる軽量で隔離された環境のようなものです。これは仮想マシンのようなものですが、より効率的です。

  • Prometheus: Prometheus は、監視およびアラートツールキットであり、アプリケーションに関するメトリクスやデータを収集し、後で分析するために保存します。これにより、パフォーマンスの問題を特定し、アプリケーションの挙動を理解するのに役立ちます。

  • Grafana: Grafana は、視覚化および分析プラットフォームです。アプリケーションのデータを視覚化するための美しくインタラクティブなダッシュボードを作成するのに役立ちます。Prometheus によって収集されたメトリクスをグラフィカルに表現するのに使用できます。

  • Tempo: Tempo は分散トレーシングシステムであり、リクエストがアプリケーションを通過する際の流れをトレースできます。リクエストがどのように処理されるかの洞察を提供し、アプリケーションのデバッグおよび最適化に役立ちます。

Docker の取得

Docker を取得するには、次の手順に従います：

  1. https://www.docker.com/の Docker 公式サイトにアクセスします。

  2. お使いのオペレーティングシステム（Windows または macOS）に合わせた Docker Desktop をダウンロードしてインストールします。

  3. インストール後、Docker Desktop を開き、バックグラウンドで実行されます。

トレースのシミュレーション

次に、サンプル Node.js アプリケーションを使用してトレースをシミュレートします。必要なコンポーネントの設定をガイドします。

  1. Docker ファイルのダウンロード。必要な Docker ファイルをダウンロードします：docker.zip。

  2. Docker のセットアップ。ダウンロードしたファイルを解凍し、ターミナルまたはコマンドプロンプトで/docker/localディレクトリに移動して、次のコマンドを実行して必要なサービスを起動します：

    Terminal window
    docker-compose up

  3. トレースのシミュレーション。以下のサンプルコードを Node.js 環境で実行します。このコードは一連のタスクをシミュレートし、トレースを生成します。

    実行する前に、effectの最新バージョンに加えて追加のライブラリをインストールする必要があります。必要なライブラリは次のとおりです：

    • @effect/opentelemetry
    • @opentelemetry/exporter-trace-otlp-http
    • @opentelemetry/sdk-trace-node
    • @opentelemetry/sdk-trace-web
    import { Effect } from "effect";
    import { NodeSdk } from "@effect/opentelemetry";
    import { BatchSpanProcessor } from "@opentelemetry/sdk-trace-base";
    import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http";
    

    // サブタスクの可能性があるタスクをシミュレートする関数
    const task = (
      name: string,
      delay: number,
      children: ReadonlyArray<Effect.Effect<void>> = []
    ) =>
      Effect.gen(function* () {
        yield* Effect.log(name);
        yield* Effect.sleep(`${delay} millis`);
        for (const child of children) {
          yield* child;
        }
        yield* Effect.sleep(`${delay} millis`);
      }).pipe(Effect.withSpan(name));
    

    const poll = task("/poll", 1);
    

    // タスクとサブタスクを含むプログラムを作成
    const program = task("client", 2, [
      task("/api", 3, [
        task("/authN", 4, [task("/authZ", 5)]),
        task("/payment Gateway", 6, [task("DB", 7), task("Ext. Merchant", 8)]),
        task("/dispatch", 9, [
          task("/dispatch/search", 10),
          Effect.all([poll, poll, poll], { concurrency: "inherit" }),
          task("/pollDriver/{id}", 11),
        ]),
      ]),
    ]);
    

    const NodeSdkLive = NodeSdk.layer(() => ({
      resource: { serviceName: "example" },
      spanProcessor: new BatchSpanProcessor(new OTLPTraceExporter()),
    }));
    

    Effect.runPromise(
      program.pipe(
        Effect.provide(NodeSdkLive),
        Effect.catchAllCause(Effect.logError)
      )
    );
    /*
    出力:
    timestamp=... level=INFO fiber=#0 message=client
    timestamp=... level=INFO fiber=#0 message=/api
    timestamp=... level=INFO fiber=#0 message=/authN
    timestamp=... level=INFO fiber=#0 message=/authZ
    timestamp=... level=INFO fiber=#0 message="/payment Gateway"
    timestamp=... level=INFO fiber=#0 message=DB
    timestamp=... level=INFO fiber=#0 message="Ext. Merchant"
    timestamp=... level=INFO fiber=#0 message=/dispatch
    timestamp=... level=INFO fiber=#0 message=/dispatch/search
    timestamp=... level=INFO fiber=#3 message=/poll
    timestamp=... level=INFO fiber=#4 message=/poll
    timestamp=... level=INFO fiber=#5 message=/poll
    timestamp=... level=INFO fiber=#0 message=/pollDriver/{id}
    */

  4. トレースの視覚化。次に、ウェブブラウザを開いてhttp://localhost:3000/exploreにアクセスします。ウェブページに生成されたTrace IDが表示されます。それをクリックするとトレースの詳細が見れます。

    Grafana Tempoでのトレース

これで完了です！Docker、Prometheus、Grafana、Tempo を使用してトレースをシミュレートし、視覚化しました。これらのツールを使用して、アプリケーションのパフォーマンスや挙動について監視、分析、および洞察を得ることができます。