業務でRedisを取り扱っていますが、ある時特定のキーをgetしようとしたところ

ことが判明し、他にどのキャッシュデータがメモリ消費を大きくしているのかを特定する必要が生じました。結論から言いますとredis-cliにてslowlog getを使うことで特定しましたが、今回はこのslowlog getコマンドについて、備忘録を兼ねて紹介いたします。

バージョン情報

• redis-cli: 6.0.16
• Redis: 7.0

slowlog getコマンドとは

公式ドキュメントを端的に和訳すると、

になります。「指定された実行時間」はslowlog-log-slower-than構成ディレクティブに定義された実行時間しきい値（何マイクロ秒以上かかるものをスロークエリとして扱うか）を指し、この設定値はredis.confに記載します。

slowlog-log-slower-than 10000
slowlog-max-len 128

上記の設定はデフォルト値でもあります。redis.confに何も設定しなければ上記が適用されます。この内容を読み解くと下記のようになります。

スロークエリとして取り扱う実行時間しきい値: 10000マイクロ秒（ = 10ミリ秒 = 0.01秒）
スローログのエントリ最大数: 128

slowlog get [count]の"count"について

オプション引数です。スローログから時系列で最新の何件を取り出すかを指定できます。何も指定しなければデフォルトの10が適用されます。

slowlog get [count]の実行結果解説

実行結果のサンプルを使って解説します。

10.10.10.5:6379> SLOWLOG GET 10
 1) 1) (integer) 693684
    2) (integer) 1714536827
    3) (integer) 10244
    4) 1) "GET"
       2) "hoge_1"
    5) "192.168.0.20:60662"
    6) ""
 2) 1) (integer) 693683
    2) (integer) 1714536824
    3) (integer) 24891
    4) 1) "GET"
       2) "hoge_2"
    5) "192.168.0.20:59886"
    6) ""
 3) 1) (integer) 693682
    2) (integer) 1714536823
    3) (integer) 12918
    4) 1) "GET"
       2) "hoge_3"
    5) "192.168.0.20:59762"
    6) ""

• 1): すべてのスロー ログ エントリの一意のプログレッシブ識別子
• 2): ログに記録されたコマンドが処理された Unix タイムスタンプ
• 3): 実行に要した時間 (マイクロ秒単位)
• 4): コマンドの引数を構成する配列
• 5): クライアントの IP アドレスとポート
• 6): CLIENT SETNAME コマンドで設定された場合のクライアント名

この中で重要な情報は 3) と 4) になります。特に4)は「どのキャッシュキーに紐づくデータが応答遅いのか？」を特定するのに役立ちます。キー名が判明すれば、そのキーを生成したアプリケーションロジックがコード内を検索すれば特定できる可能性があるからです。

実運用事例

私の実際の業務でslowlog getにより実行に時間かかっているキー名を洗い出し、アプリケーション上で当該キャッシュデータを生成しているロジックを特定、キャッシュする際のデータ量を削減したことで実行時間の削減に成功したケースがあります。その際はネットワーク入出力バイト数も削減できました。

参考

• redis.io SLOWLOG GET
• redis.io Redis configuration file example