T-CREATOR

Redis 遅延の原因を特定:Latency Monitor と Slowlog の読み方

Redis 遅延の原因を特定:Latency Monitor と Slowlog の読み方

Redis で遅延が発生したとき、原因を特定する手段として「Latency Monitor」と「Slowlog」という 2 つの強力なツールがあります。これらを使いこなせば、パフォーマンス問題を素早く発見し、適切な対策を打つことができるでしょう。

本記事では、Redis の遅延監視機能である Latency Monitor と Slowlog の使い方を、初心者の方にもわかりやすく解説していきます。

背景

Redis は高速なインメモリデータストアとして知られていますが、実運用では様々な要因で遅延が発生することがあります。

Web アプリケーションのレスポンスタイムが悪化したとき、その原因が Redis にあるのかを判断し、さらに Redis 内のどの処理が遅いのかを特定する必要があるでしょう。

以下の図は、Redis における遅延の主な発生ポイントを示しています。

mermaidflowchart TB
  client["クライアント<br/>アプリケーション"]
  network1["ネットワーク<br/>遅延①"]
  redis["Redis<br/>サーバー"]
  network2["ネットワーク<br/>遅延②"]

  client -->|コマンド送信| network1
  network1 --> redis
  redis -->|処理実行| processing["コマンド処理<br/>(遅延発生)"]
  processing --> redis
  redis -->|レスポンス返却| network2
  network2 --> client

この図からわかるように、遅延はネットワークとサーバー処理の両方で発生します。

Redis には遅延を監視・記録する仕組みが標準で備わっており、これらを活用することで問題箇所を迅速に特定できるのです。

課題

Redis の遅延問題に直面したとき、以下のような課題が生じます。

どこで遅延が発生しているか不明

アプリケーション全体のレスポンスが遅い場合、Redis が原因なのか、データベースやネットワークが原因なのか判断が難しいですね。

Redis 内部でも、特定のコマンドだけが遅いのか、サーバー全体の動作が遅いのかを区別する必要があります。

遅延の種類が多様

Redis における遅延には複数の種類があり、それぞれ原因と対策が異なるでしょう。

#遅延の種類主な原因影響範囲
1コマンド実行遅延重いコマンド(KEYS、SMEMBERS など)特定のコマンド
2フォーク遅延RDB 保存時のメモリコピー全体的な応答
3AOF 同期遅延ディスク I/O 待ち書き込み処理
4イベントループ遅延CPU 負荷、長時間処理全体的な応答

遅延データの収集と分析が困難

遅延は断続的に発生することが多く、発生時のデータを収集するタイミングを逃すことがあります。

また、収集したデータをどう読み解けば良いか、初見では判断しにくいですね。

以下の図は、遅延発見から解決までの流れを示しています。

mermaidflowchart TD
  start["遅延を検知"]
  monitor["Latency Monitor<br/>で種類を特定"]
  slowlog["Slowlog<br/>でコマンドを特定"]
  analyze["原因を分析"]
  solution["対策を実施"]

  start --> monitor
  monitor --> slowlog
  slowlog --> analyze
  analyze --> solution

  monitor -.->|イベントループ遅延| analyze
  slowlog -.->|重いコマンド| analyze

このプロセスを効率的に進めるには、適切なツールの使い方を理解することが重要です。

解決策

Redis が提供する Latency Monitor と Slowlog を組み合わせることで、遅延の原因を効率的に特定できます。

Latency Monitor:システム全体の遅延を監視

Latency Monitor は Redis サーバー全体で発生する遅延イベントを記録する機能です。

この機能を有効にすると、以下のような遅延イベントが自動的に記録されます。

  • command:コマンド実行の遅延
  • fast-command:O(1)または O(log N)コマンドの遅延
  • fork:RDB 保存時のフォーク処理の遅延
  • aof-write:AOF ファイル書き込みの遅延
  • aof-fsync-always:AOF 同期処理の遅延

Latency Monitor を使えば、遅延が「どの種類」の処理で発生しているかを把握できるでしょう。

Slowlog:遅いコマンドを記録

Slowlog は実行に時間がかかったコマンドを記録する機能ですね。

どのコマンドが遅いのか、どんなキーに対する操作なのか、実行時間はどれくらいかといった詳細情報を取得できます。

Latency Monitor がサーバー全体の健康状態を診断するなら、Slowlog は個別の症状(遅いコマンド)を特定する役割を果たします。

2 つのツールの使い分け

以下の表は、2 つのツールの特徴と使い分けをまとめたものです。

#項目Latency MonitorSlowlog
1監視対象システム全体のイベント個別のコマンド
2記録内容遅延の種類と発生時刻コマンド、引数、実行時間
3用途遅延の種類を特定遅いコマンドを特定
4設定方法latency-monitor-thresholdslowlog-log-slower-than
5データ保持イベント種類ごとに最新 160 件設定した件数(デフォルト 128)

これらを組み合わせることで、「何が遅いか」と「なぜ遅いか」の両方を明らかにできます。

具体例

実際に Latency Monitor と Slowlog を使って遅延を調査する手順を見ていきましょう。

Latency Monitor の設定と使用方法

設定の有効化

Latency Monitor を有効にするには、遅延の閾値をミリ秒単位で設定します。

bash# Redis CLIで設定(100ミリ秒以上の遅延を記録)
redis-cli CONFIG SET latency-monitor-threshold 100

この設定により、100 ミリ秒以上かかった処理がすべて記録されます。

本番環境では、通常のレスポンスタイムより少し高めの値(例:50〜100ms)を設定すると良いでしょう。

記録されたイベントの確認

設定後、遅延イベントが記録されているか確認してみます。

bash# 記録されている遅延イベントの一覧を取得
redis-cli LATENCY LATEST

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

text1) 1) "command"
   2) (integer) 1699876543
   3) (integer) 250
   4) (integer) 350

2) 1) "fork"
   2) (integer) 1699876540
   3) (integer) 120
   4) (integer) 120

各フィールドの意味は次の通りです。

#フィールド説明例の値
1イベント名遅延の種類command、fork
2発生時刻Unix タイムスタンプ1699876543
3最新の遅延時間ミリ秒250
4最大遅延時間ミリ秒350

この例では、コマンド実行で最大 350ms、フォーク処理で 120ms の遅延が発生していることがわかります。

特定イベントの履歴確認

特定のイベント種類について、詳細な履歴を確認できます。

bash# commandイベントの履歴を確認
redis-cli LATENCY HISTORY command

出力例です。

text1) 1) (integer) 1699876543
   2) (integer) 250

2) 1) (integer) 1699876530
   2) (integer) 180

3) 1) (integer) 1699876520
   2) (integer) 210

各エントリは「発生時刻」と「遅延時間」のペアで、最新のものから順に表示されます。

グラフ形式での確認

より視覚的に確認したい場合は、グラフ形式で表示できます。

bash# commandイベントをASCIIグラフで表示
redis-cli --latency-history -i 1

このコマンドを実行すると、1 秒ごとに遅延をグラフ表示してくれるでしょう。

記録のリセット

調査が終わったら、記録をクリアすることができます。

bash# すべてのイベント記録をクリア
redis-cli LATENCY RESET

# 特定のイベントだけクリア
redis-cli LATENCY RESET command

新しい調査を始める前にリセットしておくと、古いデータと混ざらず分析しやすくなりますね。

Slowlog の設定と使用方法

設定の有効化

Slowlog は、実行時間が閾値を超えたコマンドを記録します。

bash# 10ミリ秒以上かかったコマンドを記録
redis-cli CONFIG SET slowlog-log-slower-than 10000

閾値はマイクロ秒単位で指定します(10000 マイクロ秒 = 10 ミリ秒)。

記録する最大件数も設定できます。

bash# 最大200件まで記録
redis-cli CONFIG SET slowlog-max-len 200

デフォルトは 128 件ですが、調査中は多めに設定しておくと良いでしょう。

記録されたコマンドの確認

Slowlog に記録されたコマンドを確認します。

bash# 最新10件を取得
redis-cli SLOWLOG GET 10

出力例です。

text1) 1) (integer) 5
   2) (integer) 1699876543
   3) (integer) 250000
   4) 1) "KEYS"
      2) "user:*"
   5) "127.0.0.1:54321"
   6) ""

2) 1) (integer) 4
   2) (integer) 1699876540
   3) (integer) 180000
   4) 1) "SMEMBERS"
      2) "active_users"
   5) "127.0.0.1:54322"
   6) ""

各フィールドの意味を表で確認しましょう。

#フィールド説明例の値
1ログ IDエントリの一意識別子5
2実行時刻Unix タイムスタンプ1699876543
3実行時間マイクロ秒250000(250ms)
4コマンドと引数実行されたコマンドKEYS user:*
5クライアント情報IP とポート127.0.0.1:54321
6クライアント名CLIENT SETNAME で設定された名前(空文字)

この例では、KEYS コマンドが 250ms、SMEMBERS コマンドが 180ms かかっていることがわかります。

エントリ数の確認

現在記録されているエントリ数を確認できます。

bash# Slowlogのエントリ数を取得
redis-cli SLOWLOG LEN

出力例です。

text(integer) 42

これにより、42 件のコマンドが記録されていることがわかるでしょう。

記録のリセット

Slowlog もリセットできます。

bash# Slowlogをクリア
redis-cli SLOWLOG RESET

定期的にリセットすることで、新しい問題と古い問題を区別しやすくなります。

実践的な調査フロー

実際の遅延調査は、以下のステップで進めると効果的です。

ステップ 1:Latency Monitor で遅延の種類を特定

まず、どの種類の遅延が発生しているかを確認します。

bash# 遅延イベントの一覧を確認
redis-cli LATENCY LATEST

ここで command イベントが多く記録されていれば、特定のコマンドが原因と推測できるでしょう。

ステップ 2:Slowlog で遅いコマンドを特定

次に、どのコマンドが遅いかを確認します。

bash# Slowlogから最新20件を取得
redis-cli SLOWLOG GET 20

KEYS や SMEMBERS など、O(N)の計算量を持つコマンドが頻出していないか確認してください。

ステップ 3:原因を分析

特定されたコマンドについて、以下の観点で分析します。

  • コマンドの種類:KEYS、SMEMBERS、HGETALL など重いコマンドか
  • データ量:対象キーに大量の要素が含まれていないか
  • 実行頻度:同じコマンドが短時間に何度も実行されていないか
  • 実行元:どのクライアント(アプリケーション)から実行されているか

これらの情報から、アプリケーション側の修正ポイントが見えてきます。

ステップ 4:対策を実施

分析結果に基づいて対策を実施しましょう。

一般的な対策としては以下があります。

typescript// 悪い例:KEYSコマンドでパターンマッチング
const keys = await redis.keys('user:*');
typescript// 良い例:SCANコマンドで段階的に取得
let cursor = '0';
const keys: string[] = [];

do {
  const result = await redis.scan(
    cursor,
    'MATCH',
    'user:*',
    'COUNT',
    '100'
  );
  cursor = result[0];
  keys.push(...result[1]);
} while (cursor !== '0');

KEYS を SCAN に置き換えることで、一度に大量のキーを処理せず、段階的に取得できます。

また、大きな Set を扱う場合も工夫が必要です。

typescript// 悪い例:SMEMBERSで全要素を一度に取得
const members = await redis.smembers('active_users');
typescript// 良い例:SSCANで段階的に取得
let cursor = '0';
const members: string[] = [];

do {
  const result = await redis.sscan(
    'active_users',
    cursor,
    'COUNT',
    '100'
  );
  cursor = result[0];
  members.push(...result[1]);
} while (cursor !== '0');

SSCAN を使うことで、メモリとレスポンスタイムの両方を改善できるでしょう。

監視の自動化

本番環境では、継続的に監視する仕組みを構築することが重要です。

以下は Node.js で定期的に Latency Monitor と Slowlog をチェックする例です。

Redis クライアントの設定

まず、Redis クライアントを初期化します。

typescriptimport Redis from 'ioredis';

// Redisクライアントの作成
const redis = new Redis({
  host: 'localhost',
  port: 6379,
  // 必要に応じて認証情報を設定
});

Latency Monitor のチェック関数

Latency Monitor の結果を取得し、閾値を超えた遅延を検知します。

typescript// Latency Monitorの結果を取得
async function checkLatencyMonitor(): Promise<void> {
  // latency-monitor-thresholdを設定(100ms)
  await redis.config(
    'SET',
    'latency-monitor-threshold',
    '100'
  );

  // 最新の遅延イベントを取得
  const latencyData = await redis.latency('LATEST');

  // データを解析
  for (let i = 0; i < latencyData.length; i += 4) {
    const eventName = latencyData[i];
    const timestamp = latencyData[i + 1];
    const latestLatency = latencyData[i + 2];
    const maxLatency = latencyData[i + 3];

    // 200ms以上の遅延があれば警告
    if (maxLatency >= 200) {
      console.warn(`⚠️ 高遅延検知: ${eventName}`);
      console.warn(`  最大遅延: ${maxLatency}ms`);
      console.warn(`  最新遅延: ${latestLatency}ms`);
      console.warn(
        `  発生時刻: ${new Date(
          timestamp * 1000
        ).toISOString()}`
      );
    }
  }
}

この関数は、200ms を超える遅延が発生したら警告を出力します。

Slowlog のチェック関数

Slowlog から遅いコマンドを取得し、分析します。

typescript// Slowlogの結果を取得
async function checkSlowlog(): Promise<void> {
  // slowlog設定(10ms以上を記録)
  await redis.config(
    'SET',
    'slowlog-log-slower-than',
    '10000'
  );
  await redis.config('SET', 'slowlog-max-len', '200');

  // 最新10件を取得
  const slowlogData = await redis.slowlog('GET', 10);

  // 各エントリを解析
  for (const entry of slowlogData) {
    const id = entry[0];
    const timestamp = entry[1];
    const duration = entry[2]; // マイクロ秒
    const command = entry[3];
    const clientInfo = entry[4];

    const durationMs = duration / 1000; // ミリ秒に変換

    // 100ms以上のコマンドを警告
    if (durationMs >= 100) {
      console.warn(`🐌 遅いコマンド検知:`);
      console.warn(`  コマンド: ${command.join(' ')}`);
      console.warn(
        `  実行時間: ${durationMs.toFixed(2)}ms`
      );
      console.warn(`  クライアント: ${clientInfo}`);
      console.warn(
        `  発生時刻: ${new Date(
          timestamp * 1000
        ).toISOString()}`
      );
    }
  }
}

この関数は、100ms を超えるコマンドがあれば詳細を出力してくれます。

定期実行の設定

これらのチェック関数を定期的に実行します。

typescript// 監視を開始
async function startMonitoring(): Promise<void> {
  console.log('Redis遅延監視を開始します');

  // 5分ごとにチェック
  setInterval(async () => {
    try {
      await checkLatencyMonitor();
      await checkSlowlog();
    } catch (error) {
      console.error('監視エラー:', error);
    }
  }, 5 * 60 * 1000); // 5分

  // 初回実行
  await checkLatencyMonitor();
  await checkSlowlog();
}

// 監視開始
startMonitoring();

これで、5 分ごとに自動的に遅延をチェックし、問題があれば通知されるようになります。

実際の運用では、ログ出力だけでなく、Slack や監視ツールへの通知を追加すると良いでしょう。

まとめ

Redis の遅延問題を特定するには、Latency Monitor と Slowlog という 2 つの強力なツールを使いこなすことが重要です。

Latency Monitor はサーバー全体の遅延イベントを監視し、どの種類の処理で遅延が発生しているかを教えてくれます。

Slowlog は個別のコマンドレベルで遅延を記録し、具体的にどのコマンドが遅いのかを明らかにしてくれるでしょう。

この 2 つを組み合わせることで、「何が遅いか」と「なぜ遅いか」を効率的に特定できます。

調査の基本フローは次の通りです。

  1. Latency Monitor で遅延の種類を確認
  2. Slowlog で遅いコマンドを特定
  3. コマンドの種類、データ量、実行頻度を分析
  4. アプリケーション側で対策を実施(KEYS → SCAN など)
  5. 継続的な監視で再発を防止

本番環境では、これらのツールを定期的にチェックする仕組みを構築し、問題を早期に発見できる体制を整えることが大切ですね。

Redis の遅延監視をマスターして、快適なアプリケーション運用を実現しましょう。

関連リンク