1. 现象
某天突然收到运维告警消息,反馈产线有接口在某一段时间慢了,随之性能优化的JIRA任务也开过来了,大致内容如下:
API告警 - Base Tomcat Accesslog:
微服务: xxxapi
接口: /xxxx/xxx POST
在 [ 2022/xx/xx 10:42:00 ~ 10:43:00 ] 时间窗口,RT > 阈值(300ms) 发生 141 次。
公司内部对API的响应时间要求是低于300ms,超过的都属于有性能问题的接口,接下来就排查吧。
2. 排查
2.1. 查监控平台:接口速度
首先就去查看公司的API监控平台,确认这个接口的确在这段时间的确在响应速度上,有100多次超过300ms。
不过发现几个有意思的现象:
- 在那段时间前后,该接口都很正常,所以应该只是那段时间发生了什么。
- 不只是那一个接口超过300ms了,其实那段时间内,也有个别其他接口超过阈值。只不过因为那个接口的并发比较高,很明显的被告警机制检测出来。
2.2. 查监控平台:全链路日志
虽然上面发现,可能不只是那一个接口的问题,但还是要仔细分析一下那个接口的全链路日志。
通过调用链路图,可以明显的发现,主要的耗时都在redis命令的执行阶段。又找了那段时间,其他的几个接口,结果都是一样的。
接下来就应该看看对应接口的代码,是不是执行redis命令时,有什么影响性能的问题。
2.3. 分析代码
找到对应接口的代码,代码中唯一用到redis的命令是 HMGET key field1 [field2]
,分析后排除该代码的问题:
- 代码中就那一次的redis调用,
HMGET
不是耗时的命令(不在后文 O(n)命令之列),且field
的数量是可枚举的,最多也就几十个,不会有多耗时。 - 该接口因为之前预计到并发高,所以上线之前经过压测,上万QPS完全不成问题,不会在这里栽跟头。
2.4. 查监控平台:redis连接池
排除了代码层面上该接口的问题,那只能从运维侧看看执行redis命令慢的问题了,正好监控平台上有mysql、redis连接池的监控。不看不知道,一看吓一跳。
在出问题时间段,redis连接数瞬间飙升,直接超过了最大空闲连接数。在时间节点上,和产线出现慢响应的时间完全吻合。
可以推测出,这段时间可能执行了某些奇怪的命令,造成了redis阻塞,其他redis请求只能频繁的创建新的连接,从而导致redis连接池中连接数飙升。
想要推测那段时间redis经历了什么,只能托付于运维的同事了。
2.5. 运维:查redis慢请求
通过从运维同事导出来的,那段时间redis执行过的慢请求日志,果然和预想的一样。那段时间执行了大量的慢请求命令,尤其是一段 lrange
命令,每次执行时间都超过了300ms,一分钟执行了几百次。
通过具体的redis命令,倒推找到了对应的代码,该代码对应的其实是一段对应用户登录后,通过MQ异步刷新用户权限的逻辑。因为是异步消费,所以就算执行的慢,也并不会因为响应时间阈值而被告警。
再结合 ELK 中有关该接口的调用日志,可以还原出问题发生的完整过程。
2.6. 场景还原
该 lrange
命令单独执行还行,可那段时间在产线有大批量用户的登录并发,导致该慢请求命令阻塞住了redis,大量redis请求都在阻塞排队,redis连接池中连接数也在不断扩展。
所以说,那段时间所有的redis请求命令,都会因为阻塞而延迟执行完成。告警的那个接口属于“躺枪”,因为它调用的并发高,所以表现显著,被告警程序当典型抓住了。
如果没有这一步步排查,很难相信一个API的告警,是由于另外一个毫无关系的API影响的。
3. 解决
3.1. 解决
lrange
是时间复杂度为 O(n) 的命令,原则上是不应该被频繁调用的。分析代码上下文逻辑,其实只是为了全量存储和读取 List 类型数据。完全可以用redis中的 String 代替 List。
对于redis 中 keys *
、flushdb
、flushall
等超耗时的命令,可以直接作为禁用命令,维护进 redis.conf
的禁用命令清单中。
但像 lrange
这种可以用,但要严格审视应用场景的命令,就需要研发人员特别注意。下面整理了一下redis常见的 O(n) 命令。
3.2. O(n) 命令
- String: MSET、MSETNX、MGET
- List: LPUSH、RPUSH、LRANGE、LINDEX、LSET、LINSERT
- Hash: HDEL、HGETALL、HKEYS/HVALS
- Set: SADD、SREM、SRANDMEMBER、SPOP、SMEMBERS、SUNION/SUNIONSTORE、SINTER/SINTERSTORE、SDIFF/SDIFFSTORE
- Sorted Set: ZADD、ZREM、ZRANGE/ZREVRANGE、ZRANGEBYSCORE/ZREVRANGEBYSCORE、ZREMRANGEBYRANK/ZREMRANGEBYSCORE
3.3. 其他
因为Spring中 Lettuce 连接池的bug,公司要求都改回 Jedis 连接池。感觉在该问题的避免上,Jedis 连接池应该也有优化空间。待后续实践后再分享。
**粗体** _斜体_ [链接](http://example.com) `代码` - 列表 > 引用
。你还可以使用@
来通知其他用户。