ログとトレーシング：エージェントの挙動を観測可能にする

01TL;DR

• エージェントのログには「何を入力し、どのフェーズで、何を出力したか」の3要素を構造化して記録します。
• taskId を全ログに付与することで、1リクエストの全工程を後から再構築できます。
• OpenTelemetry のスパン（Span）を使うと、LLM呼び出しの親子関係とレイテンシを可視化できます。
• 個人情報を含む可能性がある入力は、ログ書き込み前にマスキングを通す設計を推奨します。
• サンプルコードはTypeScript（Node.js v22.x / @opentelemetry SDK v1.x系）で記述しています。

---

02はじめに

この記事の対象読者

• LLMを使ったエージェントを本番環境で運用しているエンジニア
• 「なぜこの応答になったのか」を後から追いたいが、何をログに残せばいいか迷っている人
• OpenTelemetry の名前は知っているが、LLM系の用途に応用したことがない人

TypeScript と Node.js の基礎的な扱いを前提にしています。 OpenTelemetry の基礎概念（トレース・スパン・エクスポーター）については本記事で簡単に説明しますが、詳細は公式ドキュメントを参照してください。

実行環境

• Node.js: v22.4.0
• TypeScript: v5.5.x
• @opentelemetry/sdk-node: v0.52.x
• @opentelemetry/api: v1.9.x
• @opentelemetry/exporter-trace-otlp-http: v0.52.x
• openai: v4.52.x（OpenAI API クライアント）

この記事で得られること

• 構造化ログの設計思想と、taskId・フェーズ・入出力を記録するパターン
• LLM呼び出しにOpenTelemetryのスパンを付与する実装例
• スパンの親子関係を利用した、エージェント内部の処理フロー可視化
• 個人情報・機密情報を含む入力をマスキングしてからログに書く手法
• 実際のトレースデータの読み方と、問題調査での活用ポイント

---

03なぜエージェントのObservabilityが難しいのか

通常のWebサーバーとの違い

Webサーバーのリクエストは、基本的に「入力 → 決定的な処理 → 出力」という流れで動きます。 同じ入力を渡せば同じ出力が返ることが多く、問題の再現性が高いです。

エージェントは少し異なります。 LLMの応答は確率的であり、同じ入力でも毎回少しずつ異なる出力が返ることがあります。 さらに、複数のツール呼び出しやサブエージェントへの委譲が連鎖するため、「どの段階の判断が問題だったのか」を追うのが難しくなります。

たとえば筆者たちが BizPlan（事業計画エージェント）の開発で経験した事例として、こんな状況があります。

ユーザーから「財務計画が前回と比べて異常に楽観的な数字になっている」という報告が来た。 しかし手元のコードをいくら見ても、数字を変えるようなロジックが見当たらない。 結局、LLMがコンテキストの途中にある「類似ケースの例示」を参照してしまっていたことが原因だった。 これを突き止めるまでに、ログがほぼ残っていなかったため、丸2日かかった。

この経験から、筆者たちはログ設計を「後から追える」ことを第一の目標として見直しました。 本記事はその設計思想と実装パターンをまとめたものです。

「後から追える」ために最低限必要なもの

最小限のログセットとして、筆者たちは以下の4要素を必須と考えています。

要素	説明	例
taskId	リクエスト全体を貫く一意のID	task_a1b2c3d4
フェーズ	処理のどのステップか	planning, tool_call, synthesis
入力	そのフェーズに渡った内容（マスキング後）	ユーザーメッセージ、ツール引数
出力	そのフェーズが返した内容	LLM応答、ツール結果

この4要素があれば、少なくとも「どのフェーズで何を処理したか」の時系列を再構築できます。 これにタイミング情報（開始・終了・レイテンシ）を加えると、パフォーマンス分析にも使えます。

---

04構造化ログの設計

非構造化ログが引き起こす問題

まず、よくある「とりあえず console.log で出しておく」アプローチを見てみます。

// 避けたいパターン
async function runAgent(userInput: string): Promise<string> {
  console.log("エージェント開始:", userInput);

  const plan = await createPlan(userInput);
  console.log("計画生成完了");

  const result = await executePlan(plan);
  console.log("実行完了:", result);

  return result;
}

このログには重大な欠点があります。 複数リクエストが並行処理されると、どの console.log がどのリクエストに対応するか判別できなくなります。 また、テキストの検索やフィルタリングが困難で、大量ログから特定リクエストだけを抽出する操作が非常に手間になります。

構造化ログの基本形

以下が、筆者たちが採用している構造化ログの型定義です。

// src/logger/types.ts

export type LogLevel = "debug" | "info" | "warn" | "error";

export type AgentPhase =
  | "request_received"
  | "planning"
  | "tool_call"
  | "tool_result"
  | "llm_call"
  | "llm_response"
  | "synthesis"
  | "response_sent";

export interface AgentLogEntry {
  /** リクエスト全体を貫く一意のID */
  taskId: string;
  /** ログの記録時刻（ISO 8601形式） */
  timestamp: string;
  /** ログレベル */
  level: LogLevel;
  /** 処理フェーズ */
  phase: AgentPhase;
  /** そのフェーズに渡った入力（マスキング済み） */
  input?: unknown;
  /** そのフェーズが返した出力 */
  output?: unknown;
  /** エラー情報 */
  error?: {
    name: string;
    message: string;
    stack?: string;
  };
  /** フェーズの処理時間（ミリ秒） */
  durationMs?: number;
  /** 任意の追加メタデータ */
  meta?: Record<string, unknown>;
}

次に、この型を使ったロガーの実装です。

// src/logger/agent-logger.ts

import { AgentLogEntry, AgentPhase, LogLevel } from "./types";

export class AgentLogger {
  private readonly taskId: string;
  private readonly outputStream: NodeJS.WritableStream;

  constructor(taskId: string, outputStream: NodeJS.WritableStream = process.stdout) {
    this.taskId = taskId;
    this.outputStream = outputStream;
  }

  log(
    level: LogLevel,
    phase: AgentPhase,
    options: Omit<AgentLogEntry, "taskId" | "timestamp" | "level" | "phase">
  ): void {
    const entry: AgentLogEntry = {
      taskId: this.taskId,
      timestamp: new Date().toISOString(),
      level,
      phase,
      ...options,
    };
    // JSON1行で出力するとログ収集基盤（Fluentd等）が扱いやすい
    this.outputStream.write(JSON.stringify(entry) + "\n");
  }

  info(phase: AgentPhase, options: Omit<AgentLogEntry, "taskId" | "timestamp" | "level" | "phase">): void {
    this.log("info", phase, options);
  }

  error(phase: AgentPhase, err: unknown, options?: Partial<AgentLogEntry>): void {
    const errorInfo =
      err instanceof Error
        ? { name: err.name, message: err.message, stack: err.stack }
        : { name: "UnknownError", message: String(err) };
    this.log("error", phase, { ...options, error: errorInfo });
  }
}

taskId の生成と伝播

taskId はリクエストの入口で1度だけ生成し、そのリクエストが関与するすべての処理に伝播させます。

// src/agent/task-context.ts

import { randomUUID } from "crypto";
import { AgentLogger } from "../logger/agent-logger";

export interface TaskContext {
  taskId: string;
  logger: AgentLogger;
  startedAt: Date;
}

export function createTaskContext(): TaskContext {
  const taskId = `task_${randomUUID().replace(/-/g, "").slice(0, 12)}`;
  return {
    taskId,
    logger: new AgentLogger(taskId),
    startedAt: new Date(),
  };
}

HTTP リクエストのハンドラーでは、以下のように使います。

// src/server/handler.ts

import { createTaskContext } from "../agent/task-context";
import { runAgentPipeline } from "../agent/pipeline";

export async function handleRequest(userInput: string): Promise<string> {
  const ctx = createTaskContext();

  ctx.logger.info("request_received", {
    input: { userInput }, // マスキングは次節で説明
    meta: { userAgent: "web-client" },
  });

  try {
    const result = await runAgentPipeline(ctx, userInput);
    ctx.logger.info("response_sent", { output: { result } });
    return result;
  } catch (err) {
    ctx.logger.error("response_sent", err);
    throw err;
  }
}

実際の出力は以下のようになります。

{"taskId":"task_a1b2c3d4ef56","timestamp":"2026-06-11T09:00:00.123Z","level":"info","phase":"request_received","input":{"userInput":"来月の売上予測を出して"},"meta":{"userAgent":"web-client"}}
{"taskId":"task_a1b2c3d4ef56","timestamp":"2026-06-11T09:00:00.234Z","level":"info","phase":"planning","output":{"plan":["データ取得","予測計算","レポート生成"]}}
{"taskId":"task_a1b2c3d4ef56","timestamp":"2026-06-11T09:00:01.456Z","level":"info","phase":"tool_call","input":{"toolName":"get_sales_data","args":{"period":"last_3_months"}},"durationMs":1222}

taskId が全行に付与されているため、後から grep "task_a1b2c3d4ef56" するだけでそのリクエストの全工程が抽出できます。

---

05フェーズと入出力の記録

フェーズを意識したパイプライン設計

エージェントの処理を「フェーズ」という単位で区切り、各フェーズの境界でログを書く設計にすると、処理フローが追いやすくなります。

// src/agent/pipeline.ts

import { TaskContext } from "./task-context";
import { callLlm } from "./llm-client";
import { executeTool } from "./tool-executor";
import { maskInput } from "../logger/masking";

export async function runAgentPipeline(
  ctx: TaskContext,
  userInput: string
): Promise<string> {
  // フェーズ1: 計画の立案
  const planningStart = Date.now();
  ctx.logger.info("planning", { input: { userInput: maskInput(userInput) } });

  const plan = await callLlm(ctx, {
    systemPrompt: "ユーザーの要求を分解してステップのリストを返してください。",
    userMessage: userInput,
  });

  ctx.logger.info("planning", {
    output: { plan },
    durationMs: Date.now() - planningStart,
  });

  // フェーズ2: ツール呼び出し（計画に基づく）
  const toolResults: Record<string, unknown> = {};
  for (const step of plan.steps ?? []) {
    if (step.toolName) {
      const toolStart = Date.now();
      ctx.logger.info("tool_call", {
        input: { toolName: step.toolName, args: step.args },
      });

      const toolResult = await executeTool(step.toolName, step.args);

      ctx.logger.info("tool_result", {
        input: { toolName: step.toolName },
        output: { result: toolResult },
        durationMs: Date.now() - toolStart,
      });

      toolResults[step.toolName] = toolResult;
    }
  }

  // フェーズ3: 最終回答の合成
  const synthesisStart = Date.now();
  ctx.logger.info("synthesis", {
    input: { plan, toolResults: maskInput(toolResults) },
  });

  const finalResponse = await callLlm(ctx, {
    systemPrompt: "ツールの結果を踏まえて、ユーザーへの最終回答を生成してください。",
    userMessage: JSON.stringify({ originalInput: userInput, toolResults }),
  });

  ctx.logger.info("synthesis", {
    output: { response: finalResponse.content },
    durationMs: Date.now() - synthesisStart,
  });

  return finalResponse.content;
}

LLM呼び出しのログ記録

LLM呼び出しは専用のクライアント関数にまとめ、そこでログを一元管理するのが保守しやすい設計です。

// src/agent/llm-client.ts

import OpenAI from "openai";
import { TaskContext } from "./task-context";
import { maskInput } from "../logger/masking";

const openai = new OpenAI();

interface LlmCallOptions {
  systemPrompt: string;
  userMessage: string;
  model?: string;
}

interface LlmResponse {
  content: string;
  usage?: {
    promptTokens: number;
    completionTokens: number;
    totalTokens: number;
  };
}

export async function callLlm(
  ctx: TaskContext,
  options: LlmCallOptions
): Promise<LlmResponse> {
  const { systemPrompt, userMessage, model = "gpt-5.4-mini" } = options;
  const callStart = Date.now();

  // 入力をマスキングしてからログに書く
  ctx.logger.info("llm_call", {
    input: {
      model,
      systemPromptLength: systemPrompt.length,
      userMessage: maskInput(userMessage),
    },
  });

  const response = await openai.chat.completions.create({
    model,
    messages: [
      { role: "system", content: systemPrompt },
      { role: "user", content: userMessage },
    ],
  });

  const content = response.choices[0]?.message?.content ?? "";
  const usage = response.usage
    ? {
        promptTokens: response.usage.prompt_tokens,
        completionTokens: response.usage.completion_tokens,
        totalTokens: response.usage.total_tokens,
      }
    : undefined;

  ctx.logger.info("llm_response", {
    output: { content, usage },
    durationMs: Date.now() - callStart,
  });

  return { content, usage };
}

この設計にすることで、どのフェーズで何トークン消費し、レイテンシが何ミリ秒だったかが全LLM呼び出しで均一に記録されます。 後からコスト分析やレイテンシのボトルネック分析を行う際に、このデータが役立ちます。

---

06個人情報・機密情報のマスキング

なぜログを書く前にマスキングが必要か

エージェントへの入力にはしばしば個人情報が含まれます。 氏名・メールアドレス・電話番号・住所などです。 こうした情報をそのままログに書いてしまうと、ログ収集基盤がGDPR等の個人情報保護規制の対象になったり、ログが漏洩した際のリスクが高まります。

筆者たちの考えとしては、「ログは最初から安全な状態で書く」を原則にするのが、後から「マスキングが漏れていた」という事態を防ぐ上で確実です。 デバッグのためにマスキングを外したい場合は、開発環境専用のフラグで制御する設計にします。

マスキングの実装例

// src/logger/masking.ts

/**
 * 正規表現ベースのマスキングルール
 * 各ルールはパターンにマッチした部分を置換文字列で置換する
 */
interface MaskingRule {
  name: string;
  pattern: RegExp;
  replacement: string;
}

const DEFAULT_MASKING_RULES: MaskingRule[] = [
  {
    name: "email",
    // メールアドレスをマスク
    pattern: /[a-zA-Z0-9._%+-]+@[a-zA-Z0-9.-]+\.[a-zA-Z]{2,}/g,
    replacement: "[EMAIL]",
  },
  {
    name: "phone_jp",
    // 日本の電話番号（携帯・固定）をマスク
    pattern: /0\d{1,4}[-\s]?\d{1,4}[-\s]?\d{4}/g,
    replacement: "[PHONE]",
  },
  {
    name: "credit_card",
    // クレジットカード番号（16桁）をマスク
    pattern: /\b\d{4}[-\s]?\d{4}[-\s]?\d{4}[-\s]?\d{4}\b/g,
    replacement: "[CARD]",
  },
  {
    name: "postal_code_jp",
    // 日本の郵便番号をマスク
    pattern: /〒?\d{3}[-\s]?\d{4}/g,
    replacement: "[POSTAL]",
  },
];

/**
 * 文字列に対してマスキングルールを適用する
 */
export function maskString(
  value: string,
  rules: MaskingRule[] = DEFAULT_MASKING_RULES
): string {
  let result = value;
  for (const rule of rules) {
    result = result.replace(rule.pattern, rule.replacement);
  }
  return result;
}

/**
 * 任意の値（文字列・オブジェクト・配列）に対してマスキングを適用する
 * ネストされたオブジェクトに対しても再帰的に処理する
 */
export function maskInput(value: unknown): unknown {
  if (typeof value === "string") {
    return maskString(value);
  }
  if (Array.isArray(value)) {
    return value.map(maskInput);
  }
  if (value !== null && typeof value === "object") {
    return Object.fromEntries(
      Object.entries(value as Record<string, unknown>).map(([k, v]) => [k, maskInput(v)])
    );
  }
  return value;
}

動作確認として、以下のように試せます。

import { maskInput } from "./masking";

const testInput = {
  userName: "山田太郎",
  contact: {
    email: "yamada.taro@example.com",
    phone: "090-1234-5678",
  },
  message: "来月の見積もりを yamada.taro@example.com に送ってください",
};

console.log(JSON.stringify(maskInput(testInput), null, 2));

出力結果は以下の通りです。

{
  "userName": "山田太郎",
  "contact": {
    "email": "[EMAIL]",
    "phone": "[PHONE]"
  },
  "message": "来月の見積もりを [EMAIL] に送ってください"
}

氏名については、単語マッチでは誤検知が多いため、このサンプルではマスキング対象外にしています。 実際の運用では、要件や法的リスクの評価に応じてルールを追加・調整してください。

マスキングが難しいケース

正規表現マスキングには限界もあります。 たとえば「鈴木さんに連絡しておいて」という入力は、「鈴木さん」が人名であることを文脈なしに判定するのは難しいです。

こうした場合の対応として、筆者たちは以下のアプローチを状況に応じて組み合わせています。

• NERモデル（固有表現認識）を使ったマスキング。精度は上がるが処理コストが増す。
• 入力全体を「ユーザー提供データ」として扱い、ログに入力の長さと文字種のみを記録し、内容そのものは記録しない。
• ログ保存先のアクセス制御を強化し、ログ自体をセンシティブデータとして管理する。

どのアプローチが適切かは、サービスの性質と法的要件によって異なります。

---

07OpenTelemetryによるトレーシング

トレーシングとは何か

ログが「時点の記録」であるのに対し、トレーシングは「処理の流れの記録」です。

OpenTelemetry では、1つのリクエストを「トレース」と呼び、その中の個々の処理単位を「スパン（Span）」と呼びます。 スパンには開始時刻・終了時刻・属性・親子関係が記録されます。

トレース（1リクエスト全体）
└── スパン: handleRequest          [0ms ─────────────────── 2500ms]
    ├── スパン: planning           [10ms ──── 800ms]
    │   └── スパン: llm_call       [20ms ─── 780ms]
    ├── スパン: tool_call          [820ms ── 1200ms]
    └── スパン: synthesis          [1210ms ─────── 2490ms]
        └── スパン: llm_call       [1220ms ──────── 2480ms]

この可視化によって、「どのスパンでボトルネックが発生しているか」が一目でわかります。

OpenTelemetry SDKのセットアップ

まずパッケージをインストールします。

npm install \
  @opentelemetry/sdk-node \
  @opentelemetry/api \
  @opentelemetry/exporter-trace-otlp-http \
  @opentelemetry/resources \
  @opentelemetry/semantic-conventions

次に、アプリケーション起動時に1回だけ実行するセットアップファイルを作ります。

// src/telemetry/setup.ts

import { NodeSDK } from "@opentelemetry/sdk-node";
import { OTLPTraceExporter } from "@opentelemetry/exporter-trace-otlp-http";
import { Resource } from "@opentelemetry/resources";
import { SEMRESATTRS_SERVICE_NAME, SEMRESATTRS_SERVICE_VERSION } from "@opentelemetry/semantic-conventions";
import { SimpleSpanProcessor } from "@opentelemetry/sdk-trace-base";

export function initTelemetry(): NodeSDK {
  const exporter = new OTLPTraceExporter({
    // ローカル開発ではJaeger等のコレクターへ送る
    // 本番では環境変数で上書きする
    url: process.env.OTEL_EXPORTER_OTLP_ENDPOINT ?? "http://localhost:4318/v1/traces",
  });

  const sdk = new NodeSDK({
    resource: new Resource({
      [SEMRESATTRS_SERVICE_NAME]: "agent-service",
      [SEMRESATTRS_SERVICE_VERSION]: "1.0.0",
    }),
    spanProcessors: [new SimpleSpanProcessor(exporter)],
  });

  sdk.start();
  console.log("OpenTelemetry initialized");

  // プロセス終了時にエクスポーターをフラッシュする
  process.on("SIGTERM", () => {
    sdk.shutdown().then(() => process.exit(0));
  });

  return sdk;
}

アプリのエントリーポイントで最初に呼び出します。

// src/index.ts

// OpenTelemetryは他のモジュールより先に初期化する必要があります。
// ESMでは静的importはファイル先頭で一括評価されるため、
// 「importしてから関数を呼ぶ」方式では初期化順を保証できません。
// 代わりに、初期化処理を副作用として持つモジュールを最初にimportします。
import "./telemetry/setup-init";

// --- 以降は通常のアプリコード ---
import { handleRequest } from "./server/handler";
// ...

setup-init.ts は setup.ts の initTelemetry() を呼び出すだけのモジュールです。

// src/telemetry/setup-init.ts
import { initTelemetry } from "./setup";
initTelemetry();

スパンをエージェント処理に組み込む

@opentelemetry/api のトレーサーを使ってスパンを付与します。

// src/telemetry/tracer.ts

import { trace, Tracer } from "@opentelemetry/api";

export function getTracer(): Tracer {
  return trace.getTracer("agent-service", "1.0.0");
}

パイプラインにスパンを組み込んだ例です。

// src/agent/pipeline-with-tracing.ts

import { context, SpanStatusCode } from "@opentelemetry/api";
import { getTracer } from "../telemetry/tracer";
import { TaskContext } from "./task-context";
import { callLlmWithTracing } from "./llm-client-with-tracing";
import { executeTool } from "./tool-executor";
import { maskInput } from "../logger/masking";

export async function runAgentPipelineWithTracing(
  ctx: TaskContext,
  userInput: string
): Promise<string> {
  const tracer = getTracer();

  // ルートスパン: リクエスト全体
  return tracer.startActiveSpan("agent.pipeline", async (pipelineSpan) => {
    // taskId をスパン属性として記録しておくと、ログとトレースを紐付けやすい
    pipelineSpan.setAttribute("agent.task_id", ctx.taskId);
    pipelineSpan.setAttribute("agent.input_length", userInput.length);

    try {
      // 子スパン: 計画フェーズ
      const plan = await tracer.startActiveSpan("agent.planning", async (planSpan) => {
        ctx.logger.info("planning", { input: { userInput: maskInput(userInput) } });
        try {
          const result = await callLlmWithTracing(ctx, {
            systemPrompt: "ユーザーの要求を分解してステップのリストを返してください。",
            userMessage: userInput,
          });
          planSpan.setAttribute("agent.plan_steps", result.steps?.length ?? 0);
          planSpan.setStatus({ code: SpanStatusCode.OK });
          return result;
        } catch (err) {
          planSpan.setStatus({ code: SpanStatusCode.ERROR, message: String(err) });
          throw err;
        } finally {
          planSpan.end();
        }
      });

      // 子スパン: ツール呼び出し
      const toolResults: Record<string, unknown> = {};
      for (const step of plan.steps ?? []) {
        if (step.toolName) {
          await tracer.startActiveSpan(`agent.tool.${step.toolName}`, async (toolSpan) => {
            toolSpan.setAttribute("agent.tool_name", step.toolName);
            ctx.logger.info("tool_call", {
              input: { toolName: step.toolName, args: step.args },
            });
            try {
              const result = await executeTool(step.toolName, step.args);
              toolResults[step.toolName] = result;
              toolSpan.setStatus({ code: SpanStatusCode.OK });
            } catch (err) {
              toolSpan.setStatus({ code: SpanStatusCode.ERROR, message: String(err) });
              throw err;
            } finally {
              toolSpan.end();
            }
          });
        }
      }

      // 子スパン: 合成フェーズ
      const finalResponse = await tracer.startActiveSpan("agent.synthesis", async (synthSpan) => {
        try {
          const result = await callLlmWithTracing(ctx, {
            systemPrompt: "ツールの結果を踏まえて最終回答を生成してください。",
            userMessage: JSON.stringify({ originalInput: userInput, toolResults }),
          });
          synthSpan.setStatus({ code: SpanStatusCode.OK });
          return result;
        } catch (err) {
          synthSpan.setStatus({ code: SpanStatusCode.ERROR, message: String(err) });
          throw err;
        } finally {
          synthSpan.end();
        }
      });

      pipelineSpan.setStatus({ code: SpanStatusCode.OK });
      return finalResponse.content;
    } catch (err) {
      pipelineSpan.setStatus({ code: SpanStatusCode.ERROR, message: String(err) });
      ctx.logger.error("synthesis", err);
      throw err;
    } finally {
      pipelineSpan.end();
    }
  });
}

LLM呼び出しにスパンを付与する

LLM呼び出し専用のスパンを作り、モデル・トークン数・レイテンシを属性として記録します。

// src/agent/llm-client-with-tracing.ts

import OpenAI from "openai";
import { SpanStatusCode } from "@opentelemetry/api";
import { getTracer } from "../telemetry/tracer";
import { TaskContext } from "./task-context";
import { maskInput } from "../logger/masking";

const openai = new OpenAI();

interface LlmCallOptions {
  systemPrompt: string;
  userMessage: string;
  model?: string;
}

interface LlmResponse {
  content: string;
  steps?: Array<{ toolName?: string; args?: unknown }>;
  usage?: {
    promptTokens: number;
    completionTokens: number;
    totalTokens: number;
  };
}

export async function callLlmWithTracing(
  ctx: TaskContext,
  options: LlmCallOptions
): Promise<LlmResponse> {
  const tracer = getTracer();
  const { systemPrompt, userMessage, model = "gpt-5.4-mini" } = options;

  return tracer.startActiveSpan("llm.chat_completion", async (span) => {
    // OpenTelemetry Semantic Conventions for GenAI (2026年時点のドラフト仕様に準拠)
    span.setAttribute("gen_ai.operation.name", "chat");
    span.setAttribute("gen_ai.provider.name", "openai");
    span.setAttribute("gen_ai.request.model", model);
    span.setAttribute("agent.task_id", ctx.taskId);

    ctx.logger.info("llm_call", {
      input: {
        model,
        userMessage: maskInput(userMessage),
      },
    });

    try {
      const response = await openai.chat.completions.create({
        model,
        messages: [
          { role: "system", content: systemPrompt },
          { role: "user", content: userMessage },
        ],
      });

      const content = response.choices[0]?.message?.content ?? "";

      if (response.usage) {
        span.setAttribute("gen_ai.usage.input_tokens", response.usage.prompt_tokens);
        span.setAttribute("gen_ai.usage.output_tokens", response.usage.completion_tokens);
      }

      ctx.logger.info("llm_response", {
        output: {
          contentLength: content.length,
          usage: response.usage,
        },
      });

      span.setStatus({ code: SpanStatusCode.OK });

      // LLMがJSON形式でステップリストを返した場合はパースして steps に格納する
      let steps: Array<{ toolName?: string; args?: unknown }> | undefined;
      try {
        const parsed = JSON.parse(content);
        if (Array.isArray(parsed)) {
          steps = parsed;
        } else if (Array.isArray(parsed?.steps)) {
          steps = parsed.steps;
        }
      } catch {
        // テキスト応答の場合はパース不要
      }

      return {
        content,
        steps,
        usage: response.usage
          ? {
              promptTokens: response.usage.prompt_tokens,
              completionTokens: response.usage.completion_tokens,
              totalTokens: response.usage.total_tokens,
            }
          : undefined,
      };
    } catch (err) {
      span.setStatus({ code: SpanStatusCode.ERROR, message: String(err) });
      ctx.logger.error("llm_call", err, { meta: { model } });
      throw err;
    } finally {
      span.end();
    }
  });
}

---

08スパンの親子関係と処理フローの可視化

親子関係が生まれる仕組み

OpenTelemetry では、startActiveSpan を入れ子に呼び出すと自動的に親子関係が形成されます。 外側のスパンが親、内側のスパンが子です。

agent.pipeline            [taskId: task_a1b2c3d4ef56]
├── agent.planning
│   └── llm.chat_completion  [model: gpt-5.4-mini, total_tokens: 312]
├── agent.tool.get_sales_data
└── agent.synthesis
    └── llm.chat_completion  [model: gpt-5.4-mini, total_tokens: 894]

この構造があると、Jaeger や Grafana Tempo などの可視化ツールで「ウォーターフォール図」として表示できます。 どの処理がどの処理の中で行われ、それぞれが何ミリ秒かかったかが一目でわかります。

別サービス・別プロセスへのコンテキスト伝播

複数サービスをまたぐエージェント（たとえばオーケストレーターとサブエージェントが別プロセスの場合）では、HTTPヘッダーを介してトレースコンテキストを伝播させます。

// src/telemetry/propagation.ts

import { context, propagation, trace } from "@opentelemetry/api";

/**
 * 外部HTTPリクエストを送る際にトレースコンテキストをヘッダーに注入する
 */
export function injectTraceContext(headers: Record<string, string>): Record<string, string> {
  const carrier: Record<string, string> = { ...headers };
  propagation.inject(context.active(), carrier);
  return carrier;
}

/**
 * 受信したHTTPリクエストのヘッダーからトレースコンテキストを抽出する
 */
export function extractTraceContext(headers: Record<string, string>): ReturnType<typeof context.active> {
  return propagation.extract(context.active(), headers);
}

サブエージェントを呼び出す側の実装例です。

// src/agent/sub-agent-caller.ts

import { injectTraceContext } from "../telemetry/propagation";
import { getTracer } from "../telemetry/tracer";
import { SpanStatusCode } from "@opentelemetry/api";

export async function callSubAgent(taskId: string, input: unknown): Promise<unknown> {
  const tracer = getTracer();

  return tracer.startActiveSpan("sub_agent.call", async (span) => {
    span.setAttribute("agent.task_id", taskId);

    // 現在のトレースコンテキストをHTTPヘッダーに注入する
    const headers = injectTraceContext({
      "Content-Type": "application/json",
      "X-Task-Id": taskId,
    });

    try {
      const response = await fetch("https://sub-agent.example.internal/run", {
        method: "POST",
        headers,
        body: JSON.stringify({ input }),
      });

      if (!response.ok) {
        throw new Error(`Sub-agent returned ${response.status}`);
      }

      const result = await response.json();
      span.setStatus({ code: SpanStatusCode.OK });
      return result;
    } catch (err) {
      span.setStatus({ code: SpanStatusCode.ERROR, message: String(err) });
      throw err;
    } finally {
      span.end();
    }
  });
}

このように実装することで、オーケストレーターとサブエージェントがそれぞれ別プロセスで動いていても、1つのトレースとして可視化ツール上に表示されます。

---

09トレースの読み方と問題調査への活用

典型的な問題パターンとトレースでの見え方

実際の運用でよく遭遇する問題と、トレースデータでどう見えるかを整理します。

パターン1: LLM呼び出しのレイテンシが突出して長い

agent.pipeline           [0ms ─────────────────────── 8500ms]
├── agent.planning       [10ms ─ 200ms]
│   └── llm.call         [20ms ─ 190ms]   ← 正常（~170ms）
└── agent.synthesis      [210ms ──────────────────── 8490ms]
    └── llm.call         [220ms ─────────────────── 8480ms]   ← 異常（~8260ms）

agent.synthesis 内のLLM呼び出しが極端に長い場合、コンテキストが大きくなりすぎていることが原因の一つとして考えられます。 スパンの gen_ai.usage.input_tokens 属性を確認し、想定外のトークン数になっていないかを確認します。

（関連記事: コンテキストウィンドウ管理：長い対話で情報を失わない工夫）

パターン2: ツール呼び出しがエラーで落ちている

agent.pipeline           [0ms ──────── 1200ms]  ← ERROR
├── agent.planning       [10ms ─ 400ms]
└── agent.tool.get_data  [410ms ─ 1190ms]  ← ERROR

スパンのステータスが ERROR になっているスパンを見つけ、その属性とログを照合します。 taskId が一致するログエントリーをフィルタリングすると、エラーの詳細メッセージが確認できます。

パターン3: 同じLLMを何度も呼び出している

agent.pipeline           [0ms ──────────────────────────── 12000ms]
├── agent.planning       [10ms ─ 400ms]
│   └── llm.call × 1
├── agent.tool_call × 8  [各200ms ── 600ms]
└── agent.synthesis      [5000ms ─────────── 12000ms]
    └── llm.call × 6    ← 6回呼ばれている

synthesis フェーズで llm.call が6回発生しているのは、ループ処理の設計上の問題、またはリトライが連続発生している可能性があります。 （関連記事: エラー処理とリトライ設計：失敗からの復帰のさせ方）

taskId を使ったログとトレースの突き合わせ

スパンに agent.task_id 属性を付与しているため、ログとトレースを以下の手順で突き合わせられます。

1. 可視化ツール（Jaeger / Grafana Tempo）で問題のあるトレースを見つける。
2. そのトレースの agent.task_id 属性の値を取得する（例: task_a1b2c3d4ef56）。
3. ログ収集基盤（Elasticsearch / CloudWatch Logs / Datadog Logs）で taskId: "task_a1b2c3d4ef56" をキーにフィルタリングする。
4. 構造化ログの各エントリーから入力・出力・エラー詳細を読む。

これにより、トレースで「いつ・どこで問題が起きたか」を特定し、ログで「何が起きたか」を把握するという二段構えの調査ができます。

---

10ローカル開発環境でのトレース確認

Jaeger を使ったローカルでの可視化

開発中にトレースを手軽に確認するために、Jaeger をローカルで立ち上げる方法を紹介します。

Docker が使える環境であれば、以下のコマンドで起動できます。

docker run --rm \
  -p 16686:16686 \
  -p 4318:4318 \
  jaegertracing/all-in-one:1.58

• ポート 4318: OpenTelemetry Collector（OTLP over HTTP）の受け口
• ポート 16686: Jaeger のWeb UI

アプリを起動してリクエストを送ると、http://localhost:16686 でトレースが確認できます。

docker-compose.yml を使う場合は以下のように記述します。

# docker-compose.yml

services:
  agent-service:
    build: .
    environment:
      OTEL_EXPORTER_OTLP_ENDPOINT: http://jaeger:4318/v1/traces
    depends_on:
      - jaeger

  jaeger:
    image: jaegertracing/all-in-one:1.58
    ports:
      - "16686:16686"
      - "4318:4318"

ローカルでのログ確認

構造化ログをターミナルで読みやすくするために、jq コマンドを使うと便利です。

# アプリを起動してログをjqに流す
node dist/index.js | jq '.'

# 特定のtaskIdだけを抽出する
node dist/index.js | jq 'select(.taskId == "task_a1b2c3d4ef56")'

# エラーログだけを抽出する
node dist/index.js | jq 'select(.level == "error")'

# フェーズ別のdurationMsを集計する
node dist/index.js | jq -r '[.phase, .durationMs] | @tsv' | sort

ローカルでの開発中は、jq のフィルタリングで十分な場合が多いです。 ステージング・本番環境では、Elasticsearch + Kibana や Datadog Logs などの本格的なログ収集基盤と組み合わせることで、より高度な分析が可能になります。

---

11ログ設計でよくある落とし穴

落とし穴1: ログが多すぎて探せなくなる

「念のため全部ログに残す」という考え方で実装すると、1リクエストで数百行のログが出るようになり、かえって問題が追いにくくなることがあります。

筆者たちが目安にしているのは、「フェーズの境界でのみログを書く」という原則です。 フェーズ内のループや細かい処理は debug レベルで書き、通常環境では出力しないように設定します。

// 環境変数でログレベルを切り替える例
const MIN_LOG_LEVEL = (process.env.LOG_LEVEL ?? "info") as LogLevel;

const LOG_LEVEL_PRIORITY: Record<LogLevel, number> = {
  debug: 0,
  info: 1,
  warn: 2,
  error: 3,
};

export class AgentLogger {
  // ...（前述のコードと同一）

  log(level: LogLevel, phase: AgentPhase, options: Omit<AgentLogEntry, "taskId" | "timestamp" | "level" | "phase">): void {
    if (LOG_LEVEL_PRIORITY[level] < LOG_LEVEL_PRIORITY[MIN_LOG_LEVEL]) {
      return; // ログレベルが低い場合は出力しない
    }
    // ...
  }
}

落とし穴2: エラーログだけ残してコンテキストがわからない

エラーが起きたときだけログを書く設計では、「そのエラーの前に何をしていたか」が記録に残りません。 少なくとも request_received と直前のフェーズの info ログは必ず残す設計にすると、問題調査のコンテキストが確保されます。

落とし穴3: 非同期処理でtaskIdが混在する

Promise.all で複数の処理を並列実行するとき、グローバルな変数やシングルトンのロガーを使っていると、異なるタスクのtaskIdが混在したログが生成されることがあります。

これを避けるため、本記事のサンプルコードのように TaskContext を引数として明示的に渡す設計を推奨します。 Node.js の AsyncLocalStorage を使うとコンテキストをより透明に伝播させることもできますが、設計が複雑になるため、まずは明示的な引数渡しから始めるのが手堅いです。

---

12まとめ

エージェントのObservabilityを整備するにあたって、筆者たちが最も重要だと考えるのは「ログとトレースを後から突き合わせられる状態を作ること」です。

本記事で紹介した手法をまとめます。

• taskId をリクエストの入口で1度だけ生成し、全ログ・全スパンに付与します。
• フェーズ単位でログを書くことで、処理フローの時系列が再構築しやすくなります。
• OpenTelemetry のスパンを使うと、LLM呼び出しの親子関係とレイテンシが可視化できます。
• 個人情報はログ書き込み前に正規表現マスキングを通す設計にします。
• taskId を使いログとトレースを突き合わせると、「いつ・どこで」と「何が」を組み合わせた調査ができます。

すべてを一度に導入する必要はありません。 まず taskId 付きの構造化ログから始め、問題調査の手ごたえを感じながら徐々に拡張していくのが、筆者たちの経験上、持続しやすい進め方です。

---

13参考文献

• OpenTelemetry 公式ドキュメント（opentelemetry.io）
• OpenTelemetry JavaScript SDK（GitHub: open-telemetry/opentelemetry-js）
• OpenTelemetry Semantic Conventions for GenAI（GitHub: open-telemetry/semantic-conventions）
• Jaeger 公式ドキュメント（jaegertracing.io）
• OpenAI API リファレンス（platform.openai.com）