【redis】redis hits 飙高问题的分析处理

2022-07-21 本文已影响0人 Bogon

一、背景

看redis监控发现有个指标居高不下，晚上11点都维持着四五万的hits
对redis哨兵而言，七八万qps就是极限了，再高，就会引发redis性能的下降

image.png

需要注意的是，redis实例内存使用并不高，说明只是并发量而不是数据量问题

image.png

二、问题排查思路

有必要对其并发操作做一下分析：

这些 hits 都由哪些操作构成？
哪些是热key？

排查思路：
1、监控里面会显示各种命令的操作次数
2、可以确定命令类型后，就能知道是操作类型，然后再在增长点的时候直接开启monitor去镜像操作
3、高峰高达8w/s的话，然后确定不是很多key，而是部分热key，可以修改淘汰策略，然后保证实例空间足够，然后进行热key遍历

image.png

为什么要设置key生存时间？

在实际开发过程中，经常会遇到一些有实效性的数据，比如限时优惠、缓存、验证码等等，过了一段时间后就应该删除这些数据。如果用关系型数据库，那么就需要在表中增加一个字段存储实效时间，然后定时轮询该字段并判断删除。而在redis中，可以使用expire命令给key设置有效时间来实现这个需求。

设置key的生存时间，可以用于以下使用场景：

1.在登录网站后，将用户session存储在内存，设置一个过期时间，超过这个时间后，用户必须重新登录（例如aws控制台的session过期时间为12个小时）。

使用redis队列时，通常设置一个过期时间，这样即使队列的消费者应用出bug，队列内的消息也不会积压。

那这个问题就有突破口了：

hits高，从对 command calls 监控看，绝大部分是 ttl 操作
什么业务会需要大量 ttl 操作？
这样量的 ttl 是否合理？
如果不合理，要做业务改造；
如果合理，那么要搞清是哪些微服务工程行为，针对性做 redis拆分，用redis集群来这部分缓存

三、找出 ttl 操作来源

redis 主节点： 192.168.1.102:6379

$ redis-cli  -h  192.168.1.102 -p 6379   -a  'XXXX'  client list  > client_list.txt

$  grep -w  ttl   client_list.txt 

$  grep -w  ttl   client_list.txt  |  awk '{printf "%-32s| %-16s| %-16s| %-16s| %-16s| %-16s| %s\n", $2,$5,$6,$7,$12,$16,$18}'

id=847281399 addr=10.22.193.111:59912 fd=1326 name= age=648560 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=ttl
id=854228598 addr=192.168.65.118:25991 fd=3898 name= age=247 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=ttl
id=854228609 addr=192.168.65.112:38738 fd=3930 name= age=247 idle=1 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=ttl
id=854228610 addr=10.22.193.106:64575 fd=3942 name= age=247 idle=2 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=ttl
id=854228613 addr=192.168.65.114:14066 fd=3948 name= age=247 idle=9 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=ttl
id=847281353 addr=10.22.193.112:2629 fd=870 name= age=648561 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=ttl
id=847282211 addr=10.22.193.114:5990 fd=881 name= age=648484 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=ttl
id=854229751 addr=192.168.65.110:17349 fd=1543 name= age=136 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=ttl
id=851921182 addr=10.22.193.107:13161 fd=3056 name= age=215691 idle=1 flags=N db=5 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=0 obl=0 oll=0 omem=0 events=r cmd=ttl
id=854228137 addr=192.168.65.116:16920 fd=3915 name= age=286 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=ttl
id=847281352 addr=10.22.193.121:2585 fd=1257 name= age=648562 idle=0 flags=N db=0 sub=0 psub=0 multi=-1 qbuf=0 qbuf-free=32768 obl=0 oll=0 omem=0 events=r cmd=ttl

根据  addr=ip:port  socket信息，可以查到目标ip上哪个工程 监听该 port,连到 192.168.1.102:6379，发起ttl操作。



$ netstat  -pantu | grep  -w  2629
(Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.)
tcp6       0      0 10.21.193.112:2629      192.168.1.102:6380       ESTABLISHED 308616/java      
tcp6       0      0 10.21.193.112:12197     172.18.36.120:2629      TIME_WAIT   -                   
tcp6       0      0 10.21.193.112:10657     172.18.65.189:2629      TIME_WAIT   -                   


$ ps aux | grep 308616
nobody      308616  7.3  2.3 11913984 1526956 ?    Sl   Jul14 799:22 /opt/jdk/bin/java -Dservicename=test -XX:+UseG1GC -Xmx1024m -Xms1024m 



$ netstat  -pantu | grep -w 3954
(Not all processes could be identified, non-owned process info will not be shown, you would have to be root to see it all.)
tcp6       0     92 172.18.65.130:3954      192.168.1.102:6379       ESTABLISHED 588857/java         
tcp6       0      0 172.18.65.130:12869     172.18.65.106:3954      TIME_WAIT   -                   
tcp6       0      0 172.18.65.130:12451     172.18.65.189:3954      TIME_WAIT   -    


$ ps aux | grep  588857

nobody      588857 18.5  2.4 11913980 1618388 ?    Sl   Jul14 2006:20 /opt/jdk/bin/java -Dservicename=test  -XX:+UseG1GC -Xmx1024m -Xms1024m

从选取几个连接看，都是test工程发起的对该redis实例的 ttl操作。

四、追踪 ttl操作相关的key

redis-faina 是由Instagram 开发并开源的一个Redis 查询分析小工具。
redis-faina通过解析redis的MONITOR命令的输出，从而对redis实例进行性能诊断的工具。
该工具使用虽然简单，但是功能还是很不错，对于定位线上redis性能问题，确实是一把利器。

通过管道从stdin读取redis monitor 输出，解析

# yum install git 

# git clone https://github.com/facebookarchive/redis-faina.git 

# cd redis-faina 

# redis-cli -h xx.xx.xx.xx   -p 6379  -a 'XXX'  monitor  | head -n  10000 |  ./redis-faina.py

将redis monitor 输出重定向到文件，然后读取解析

# yum install git 

# git clone https://github.com/facebookarchive/redis-faina.git 

# cd redis-faina 

# redis-cli -h xx.xx.xx.xx  -p 6379  -a 'XXX'  monitor  > m.log 

//另开窗口，查询输出日志行数，到达自己目标行，就中断掉
# wc  -l  m.log 

# ./redis-faina.py m.log