记一次Redis KEY莫名丢失的问题排查

第一次察觉有key被莫名删除时：

1. 首先想到的是不是内存不足，导致被淘汰了，赶紧查看内存使用情况：

# free -m
             total       used       free     shared    buffers     cached
Mem:          8023       7535        488          1        100        373
-/+ buffers/cache:       7061        961
Swap:         3967       2198       1769

内存有余量。

2. 那是不是redis配置里限制了redis的最大内存呢，看一下redis配置文件，

vim /..../redis.conf

看了下没对maxmemory做限制。

3. redis-cli ，进入客户端
   查看内存概况

127.0.0.1:6379[1]>  info memory
# Memory
used_memory:2375848#由Redis分配器分配的内存总量,
used_memory_human:2.27M # 以人易读的格式返回 
used_memory_rss:8454144#从操作系统的角度，返回 Redis 已被分配的内存总量（俗称常驻集大小）。这个值和 top 、 ps 等命令的输出一致，即RSS。
used_memory_rss_human:8.06M
used_memory_peak:5255280#redis使用内存的峰值
used_memory_peak_human:5.01M
total_system_memory:8412987392#系统内存
total_system_memory_human:7.84G
used_memory_lua:37888 #Lua 引擎所使用的内存大小
used_memory_lua_human:37.00K
maxmemory:0 #0表示不限制
maxmemory_human:0B
maxmemory_policy:allkeys-lru#key的缓存淘汰策略
mem_fragmentation_ratio:3.56#used_memory_rss 和 used_memory 之间的比率
mem_allocator:jemalloc-4.4.0#编译时指定的， Redis 所使用的内存分配器。可以是 libc 、 jemalloc 或者 tcmalloc

1）当 rss > used ，且两者的值相差较大时，表示存在（内部或外部的）内存碎片。
内存碎片的比率可以通过 mem_fragmentation_ratio 的值看出。
2）当 used > rss 时，表示 Redis 的部分内存被操作系统换出到交换空间了，在这种情况下，操作可能会产生明显的延迟。
3)当 Redis 释放内存时，分配器可能会，也可能不会，将内存返还给操作系统。如果 Redis 释放了内存，却没有将内存返还给操作系统，那么 used_memory 的值可能和操作系统显示的 Redis 内存占用并不一致。查看 used_memory_peak 的值可以验证这种情况是否发生。

可以看到used_memory并没有多少，至此可以看出不是内存不足了
不带单位的，默认的单位是B

尝试写入几次，发现被删除的时间约为1min左右，怀疑是有脚本在执行特殊命令

于是乎，执行：

redis-cli monitor >/home/redis/redis-op.log

查看客户端都执行了什么命令，通过观察log文件内容变化，发现问题所在：

# tail -f  /home/fpf/redis-op.log
.......
1611058888.482474 [1 200.200.107.241:48126] "SELECT" "1"
1611058888.482548 [1 200.200.107.241:48126] "HSET" "JOIN_DOMAIN:6c7bd46a70bd7477937dc90313461aa5" "12345665698" "200.200.170.29"
1611058922.783485 [0 200.200.107.241:39078] "SELECT" "0"
1611058922.786919 [0 200.200.107.241:39078] "PING"
1611058922.787479 [0 200.200.107.241:39078] "GET" "mjcogmt5frm185597sea37ehqq"
1611058922.811595 [0 200.200.107.241:39082] "SELECT" "1"
1611058922.811844 [1 200.200.107.241:39082] "KEYS" "visit:*"
1611058922.811985 [1 200.200.107.241:39082] "FLUSHDB"
1611058922.854436 [0 200.200.107.241:39078] "PING"
......

可以清晰的看到对于db 1操作，在HSET后会有个FLUSHDB动作，破案完结

题外话

在处理问题的过程中，发现info这个命令还是挺好用的，

#直接执行info可以看到redis服务的很多信息，但太多，容易眼花，可以加个选项，例如
127.0.0.1:6379> info commandstats 
# Commandstats
cmdstat_get:calls=2,usec=9,usec_per_call=4.50
cmdstat_setex:calls=2,usec=9,usec_per_call=4.50
cmdstat_hset:calls=1,usec=4,usec_per_call=4.00
cmdstat_select:calls=4,usec=5,usec_per_call=1.25
cmdstat_keys:calls=2,usec=18,usec_per_call=9.00
cmdstat_ping:calls=4,usec=3,usec_per_call=0.75
cmdstat_flushdb:calls=1,usec=20,usec_per_call=20.00
cmdstat_info:calls=7,usec=505,usec_per_call=72.14
cmdstat_config:calls=1,usec=6,usec_per_call=6.00 

可以在不重启服务的情况下通过 config resetstat重置info commandstats结果

另外 config 这个命令也挺好用的

127.0.0.1:6379> config get maxmemory
1) "maxmemory"
2) "0"

参考资料

1:查看redis内存使用情况
2:redis内存管理
3:redis maxmemory配置