大量日志WRN unknown command. argv=[opinfo

[lenovore]

问题描述

阿里云redis同步自建单实例redis，全量同步完后持续有大量的unknown command opinfo信息写入日志，

redis-shake版本：v3.1.7

filter lua:

-- Aliyun Redis 4.0: skip OPINFO command
function filter(id, is_base, group, cmd_name, keys, slots, db_id, timestamp_ms)
    if cmd_name == "OPINFO" then
        return 1, db_id -- disallow
    elseif db_id == 68 then
        return 0, db_id
    else
        return 1, db_id -- allow
    end
end

redis-shake 的日志：

{"level":"info","time":"2022-11-25T22:50:39+08:00","message":"LUA script: [if (redis.call('hexists', KEYS[1], ARGV[3]) == 0) then return nil;end; local counter = redis.call('hincrby', KEYS[1], ARGV[3],
 -1); if (counter > 0) then redis.call('pexpire', KEYS[1], ARGV[2]); return 0; else redis.call('del', KEYS[1]); redis.call('publish', KEYS[2], ARGV[1]); return 1; end; return nil;]"}
{"level":"info","time":"2022-11-25T22:50:39+08:00","message":"LUA script: [if (redis.call('hexists', KEYS[1], ARGV[2]) == 1) then redis.call('pexpire', KEYS[1], ARGV[1]); return 1; end; return 0;]"}
{"level":"info","time":"2022-11-25T22:50:39+08:00","message":"send RDB finished. address=[xxx:6379], repl-stream-db=[65]"}
{"level":"info","time":"2022-11-25T22:50:40+08:00","message":"AOFReader open file. aof_filename=[19774065566122.aof]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001B\n\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\r\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\ufffd\uf
ffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001B@\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u000e\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\ufffd
\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001BA\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u000f\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\ufffd
\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001B[\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u0010\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\ufffd
\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001BA\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u0011\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\ufffd
\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001\u0002M\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u0012\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\
ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001\u0002M\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u0013\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\
ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001\u0002M\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u0014\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\
ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001\u0002M\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u0015\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\
ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}
{"level":"warn","time":"2022-11-25T22:50:40+08:00","message":"unknown command. argv=[opinfo \u0001\u0002M\u0000\fրc\ufffdЭ\u0002\u0000\u0000\u0000\u0000\u0016\u0017\ufffd\ufffd\u0002\u0000\u0000\u0000\
ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd\ufffd]"}

---

源端 Redis 版本：阿里云v4.0 日志：

2022-11-25 22:50:41 | 37048:M 25 Nov 22:50:40.726 # Connection with slave 172.17.4.2:10007 lost.
2022-11-25 22:50:14 | 37048:M 25 Nov 22:50:13.564 * unlink appendonly-inc-1669367674.aof success
2022-11-25 22:50:13 | 40497:S 25 Nov 22:50:12.550 * unlink appendonly-inc-1669367680.aof success
2022-11-25 22:50:08 | 37048:M 25 Nov 22:50:05.895 * Synchronization with slave 172.17.4.2:10007 succeeded
2022-11-25 22:50:05 | 37048:M 25 Nov 22:50:03.439 * Background saving terminated with success
2022-11-25 22:50:05 | 20091:C 25 Nov 22:50:03.051 * BGSAVE done, write rdb.index, rdb name: dump.rdb, aof name: appendonly-inc-1669387788.aof, aof offset: 0, next opid: 12323723021
2022-11-25 22:50:05 | 20091:C 25 Nov 22:50:03.274 * RDB: 128 MB of memory used by copy-on-write
2022-11-25 22:50:05 | 20091:C 25 Nov 22:50:03.210 * DB saved on disk

---

目的端 Redis 版本：自建v4.0.14 日志：

无

[suxb201]

看这里，阿里云 4.x 版本 Redis 有自定义命令，需要过滤掉：https://github.com/alibaba/RedisShake/wiki/%E4%BB%8E%E5%B8%B8%E8%A7%81%E4%BA%91%E5%8E%82%E5%95%86%E8%BF%81%E5%87%BA%E6%95%B0%E6%8D%AE

[lenovore]

看我上面的描述嘛，就是使用了lua脚本过滤了阿里云的OPINFO，为什么还有那么多WARN

[lenovore]

如果不过滤的话，就直接报错的，但加上过滤后，就一直刷warn 信息

[suxb201]

明白了，对于不认识的命令 redis-shake 会报出来。这个场景 opinfo 比较多，所以 warn 也比较多。你可以把 redis-shake 对应 log 注释。

[lenovore]

@suxb201 怎么注释log呢，目前用的v2.x版本，有点问题，想用回3.x的，就日志这块卡主了。

还有 注释了日志，那同步信息从哪看。

[suxb201]

代码中搜 "unknown command. argv" 找到对应行注释掉就好。

[lenovore]

好的，你说的是要改源码

[suxb201]

是的