Redis Lua script(EVAL)はSLOWLOGにはどう出るのか

先日、RedisのINCRBYFLOATコマンドがSLOWLOGにはSETコマンドとして出て来るといったような話がありました。 https://github.com/antirez/redis/issues/3841

EVALコマンドでLua scriptを実行したときのSLOWLOGは、EVALとして出て来るのか。それともLua script内のRedisコマンド単位で出てくるのか気になるね〜みたいな話がでたので検証してみる次第です。

結果から言うと、(Redis 3.2.1 versionでは)EVALコマンドとして出て来るので問題ないです。

検証する

なんか適当にLua内でsleepさせてみれば良いわけであります。

しかし、RedisのLuaでは使用できるlibに限りがあるので、os.sleepとかは使えません。
どうしたもんかと考えた結果、SET, PEXPIRE, PTTLを以下のように使って20ms sleepさせてみました。
(Redisはデフォだと10msこえるとSLOWLOGに出てくる)

local tempKey = "temp-key"
local cycles

redis.call("SET", tempKey, "1")
redis.call("PEXPIRE", tempKey, 20)

for i = 0, ARGV[1] do
    local pttl = redis.call("PTTL", tempKey)
    cycles = i;
    if pttl == 0 then
        break;
    end
end

準備できたので、実行してみるです。

EVALのとき

$ redis-cli EVAL "$(cat slow.lua)" 0 100000
(integer) 29409

$ redis-cli SLOWLOG GET 1

1) 1) (integer) 4
   2) (integer) 1488512354
   3) (integer) 19775
   4) 1) "EVAL"
      2) "local tempKey = \"temp-key\"\nlocal cycles\n\nredis.call(\"SET\", tempKey, \"1\")\nredis.call(\"PEXPIRE\", tempKey, 20)\n\nfor i = 0, ARGV[1] ... (127 more bytes)"
      3) "0"
      4) "100000"

お、ちゃんとEVAL単位で出てきます。

EVALSHAのとき

毎回Lua scriptをRedisに送るのは帯域の無駄なので、予めRedisにscriptを読ませておく方法があります。
そして、そのscriptのsha1を使ってこんな風に実行します。

EVALSHA sha1 numkeys key [key ...] arg [arg ...]

もし、SLOWLOGでこのコマンドで出てきても、いったいどのLua scriptなのかパッと見でわからんという問題があります。

というわけで、一応試します。

$ redis-cli SCRIPT LOAD "$(cat slow.lua)"
9dabe8fa13e49ee8c41467e697cd852e553ca36c

$ redis-cli EVALSHA 9dabe8fa13e49ee8c41467e697cd852e553ca36c 0 100000
(integer) 35989

$ redis-cli SLOWLOG GET 10
1) 1) (integer) 6
   2) (integer) 1488512445
   3) (integer) 19238
   4) 1) "EVAL"
      2) "local tempKey = \"temp-key\"\nlocal cycles\n\nredis.call(\"SET\", tempKey, \"1\")\nredis.call(\"PEXPIRE\", tempKey, 20)\n\nfor i = 0, ARGV[1] ... (127 more bytes)"
      3) "0"
      4) "100000"

お、ちゃんとEVALとして出て来るので安心です。

まとめ

というわけで安心です。