kafka故障排查-consumer處理超時導致的異常

最近遇到一個kafka方面的問題，大致就是由于consumer處理業務超時，導致無法正常提交Offset，進而導致無法消費新消息的問題。下面我想從以下幾個方面對此次故障排查進行復盤分析：業務背景、問題描述、排查思路、經驗教訓。

一、業務背景

先簡單描述一下業務背景吧。我們有個業務需要嚴格按順序消費Topic消息，所以針對該topic設置了唯一的partition，以及唯一的副本。當同一個消費組的多個consumer啟動時，只會有一個consumer訂閱到該Topic，進行消費，保證同一個消費組內的消費順序。
注：消費組的groupId名稱為“smart-building-consumer-group”，訂閱的Topic名稱為“gate_contact_modify”。

二、問題描述

有一天我們突然收到一個問題反饋：producer側的業務產生消息后，consumer側并沒有得到預期的結果。經過排查，排除了業務邏輯出現問題的可能性，我們判斷最有可能是因為kafka消息沒有被消費到。為了印證這個猜測，我們查看了consumer消費日志，發現日志中存在這樣幾處問題：
（1）日志偶爾會打印出一條Kafka的警告日志，內容為：
org.springframework.kafka.KafkaListenerEndpointContainer#2-0-C-1 org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.maybeAutoCommitOffsetsSync:648 - Auto-commit of offsets {gate_contact_modify-0=OffsetAndMetadata{offset=2801, metadata=''}} failed for group smart-building-consumer-group: Commit cannot be completed since the group has already rebalanced and assigned the partitions to another member. This means that the time between subsequent calls to poll() was longer than the configured max.poll.interval.ms, which typically implies that the poll loop is spending too much time message processing. You can address this either by increasing the session timeout or by reducing the maximum size of batches returned in poll() with max.poll.records.
（2）接著進行了一次rebalance；
（3）consumer側輸出了Topic消費者的業務日志，表明正常獲取到了Topic消息。
接著我們查看kafka 消費組中該Topic對應的Offset的變化情況，發現Offset一直沒有變化。

三、排查思路

日志中的異常信息很明確的告知我們，topic消息消費完成后，由于group發生了一次rebalance，導致Commit沒有被提交，這表明兩次poll消息的間隔時間超過了max.poll.interval.ms定義的最大間隔，這也意味著一次poll后處理消息的過程超時了，正是由于poll間隔時間超時，導致了一次rebalance。同時建議我們要么增加間隔時間，要么減少每次拉取的最大消息數。
另外，由于Commit沒有被提交，導致OffSet值沒有變化，那么每次拉取到的消息都是同一批重復消息。具體的異常流程如下圖：

根據上述信息，我們進一步檢查了consumer的max.poll.records配置、max.poll.interval.ms配置，并統計了每條Topic消息的處理耗時，發現max.poll.records使用了默認配置值500，max.poll.interval.ms使用了默認配置值為300s，而每條Topic消息的處理耗時為10S。這進一步證實了我們的推論：
由于每次拉取的消息數太多，而每條消息處理時間又較長，導致每次消息處理時間超過了拉取時間間隔，從而使得group進行了一次rebalance，導致commit失敗，并最終導致下次拉取重復的消息、繼續處理超時，進入一個死循環狀態。
知道問題根源后，我們結合業務特點，更改了max.poll.records=1，每次僅拉取一條消息進行處理，最終解決了這個問題。

四、經驗教訓

這次故障排查，使我們對Kafka消息poll機制、rebalance和commit之間的相互影響等有了更深的理解。
（1）kafka每次poll可以指定批量消息數，以提高消費效率，但批量的大小要結合poll間隔超時時間和每條消息的處理時間進行權衡；
（2）一旦兩次poll的間隔時間超過閾值，group會認為當前consumer可能存在故障點，會觸發一次rebalance，重新分配Topic的partition；
（3）如果在commit之前進行了一次rebalance，那么本次commit將會失敗，下次poll會拉取到舊的數據（重復消費），因此要保證好消息處理的冪等性；