NodeJS 速習チュートリアル

Node.js ロギング

1. なぜロギングが重要なのか

効果的なロギングは、以下の理由から不可欠です。

  • デバッグ (Debugging): アプリケーション内部で何が起きているかを把握する
  • トラブルシューティング (Troubleshooting): プロダクション環境での問題を診断する
  • モニタリング (Monitoring): アプリケーションのヘルス状態とパフォーマンスを追跡する
  • 監査 (Auditing): コンプライアンスとセキュリティのために重要なイベントを記録する
  • アナリティクス (Analytics): アプリケーションの使用状況や挙動に関するデータを収集する

2. console による基本ロギング

Node.js には、基本的なロギングのための組み込み console メソッドが用意されています。

// 基本的なロギング
console.log('情報メッセージ');
console.error('エラーメッセージ');
console.warn('警告メッセージ');
console.debug('デバッグメッセージ');

// オブジェクトのログ出力
const user = { id: 1, name: 'John', roles: ['admin', 'user'] };
console.log('ユーザーオブジェクト:', user);

// 配列やオブジェクトをテーブル形式で出力
console.table([
  { name: 'John', age: 30, role: 'admin' },
  { name: 'Jane', age: 25, role: 'user' },
  { name: 'Bob', age: 40, role: 'guest' }
]);

// オペレーションの計測
console.time('operation');
// 何らかの処理を実行...
for (let i = 0; i < 1000000; i++) {
  // 処理を実行
}
console.timeEnd('operation'); // 出力例: operation: 4.269ms

// 関連するログのグループ化
console.group('ユーザー処理');
console.log('ユーザーデータを読み込み中...');
console.log('ユーザーを検証中...');
console.log('ユーザープロファイルを更新中...');
console.groupEnd();

// スタックトレースの出力
console.trace('トレースメッセージ');

2.1 console の制限事項

console は便利ですが、プロダクション環境での利用には大きな制限があります。

  • フィルタリングのためのログレベル(Log Levels)が組み込まれていない
  • ログローテーション(Log Rotation)やファイル管理機能がない
  • JSON のような構造化された出力フォーマットがない
  • モニタリングシステムとの統合が限定的

       注意:console メソッドは、ターミナルやファイルに出力する際に同期(Synchronous)処理となる場合があり、プロダクション環境で頻繁に使用するとパフォーマンスに影響を与える可能性があります。

3. 構造化ロギング (Structured Logging)

構造化ロギングは、ログメッセージをプレーンテキストではなく、データオブジェクト(通常は JSON)としてフォーマットします。これにより、パース(解析)、検索、分析が容易になります。

3.1 構造化ロギングのメリット

  • マシンが読み取りやすい一貫したフォーマット
  • 検索性とフィルタリングの向上
  • ログ集約ツール(Log Aggregation Tools)との統合が容易
  • メタデータによるコンテキスト(背景情報)の強化

構造化ログのエントリ例 (JSON)

{
  "timestamp": "2023-11-28T15:24:39.123Z",
  "level": "error",
  "message": "データベースへの接続に失敗しました",
  "service": "user-service",
  "context": {
    "requestId": "req-123-456",
    "userId": "user-789",
    "databaseHost": "db.example.com"
  },
  "error": {
    "name": "ConnectionError",
    "message": "接続が拒否されました",
    "stack": "..."
  }
}

4. 人気の Node.js ロギングライブラリ

4.1 Winston

Winston は、複数のトランスポート(出力先)をサポートする汎用性の高いロギングライブラリです。

Winston の基本セットアップ

const winston = require('winston');

// ロガーの作成
const logger = winston.createLogger({
  level: 'info',
  format: winston.format.json(),
  defaultMeta: { service: 'user-service' },
  transports: [
    // エラーログをファイルに書き出す
    new winston.transports.File({ filename: 'error.log', level: 'error' }),
    // すべてのログをファイルに書き出す
    new winston.transports.File({ filename: 'combined.log' }),
  ],
});

// プロダクション環境以外ではコンソールにも出力する
if (process.env.NODE_ENV !== 'production') {
  logger.add(new winston.transports.Console({
    format: winston.format.simple(),
  }));
}

// 使用例
logger.log('info', '分散ログファイルへようこそ!');
logger.info('分散ログを再度出力します');
logger.error('問題が発生しました', { additionalInfo: 'エラーの詳細情報' });

カスタムフォーマットの作成

const winston = require('winston');
const { format } = winston;
const { combine, timestamp, label, printf } = format;

// カスタムフォーマットの定義
const myFormat = printf(({ level, message, label, timestamp }) => {
  return `${timestamp} [${label}] ${level}: ${message}`;
});

const logger = winston.createLogger({
  format: combine(
    label({ label: 'API サービス' }),
    timestamp(),
    myFormat
  ),
  transports: [
    new winston.transports.Console(),
    new winston.transports.File({ filename: 'combined.log' })
  ]
});

logger.info('アプリケーションが起動しました');

4.2 Pino

Pino は、オーバーヘッドを最小限に抑え、最適なパフォーマンスを実現するために設計されたロガーです。

Pino の基本セットアップ

const pino = require('pino');

// ロガーの作成
const logger = pino({
  level: 'info',
  timestamp: pino.stdTimeFunctions.isoTime,
  base: { pid: process.pid, hostname: require('os').hostname() }
});

// 使用例
logger.info('アプリケーションが起動しました');
logger.info({ user: 'john' }, 'ユーザーがログインしました');
logger.error({ err: new Error('接続失敗') }, 'データベース接続エラー');

Express と Pino の連携

const express = require('express');
const pino = require('pino');
const pinoHttp = require('pino-http');

const app = express();
const logger = pino();
const httpLogger = pinoHttp({ logger });

// リクエストロギングミドルウェアを追加
app.use(httpLogger);

app.get('/', (req, res) => {
  req.log.info('ユーザーがホームページにアクセスしました');
  res.send('Hello World!');
});

app.get('/error', (req, res) => {
  req.log.error('問題が発生しました');
  res.status(500).send('エラーが発生しました!');
});

app.listen(8080, () => {
  logger.info('サーバーがポート 8080 で起動しました');
});

4.3 Bunyan

Bunyan は、ログを表示するための専用 CLI を備えた構造化ロギングライブラリです。

Bunyan の基本セットアップ

const bunyan = require('bunyan');

// ロガーの作成
const logger = bunyan.createLogger({
  name: 'myapp',
  streams: [
    {
      level: 'info',
      stream: process.stdout // 標準出力
    },
    {
      level: 'error',
      path: 'error.log' // エラーログをファイルへ
    }
  ],
  serializers: bunyan.stdSerializers
});

// 使用例
logger.info('アプリケーションが起動しました');
logger.info({ user: 'john' }, 'ユーザーがログインしました');
logger.error({ err: new Error('接続失敗') }, 'データベース接続エラー');

5. アプリケーションロギングのベストプラクティス

5.1 ログレベル (Log Levels)

ログメッセージの重要度や緊急度を分類するために、適切なログレベルを使用してください。

  • error: 注意が必要なランタイムエラー、例外、および失敗
  • warn: アプリケーションは停止しないが、潜在的な問題を示す警告
  • info: アプリケーションのイベントやマイルストーンに関する情報メッセージ
  • debug: 開発中に役立つ詳細な診断情報
  • trace: 非常に詳細なデバッグ情報(メソッドの開始/終了、変数の値など)

5.2 ログに記録すべきもの・すべきでないもの

ログに記録すべきこと:

  • アプリケーションの起動/停止イベント
  • 認証(Authentication)および認可(Authorization)イベント
  • API のリクエストとレスポンス
  • データベース操作とパフォーマンスメトリクス
  • コンテキスト情報を含むエラーと例外
  • リソース使用状況とパフォーマンス指標
  • 設定の変更

ログに記録してはいけないこと:

  • パスワード、トークン、API キー、その他の認証情報
  • 適切な保護措置がない個人情報(PII: Personally Identifiable Information)
  • クレジットカード番号、マイナンバー、その他の機密データ
  • セッション ID やクッキー(Cookies)
  • 暗号化キー

5.3 コンテキストを含めたロギング

トラブルシューティングを容易にするために、各ログエントリに関連するコンテキストを含めます。

const winston = require('winston');

// ベースロガーの作成
const logger = winston.createLogger({
  level: 'info',
  format: winston.format.json(),
  transports: [new winston.transports.Console()]
});

// リクエストコンテキストを持つチャイルドロガーを作成する関数
function createRequestLogger(req) {
  return logger.child({
    requestId: req.id,
    method: req.method,
    url: req.url,
    ip: req.ip,
    userId: req.user ? req.user.id : 'anonymous'
  });
}

// Express ミドルウェアでの使用例
app.use((req, res, next) => {
  req.id = generateRequestId();
  req.logger = createRequestLogger(req);
  req.logger.info('リクエストを受信しました');

  const start = Date.now();

  res.on('finish', () => {
    const duration = Date.now() - start;
    req.logger.info({
      statusCode: res.statusCode,
      duration: duration
    }, 'リクエストが完了しました');
  });

  next();
});

function generateRequestId() {
  return Date.now().toString(36) + Math.random().toString(36).substring(2);
}

6. ログの管理と分析

6.1 ログローテーション (Log Rotation)

ログファイルが肥大化しすぎないように、ログローテーションを実装します。

Winston でのデイリーローテーション設定

const winston = require('winston');
require('winston-daily-rotate-file');

const transport = new winston.transports.DailyRotateFile({
  filename: 'application-%DATE%.log',
  datePattern: 'YYYY-MM-DD',
  zippedArchive: true, // 圧縮保存
  maxSize: '20m',      // 1ファイルの最大サイズ
  maxFiles: '14d'      // 14日間保持
});

const logger = winston.createLogger({
  level: 'info',
  format: winston.format.json(),
  transports: [
    transport,
    new winston.transports.Console() // オプションでコンソールにも出力
  ]
});

logger.info('ローテーションされるログのテスト');

6.2 ログの集約管理 (Centralized Logging)

複数のサーバーやコンテナで実行されているアプリケーションの場合、分析を容易にするためにログを集約します。

Winston を使用した Elasticsearch への転送例

const winston = require('winston');
require('winston-elasticsearch');

const esTransportOpts = {
  level: 'info',
  clientOpts: {
    node: 'http://localhost:9200'
  },
  indexPrefix: 'app-logs'
};

const logger = winston.createLogger({
  transports: [
    new winston.transports.Elasticsearch(esTransportOpts),
    new winston.transports.Console()
  ]
});

logger.info('このログは Elasticsearch に送信されます');

人気のログ管理システム

  • ELK Stack (Elasticsearch, Logstash, Kibana): 包括的なロギングスタック
  • Graylog: セキュリティに重点を置いた中央集約型ログ管理
  • Fluentd / Fluent Bit: ログの収集とフォワーディング
  • Loki: 軽量なログ集約システム
  • 商用オプション: Datadog, New Relic, Splunk, LogDNA, Loggly

7. プロダクション環境でのロギング

7.1 パフォーマンスに関する考慮事項

  • 非同期ロギングの使用: イベントループをブロックしないようにします。
  • ログのバッファリング: パフォーマンス向上のためにログをメモリに一時蓄積します。
  • ログレベルの調整: プロダクション環境ではログの出力量を減らすためにレベルを調整します。
  • サンプリング: 高頻度で発生するログは、すべて記録せず一部をサンプリングします。

7.2 セキュリティに関する考慮事項

  • 機密データのサニタイズ: ロギング前に機密情報を除去または秘匿化します。
  • ログファイルの保護: 適切なアクセス権限を設定します。
  • 暗号化: ログを転送する際は暗号化を使用します。
  • 保持ポリシーの策定: 法規制(GDPR、HIPAAなど)に基づき、保持期間を管理します。

データサニタイズの例

const winston = require('winston');

// 機密データをサニタイズするためのカスタムフォーマット
const sanitizeFormat = winston.format((info) => {
  if (info.user && info.user.password) {
    info.user.password = '[秘匿済み]';
  }

  if (info.user && info.user.creditCard) {
    info.user.creditCard = '[秘匿済み]';
  }

  if (info.headers && info.headers.authorization) {
    info.headers.authorization = '[秘匿済み]';
  }

  return info;
});

const logger = winston.createLogger({
  format: winston.format.combine(
    sanitizeFormat(),
    winston.format.json()
  ),
  transports: [
    new winston.transports.Console()
  ]
});

// これらの機密データはログ出力時にサニタイズされます
logger.info({
  message: 'ユーザーが登録されました',
  user: {
    name: 'John',
    email: '[email protected]',
    password: 'secret123',
    creditCard: '4111-1111-1111-1111'
  },
  headers: {
    authorization: 'Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9...'
  }
});

8. ログによるデバッグ

8.1 Debug モジュール

debug モジュールは、環境変数によって条件付きでデバッグログを出力する軽量な手法を提供します。

const debug = require('debug');

// 名前付きデバッガーの作成
const dbDebug = debug('app:db');
const apiDebug = debug('app:api');
const authDebug = debug('app:auth');

// 使用例
dbDebug('データベースに接続しました');
apiDebug('/users への API リクエストを受信しました');
authDebug('ユーザーが認証されました: %o', { id: 123, roles: ['admin'] });

// 環境変数で有効化する例:
// DEBUG=app:* node app.js
// または
// DEBUG=app:db,app:auth node app.js

8.2 相関ID (Correlation IDs)

分散システムにおいて、複数のサービスをまたぐリクエストを追跡するために相関IDを使用します。

const express = require('express');
const { v4: uuidv4 } = require('uuid');
const winston = require('winston');
const app = express();

const logger = winston.createLogger({
  transports: [new winston.transports.Console()],
  format: winston.format.combine(
    winston.format.timestamp(),
    winston.format.json()
  )
});

// 相関IDミドルウェア
app.use((req, res, next) => {
  // リクエストヘッダーから取得、または新規生成
  const correlationId = req.headers['x-correlation-id'] || uuidv4();

  // レスポンスヘッダーにセット
  res.setHeader('x-correlation-id', correlationId);

  // リクエストオブジェクトに保持
  req.correlationId = correlationId;

  // リクエスト固有のチャイルドロガーを作成
  req.logger = logger.child({ correlationId });

  req.logger.info({
    message: 'リクエストを受信しました',
    method: req.method,
    url: req.url
  });

  next();
});

app.get('/', (req, res) => {
  req.logger.info('ホームページのリクエストを処理中');
  res.send('Hello World');
});

app.get('/error', (req, res) => {
  req.logger.error('リクエスト処理中にエラーが発生しました');
  res.status(500).send('Error');
});

app.listen(8080, () => {
  logger.info('サーバーがポート 8080 で起動しました');
});

9. まとめ

効果的なロギングは、Node.js アプリケーションのデバッグ、モニタリング、トラブルシューティングにおいて極めて重要です。

  • 検索や分析を容易にするために、JSON 形式の構造化ロギングを使用しましょう。
  • ニーズに合わせて Winston、Pino、Bunyan などの適切なライブラリを選択してください。
  • 適切なログレベルの使用、コンテキストの追加、機密データの保護といったベストプラクティスを適用しましょう。
  • プロダクション環境では、ログローテーションやログ集約管理を導入しましょう。
  • 分散システムでは、リクエストの追跡を可能にするために相関IDを活用してください。

ロギング戦略を慎重に設計することで、システムの可観測性(Observability)が向上し、問題解決のスピードが劇的に改善されます。