Go to Qiita Advent Calendar Top
LoginSignup
0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

@555hamano(Akr)

Model Context Protocol完全解説 30日間シリーズ - Day 20【MCP応用 #20】ログ・監視機能追加：MCP通信の可視化と問題発見手法

Posted at

はじめに

この記事は、QiitaのModel Context Protocol（以下、MCP）解説シリーズの第20回です。
今回は、MCPサーバーを本番環境で運用する上で不可欠な、ログ・監視機能の追加について解説します。これにより、MCP通信の状況を可視化し、問題が発生した際に迅速に原因を特定できるようになります。

💡 なぜログと監視が必要なのか？

開発中は問題なく動いていても、実際の運用ではさまざまな予期せぬ事態が発生します。

典型的な問題例

  • Toolsの実行失敗: 外部APIのダウンタイムや認証エラー
  • Resourcesへのアクセス遅延: 大容量ファイルの読み込み遅延やネットワークの問題
  • JSON-RPC通信エラー: プロトコル違反やタイムアウト
  • LLMクライアントの予期せぬ挙動: ツールを誤って呼び出したり、存在しないリソースにアクセスしようとする

これらの問題を解決するには、「いつ」「何が起こったか」を正確に把握する必要があります。ログと監視は、そのための強力なツールです。

📝 実装：通信ログの記録

MCPサーバーの通信は、クライアント（Claude等のLLM）からのJSON-RPCメッセージと、それに対するサーバーのレスポンスです。これらのメッセージを記録することで、通信の履歴を追跡できます。

ステップ1：プロジェクトのセットアップ

TypeScriptを使用し、ロギングライブラリwinstonを追加します。

mkdir mcp-logging-example
cd mcp-logging-example
npm init -y
npm install @modelcontextprotocol/sdk winston
npm install --save-dev typescript ts-node @types/node
npx tsc --init

ステップ2：構造化ロギングの実装

src/logger.tsファイルを作成し、以下のコードを実装してください。

import winston from 'winston';
import { format } from 'winston';

// ログフォーマットの定義
const logFormat = format.combine(
  format.timestamp(),
  format.errors({ stack: true }),
  format.json()
);

// ロガーのセットアップ
export const logger = winston.createLogger({
  level: process.env.LOG_LEVEL || 'info',
  format: logFormat,
  defaultMeta: { service: 'mcp-server' },
  transports: [
    // コンソール出力
    new winston.transports.Console({
      format: format.combine(
        format.colorize(),
        format.simple()
      )
    }),
    // ファイル出力（エラーログ）
    new winston.transports.File({ 
      filename: 'logs/error.log', 
      level: 'error' 
    }),
    // ファイル出力（全ログ）
    new winston.transports.File({ 
      filename: 'logs/combined.log' 
    }),
  ],
});

// MCP固有のログ関数
export const mcpLogger = {
  toolCall: (toolName: string, args: any, duration?: number) => {
    logger.info('Tool called', {
      event: 'tool_call',
      toolName,
      args,
      duration
    });
  },
  
  toolError: (toolName: string, error: Error, args?: any) => {
    logger.error('Tool execution failed', {
      event: 'tool_error',
      toolName,
      error: error.message,
      stack: error.stack,
      args
    });
  },
  
  resourceAccess: (uri: string, duration?: number) => {
    logger.info('Resource accessed', {
      event: 'resource_access',
      uri,
      duration
    });
  },
  
  rpcMessage: (method: string, direction: 'incoming' | 'outgoing', data?: any) => {
    logger.debug('RPC message', {
      event: 'rpc_message',
      method,
      direction,
      data
    });
  }
};

ステップ3：MCPサーバーへのログ統合

src/server.tsファイルを作成し、ログ機能を統合します。

import { Server } from '@modelcontextprotocol/sdk/server/index.js';
import { StdioServerTransport } from '@modelcontextprotocol/sdk/server/stdio.js';
import {
  CallToolRequestSchema,
  ListToolsRequestSchema,
  ListResourcesRequestSchema,
  ReadResourceRequestSchema,
} from '@modelcontextprotocol/sdk/types.js';
import { logger, mcpLogger } from './logger.js';

class LoggingMCPServer {
  private server: Server;

  constructor() {
    this.server = new Server(
      {
        name: 'logging-example-server',
        version: '1.0.0',
      },
      {
        capabilities: {
          resources: {},
          tools: {},
        },
      }
    );

    this.setupHandlers();
  }

  private setupHandlers() {
    // ツール一覧の取得
    this.server.setRequestHandler(ListToolsRequestSchema, async () => {
      mcpLogger.rpcMessage('tools/list', 'incoming');
      
      return {
        tools: [
          {
            name: 'get_system_status',
            description: 'システムの状態を取得する',
            inputSchema: {
              type: 'object',
              properties: {},
            },
          },
          {
            name: 'search_database',
            description: 'データベースを検索する',
            inputSchema: {
              type: 'object',
              properties: {
                query: {
                  type: 'string',
                  description: '検索クエリ',
                },
              },
              required: ['query'],
            },
          },
        ],
      };
    });

    // ツールの実行
    this.server.setRequestHandler(CallToolRequestSchema, async (request) => {
      const startTime = Date.now();
      const { name: toolName, arguments: args } = request.params;

      try {
        mcpLogger.rpcMessage('tools/call', 'incoming', { toolName, args });

        let result;
        switch (toolName) {
          case 'get_system_status':
            result = await this.getSystemStatus();
            break;
          case 'search_database':
            result = await this.searchDatabase(args as { query: string });
            break;
          default:
            throw new Error(`Unknown tool: ${toolName}`);
        }

        const duration = Date.now() - startTime;
        mcpLogger.toolCall(toolName, args, duration);

        return {
          content: [
            {
              type: 'text',
              text: JSON.stringify(result),
            },
          ],
        };
      } catch (error) {
        const duration = Date.now() - startTime;
        mcpLogger.toolError(toolName, error as Error, args);
        
        return {
          content: [
            {
              type: 'text',
              text: `Error: ${(error as Error).message}`,
            },
          ],
          isError: true,
        };
      }
    });

    // リソース一覧の取得
    this.server.setRequestHandler(ListResourcesRequestSchema, async () => {
      mcpLogger.rpcMessage('resources/list', 'incoming');
      
      return {
        resources: [
          {
            uri: 'file://system.log',
            name: 'System Log',
            description: 'システムログファイル',
            mimeType: 'text/plain',
          },
        ],
      };
    });

    // リソースの読み取り
    this.server.setRequestHandler(ReadResourceRequestSchema, async (request) => {
      const startTime = Date.now();
      const { uri } = request.params;

      try {
        mcpLogger.rpcMessage('resources/read', 'incoming', { uri });

        // 実際の実装では、ここでファイルやAPIからデータを取得
        const content = await this.readResource(uri);
        
        const duration = Date.now() - startTime;
        mcpLogger.resourceAccess(uri, duration);

        return {
          contents: [
            {
              uri,
              mimeType: 'text/plain',
              text: content,
            },
          ],
        };
      } catch (error) {
        const duration = Date.now() - startTime;
        logger.error('Resource read failed', {
          event: 'resource_error',
          uri,
          error: (error as Error).message,
          duration
        });

        throw error;
      }
    });
  }

  private async getSystemStatus() {
    // システム状態を取得する処理
    return {
      status: 'healthy',
      timestamp: new Date().toISOString(),
      uptime: process.uptime(),
      memory: process.memoryUsage(),
    };
  }

  private async searchDatabase(args: { query: string }) {
    // デモ用：特定のクエリでエラーを発生させる
    if (args.query === 'fail') {
      throw new Error('データベース接続エラー: Connection timeout');
    }

    // 実際の検索処理をシミュレート
    await new Promise(resolve => setTimeout(resolve, 100));

    return {
      results: [
        { id: 1, title: `結果 for "${args.query}"`, score: 0.95 },
        { id: 2, title: `関連結果 for "${args.query}"`, score: 0.87 },
      ],
      total: 2,
      query: args.query,
    };
  }

  private async readResource(uri: string) {
    // リソース読み取り処理をシミュレート
    if (uri === 'file://system.log') {
      return 'System log content here...';
    }
    
    throw new Error(`Resource not found: ${uri}`);
  }

  async start() {
    const transport = new StdioServerTransport();
    await this.server.connect(transport);
    
    logger.info('MCP Server with logging started', {
      event: 'server_start',
      capabilities: this.server.getCapabilities()
    });
  }
}

// サーバー起動
async function main() {
  try {
    const server = new LoggingMCPServer();
    await server.start();
  } catch (error) {
    logger.error('Failed to start server', { error });
    process.exit(1);
  }
}

main();

📊 メトリクス収集の実装

ログに加えて、リアルタイムメトリクスも収集しましょう。

ステップ4：メトリクス収集機能の追加

src/metrics.tsファイルを作成します。

import { logger } from './logger.js';

interface MetricData {
  name: string;
  value: number;
  labels?: Record<string, string>;
  timestamp: number;
}

class MetricsCollector {
  private metrics: Map<string, MetricData[]> = new Map();
  private counters: Map<string, number> = new Map();

  // カウンターの増加
  incrementCounter(name: string, labels?: Record<string, string>) {
    const key = this.buildKey(name, labels);
    const current = this.counters.get(key) || 0;
    this.counters.set(key, current + 1);
    
    this.addMetric({
      name,
      value: current + 1,
      labels,
      timestamp: Date.now()
    });
  }

  // ゲージ値の記録
  recordGauge(name: string, value: number, labels?: Record<string, string>) {
    this.addMetric({
      name,
      value,
      labels,
      timestamp: Date.now()
    });
  }

  // ヒストグラム（実行時間など）の記録
  recordHistogram(name: string, value: number, labels?: Record<string, string>) {
    this.addMetric({
      name: `${name}_duration`,
      value,
      labels,
      timestamp: Date.now()
    });
  }

  private buildKey(name: string, labels?: Record<string, string>): string {
    const labelStr = labels ? 
      Object.entries(labels).map(([k, v]) => `${k}=${v}`).join(',') : '';
    return `${name}{${labelStr}}`;
  }

  private addMetric(metric: MetricData) {
    const metrics = this.metrics.get(metric.name) || [];
    metrics.push(metric);
    
    // 直近1時間のメトリクスのみ保持
    const oneHourAgo = Date.now() - (60 * 60 * 1000);
    const filtered = metrics.filter(m => m.timestamp > oneHourAgo);
    
    this.metrics.set(metric.name, filtered);
  }

  // メトリクスの出力（Prometheus形式）
  getPrometheusMetrics(): string {
    const lines: string[] = [];
    
    for (const [name, metrics] of this.metrics.entries()) {
      const latest = metrics[metrics.length - 1];
      if (latest) {
        const labelsStr = latest.labels ?
          Object.entries(latest.labels).map(([k, v]) => `${k}="${v}"`).join(',') : '';
        lines.push(`${name}{${labelsStr}} ${latest.value} ${latest.timestamp}`);
      }
    }
    
    return lines.join('\n');
  }

  // 統計情報の取得
  getStats(): Record<string, any> {
    const stats: Record<string, any> = {};
    
    for (const [name, metrics] of this.metrics.entries()) {
      if (metrics.length > 0) {
        const values = metrics.map(m => m.value);
        stats[name] = {
          count: metrics.length,
          latest: values[values.length - 1],
          avg: values.reduce((sum, v) => sum + v, 0) / values.length,
          min: Math.min(...values),
          max: Math.max(...values),
        };
      }
    }
    
    return stats;
  }

  // 定期的な統計出力
  startPeriodicLogging(intervalMs: number = 60000) {
    setInterval(() => {
      const stats = this.getStats();
      logger.info('Periodic metrics', { 
        event: 'metrics_snapshot',
        metrics: stats 
      });
    }, intervalMs);
  }
}

export const metrics = new MetricsCollector();

// MCP固有のメトリクスヘルパー
export const mcpMetrics = {
  toolCalled: (toolName: string) => 
    metrics.incrementCounter('mcp_tool_calls_total', { tool: toolName }),
    
  toolDuration: (toolName: string, duration: number) => 
    metrics.recordHistogram('mcp_tool_duration_ms', duration, { tool: toolName }),
    
  toolError: (toolName: string) => 
    metrics.incrementCounter('mcp_tool_errors_total', { tool: toolName }),
    
  resourceAccessed: (uri: string) => 
    metrics.incrementCounter('mcp_resource_access_total', { uri }),
    
  rpcMessage: (method: string, direction: 'in' | 'out') =>
    metrics.incrementCounter('mcp_rpc_messages_total', { method, direction }),
};

🔍 問題発見とトラブルシューティング

ログレベルの戦略的活用

// 本番環境：info以上のみ
logger.info('Tool executed successfully'); 

// 開発環境：debug情報も含める
logger.debug('Tool arguments validation', { args });

// エラー：スタックトレース付きで記録
logger.error('Tool execution failed', { 
  error: error.message, 
  stack: error.stack 
});

構造化ログによる効率的な検索

# 特定のツールのエラーのみ抽出
grep '"event":"tool_error"' logs/combined.log | grep '"toolName":"search_database"'

# レスポンス時間が長いリクエストを特定
grep '"duration"' logs/combined.log | awk '$0 ~ /"duration":[0-9]{4,}/' 

# 時系列での問題パターンの特定
jq -r '. | select(.event == "tool_error") | "\(.timestamp) \(.toolName) \(.error)"' logs/combined.log

📈 監視ダッシュボードの構築

Grafanaダッシュボード設定例

{
  "dashboard": {
    "title": "MCP Server Monitoring",
    "panels": [
      {
        "title": "Tool Call Rate",
        "type": "graph",
        "targets": [
          {
            "expr": "rate(mcp_tool_calls_total[5m])",
            "legendFormat": "{{tool}}"
          }
        ]
      },
      {
        "title": "Error Rate",
        "type": "graph", 
        "targets": [
          {
            "expr": "rate(mcp_tool_errors_total[5m]) / rate(mcp_tool_calls_total[5m])",
            "legendFormat": "Error Rate %"
          }
        ]
      },
      {
        "title": "Response Time Distribution",
        "type": "histogram",
        "targets": [
          {
            "expr": "histogram_quantile(0.95, mcp_tool_duration_ms_bucket)",
            "legendFormat": "95th percentile"
          }
        ]
      }
    ]
  }
}

🚀 アラート設定

重要なアラートルール

# prometheus-alerts.yml
groups:
  - name: mcp-server
    rules:
      - alert: HighErrorRate
        expr: rate(mcp_tool_errors_total[5m]) / rate(mcp_tool_calls_total[5m]) > 0.1
        for: 2m
        labels:
          severity: warning
        annotations:
          summary: "MCP Server error rate is above 10%"
          
      - alert: SlowResponseTime
        expr: histogram_quantile(0.95, mcp_tool_duration_ms_bucket) > 5000
        for: 5m
        labels:
          severity: critical
        annotations:
          summary: "95th percentile response time exceeded 5 seconds"

🎯 問題発見手法のまとめ

段階的トラブルシューティング

  1. Step 1: アラートの確認

    • 監視ダッシュボードでアラートが発生していないかチェック
    • メトリクスの異常値を特定

  2. Step 2: 構造化ログの検索

    • エラーログでスタックトレースを確認
    • 特定の時間範囲でのパターンを分析

  3. Step 3: 相関分析

    • 複数のメトリクスを組み合わせて原因を特定
    • 外部依存関係（API、データベース）の状態も確認

  4. Step 4: 再現とテスト

    • 問題を再現可能な最小限の条件を特定
    • 修正後の動作確認

ベストプラクティス

  • ログローテーション: 大量のログファイルでディスクが満杯にならないよう設定
  • 機密情報の除外: パスワードやAPIキーがログに出力されないよう注意
  • パフォーマンス: 本番環境では詳細すぎるログは避け、必要最小限に留める
  • 相関ID: リクエスト単位でユニークなIDを付与し、関連するログをトレース可能にする

これらの基本的なログと監視の仕組みをMCPサーバーに組み込むことで、問題に迅速に対応し、安定したサービス運用が可能になります。

次回は、Week 4：実戦レベル週間に突入します。Day 21では、環境に応じた柔軟な設定管理方法について解説します。お楽しみに！

0
0
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
0
0

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?