更新时间:2024-05-29 GMT+08:00

消息从生产到消费时延高达6分钟

问题现象

消息从生产到消费的端到端时延偶现到达6分钟,业务对消息时延较为敏感。

分析过程

  1. 怀疑是业务堆积,处理慢导致时延。

    通过查看监控数据,发现业务请求并不是很多,堆积最多时也只有50条消息,同时每秒新增消息只有10条左右,应该还没有到达处理极限。

  2. 排查EIP流量情况,发现入流量存在下降的场景。

    联系EIP服务技术人员协助排查,未发现问题。

  3. 从业务日志中分析消费组行为。

    通过查看服务端日志,消费组存在大量rebalance动作,大部分rebalance都会秒级完成,但偶尔会有分钟级别的rebalance耗时,而rebalance过程中是无法正常消费的,只有在rebalance动作完成才可以进行消费。

    该现象与问题现象描述的偶现长时间时延行为相吻合,问题确定。

详细分析

查看用户消费组行为日志文件,文件中存在以下三种日志:

  • Preparing to rebalance group 1

    表示消费组开始进行rebalance,消费组状态变更为REABLANCING。

  • Stabilized group

    表示消费组rebalance完成,消费组状态变更为STABILIZED。

  • Member consumer-xxx in group 1 has failed

    表示消费组内的某一个消费者超时退出,一般触发场景是消费者长时间没有与服务端通信导致,比如处理消息耗时太久阻塞等。

对文件中每次Preparing到Stabilized完成的时间进行计算得到以下结果图。图中时间为UTC+0时间

图1 消费组rebalance图

从以上图中可以看出,消费组rebalance的性能在7月1号06:49以后存在明显劣化的情况,导致客户端异常。

根因描述

用户业务中偶尔会存在某一个消费者无法及时响应rebalance的动作,导致整个消费组消费阻塞,一直到该消费者响应rebalance动作为止。

问题规避

  1. 建议用户根据业务区分不同消费组使用,降低单消费者阻塞导致的影响访问。
  2. max.poll.interval.ms用于设置消费组请求消费消息的最大时间间隔,如果消费者在超时前没有发起下一次消费请求,服务端会触发rebalance。调大max.poll.interval.ms的默认配置,降低问题频率。

问题解决措施

  1. 区分业务使用不同消费组。
  2. 需要客户侧排查自身业务,优化自身业务处理逻辑,提高处理效率,降低阻塞时间。

背景知识介绍

消费组可以简单认为有两种状态REBALANCING和STABILIZED。

  • REBALANCING:消费组元数据发生变化,该状态下消费组中的所有消费者都无法进行正常的业务消费,该场景触发场景为消费组内有新的消费者加入或有已经建立连接的消费者退出。
  • STABILIZED:rebalance完成,消费组处于稳定状态,该状态下消费组中的消费者可以进行正常的业务消费,触发条件是,当前消费组内的所有消费者都同步完成新的消费组元数据,包括之前已经同步过的消费者,也需要重新同步。

消费组简单流程如下:

  1. 有新的消费者加入或退出,服务端记录的消费组元数据更新,服务端更新消费组进入REBALANCING状态。
  2. 服务端等待所有消费者(包含已有的消费者)同步最新的元数据。
  3. 所有消费者同步完最新的元数据后,服务端更新消费组状态为STABILIZED。
  4. 消费者开始正常的消费业务。