记一次redis中cpu飙升的紧急bug

前段时间遇到一个棘手问题,mq消费速度突然从30/s变成1/s,而且还持续了很长的一段时间,吓得我赶紧动手排查问题。但是mq消费速度慢的原因,可能有很多种(例如mysql、jvm、redis、mq、代码问题等)。为了可以快速定位问题点,博主直接通过Arthas工具进行问题的排查和追踪。

Arthas用法可以参照:https://mp.weixin.qq.com/s/FT1gKYDzczWa05xYm-z0Vw

image

通过Arthas的trace命令,可以分析方法中每一行代码的执行时间,分析得到方法中最耗时的竟然是redis,看到这个结果差点没卧槽出来,redis怎么可能会那么慢呢。因为公司使用的是腾讯云的redis,所以可以直接在控制台上面看到redis各个监控指标,博主火速打开控制台,然后就看到如下所示cpu持续不断的飙到100%。

image

那会是什么操作引起的呢?我们首先要清楚一般什么情况下会导致redis的cpu飙升到100%。导致cpu飙升的原因,一般可能会有如下几种:

  1. redis从库大批量同步到redis主库
  2. redis请求的qps过高
  3. redis存在大量慢查询

因为系统redis目前是单例,所以不存在第一种的情况。至于第二种,从腾讯云控制台中看到redis总请求的量,发现cpu高的那个时间段,总请求数并没有飙升,所以也不是第二种可能。至于第三种可能性,如下所示,发现了很多keys report:requestId:的命令出现。

image

到了这一步基本可以确定是因为keys report:requestId:引起的,但是为了出于严谨考虑,我们在测试环境多次请求keys report:requestId:命令,发现果然cpu直接飙升上去了。原来罪魁祸首是keys模糊搜索引起的啊,那我们要如何解决这个问题呢?

我们可以用scan来替代keys命令,java代码如下所示:

1
2
3
4
5
6
7
8
Set<String> keys = (Set<String>) redisTemplateForRequestId.execute((RedisCallback<Set<String>>) connection -> {
Set<String> keysTmp = new HashSet<>();
Cursor<byte[]> cursor = connection.scan(new ScanOptions.ScanOptionsBuilder().match(multiRedisKey + "*").count(100).build());
while (cursor.hasNext()) {
keysTmp.add(new String(cursor.next()));
}
return keysTmp;
});

优化之后可以明显看到,redis的超过2s的命令都不存在了,cpu也恢复到之前平缓的状态了。所以以后在写redis的api时候要慎用甚至不用keys命令,如果数据量特别大的情况下,严重可能会导致redis持续性宕机。

大家是不是以为到这边就结束了呢?不!不管使用keys还是scan都比一般的命令耗时。如果我们想要查询的命令可以通过枚举一一列出来(数量不大,允许一一枚举),那我们一定要用枚举来查询,这样效率会比用scan高很多(有点类似数据库的like和=操作)。所以最后代码博主优化为:

1
redisTemplate.opsForValue().multiGet("list集合,里面存储着redis的key值")

之所以能这么快定位到redis对应的问题,很大一部分是因为腾讯云给我们提供了很多便捷式的查询。如果你的redis没有这些指标监控呢,你又该如何监控这些指标呢?哈哈,后面有机会给大家介绍。

作者:林志强

林老师带你学编程 wechat
欢迎您扫一扫上面的微信公众号,订阅我的博客!