并行流导致接口慢调用问题

现象

2023.08.12 18:30 开始,桌位状态应用的请求量大幅增长,dubbo 线程数达到最大值,与此同时查询桌位状态接口出现大量慢调用。

调用量:
image.png
根据 ARMS 分析该接口的调用量在 18:31-18:41 出现断崖式增长,每分钟请求数从 5.1k 增加到 14.7k,10 分钟增长了 9.6k。(后续调查表明在该时间段内大部分接口调用量都出现了断崖式增长)
异常时刻的 qps 大致为 236.1,几乎是一周前的 2 倍。

响应时间:
image.png
每分钟响应时间平均为 3747 ms,整个异常过程中该接口最长的响应时间达到 8s 多。

dubbo 线程池:
image.png
所有接口的每分钟 dubbo 请求调用量在 18:35-18:45 内从 14.2k 增长至 35.6k
也是在这段时间内 dubbo 线程池被打满,在 18:40 左右基本被打满
image.png

排查

初步判断流量突增的原因是客户端开放灰度,使得预定业务中的一个轮询调用的接口调用次数上升。
该接口调用桌位状态服务的一个较为通用的查询接口,里面使用 parallelStream 来进行 RPC 调用获取账单。
parallelStream 使用与 CPU 核数一致的线程数来处理任务,当请求量增大时线程池中的线程全部被打满,导致后续的任务一直在排队等待延迟处理,最终 dubbo 线程池也被占满。

处理

从问题的核心代码到外部调用,可优化的点如下:

  1. 取消并行流
  2. 加大批量获取数,让调用量减小
  3. 经查看代码发现出现问题的使用并行流查账单是为了设置桌位状态的 payStatus,但是上层并不关心这个字段,所以可以让上层调用更轻量级的接口
  4. 降低客户端轮询次数,轮询调用需谨慎,轮询策略需要好好设计

2023.08.13(代码修改后)

141 部署了优化后的代码,取消了并行流,分页大小增加到 10
142 没有改动,以此作为对照。

总体应用每分钟调用量峰值也有 14.7k,但是 13 号这天的曲线明显更加平滑,没有出现 dubbo 线程池被打满的情况,慢调用的数量和时长都在正常范围内。

调用量:
image.png

响应时间:
141 比 142 更缓和

  • 141:

image.png

  • 142:

image.png

dubbo 线程数:

  • 141:

image.png

  • 142:

image.png

08.13 修改优化后至今,142 会依然出现一定量的慢调用,141 没有出现过
image.png

总结

这次问题应该是由于短时间内的调用量突增,加上使用并发流处理 RPC 调用引起的。
根据 13 号的对照来看,流量平滑增加的情况不会出现特别严重的线程池等待现象,但依然有慢调用,存在隐患。

取消并行流,增加分页大小的方案是可行的,以后并行流需要谨慎使用。后续也和客户端讨论了上层接口的调整方案。