前言

先簡(jiǎn)單介紹下我們的使用場(chǎng)景，線上5臺(tái)Broker節(jié)點(diǎn)的kafka承接了所有binlog訂閱的數(shù)據(jù)，用于Flink組件接收數(shù)據(jù)做數(shù)據(jù)中臺(tái)的原始數(shù)據(jù)。昨兒開(kāi)發(fā)反饋，線上的binlog大量報(bào)錯(cuò)，都是kafka的異常，而且都是同一條topic拋的錯(cuò)，特征也很明顯，發(fā)送的消息體非常大，主觀判斷肯定是寫入大消息導(dǎo)致的超時(shí)了，異常詳情如下：

thread:  kafka-producer-network-thread | producer-1
throwable:  org.apache.kafka.common.errors.TimeoutException: Expiring 1 record(s) for BIN-LOG-DATA-center-dmz2-TABLE-kk-data-center-ods_contract_finance_info-0 due to 56352 ms has passed since last append

定位異常點(diǎn)

應(yīng)用拋一個(gè)不常見(jiàn)的異常，一般操作是先去百度or谷歌搜索一番的，就上面這個(gè)timeout超時(shí)的異常，搜索引擎的結(jié)果都是producer連不上Borker導(dǎo)致的問(wèn)題，根本不是我們這個(gè)場(chǎng)景的，所以其次我們就需要從源碼中尋找答案了。博主使用的開(kāi)發(fā)工具是IDEA，借助IDEA很容易定位到異常拋出點(diǎn)。首先定位TimeoutException異常類，然后按住ctrl鍵，點(diǎn)擊這個(gè)類，會(huì)出現(xiàn)如下圖所有拋TimeoutException異常的點(diǎn)，然后根據(jù)異常message內(nèi)容，尋找相匹配的點(diǎn)擊進(jìn)去就是拋異常的地方了，如圖，紅色箭頭所指即代碼位置：

分析拋異常的邏輯

程序中的異常，一定是符合某些條件才會(huì)拋出的，想要解決異常，只要讓運(yùn)行時(shí)的環(huán)境不滿足拋異常的條件即可，下面就是拋異常的代碼：

boolean maybeExpire(int requestTimeoutMs, long retryBackoffMs, long now, long lingerMs, boolean isFull) {
        if (!this.inRetry() && isFull && requestTimeoutMs < (now - this.lastAppendTime))
            expiryErrorMessage = (now - this.lastAppendTime) + " ms has passed since last append";
        else if (!this.inRetry() && requestTimeoutMs < (createdTimeMs(now) - lingerMs))
            expiryErrorMessage = (createdTimeMs(now) - lingerMs) + " ms has passed since batch creation plus linger time";
        else if (this.inRetry() && requestTimeoutMs < (waitedTimeMs(now) - retryBackoffMs))
            expiryErrorMessage = (waitedTimeMs(now) - retryBackoffMs) + " ms has passed since last attempt plus backoff time";

        boolean expired = expiryErrorMessage != null;
        if (expired)
            abortRecordAppends();
        return expired;
    }

可以看到，我們的異常是在第一個(gè)邏輯判斷時(shí)候就滿足了所以拋異常了。在此處有可能會(huì)拋出三個(gè)不同的timeout異常，用中文語(yǔ)義翻譯條件分別是：

• 沒(méi)設(shè)置重試，并且發(fā)送批次（batch.size）滿了，并且配置請(qǐng)求超時(shí)時(shí)間（request.timeout.ms）小于【當(dāng)前時(shí)間減去最后追加批次的時(shí)間】
• 沒(méi)設(shè)置重試，并且配置請(qǐng)求超時(shí)時(shí)間（request.timeout.ms）小于【創(chuàng)建批次時(shí)間減去配置的等待發(fā)送的時(shí)間（linger.ms）】
• 設(shè)置重試，并且配置請(qǐng)求超時(shí)時(shí)間（request.timeout.ms）小于【當(dāng)前時(shí)間-最后重試時(shí)間-重試需要等待的時(shí)間（retry.backoff.ms）】

上面括號(hào)中的參數(shù)就是kafka producer中配置的相關(guān)的參數(shù)，這些參數(shù)都沒(méi)有重新設(shè)置過(guò)，batch.size默認(rèn)是10kb大小，而引發(fā)報(bào)錯(cuò)的消息都是36kb的大小，默認(rèn)的request.timeout.ms超時(shí)設(shè)置是30s，所以在這個(gè)判斷可能過(guò)期了的方法中，引發(fā)我們異常的主要原因是batch.size和request.timeout.ms的參數(shù)設(shè)置問(wèn)題了。

真實(shí)原因-解決方案

從上面代碼看表面原因是參數(shù)設(shè)置不夠了，實(shí)際上呢，博主使用kafka-test啟動(dòng)了五個(gè)Borker集群做復(fù)現(xiàn)驗(yàn)證測(cè)試，測(cè)試寫入相同的36kb的message，在所有配置也保持默認(rèn)的情況下，也根本毫無(wú)壓力。后面查找相關(guān)的錯(cuò)誤日志，發(fā)現(xiàn)所有的TimeoutException集中在幾乎同一時(shí)刻，經(jīng)查明，是因?yàn)闃I(yè)務(wù)批量導(dǎo)入了數(shù)據(jù)到mysql中，造成binlog消息突然增加，高并發(fā)的往kafka寫大消息導(dǎo)致Borker處理不過(guò)來(lái)，造成的TimeoutException超時(shí)，所以真正解決問(wèn)題也可以從兩個(gè)方面入手：

• 服務(wù)端：增加Borker，并設(shè)置多個(gè)TopicPartition，平攤寫入壓力，這個(gè)是根本的解決問(wèn)題
• 客戶端：加大request.timeout.ms、batch.size參數(shù)，或者開(kāi)啟消息重試，這種方案治標(biāo)不治本，但是也能大概率的減少因?yàn)榇祟悎?chǎng)景導(dǎo)致的TimeoutException

結(jié)語(yǔ)

異常不可怕，所有異常都是人為拋的，都是有既定的觸發(fā)條件的，只要定位到觸發(fā)異常的條件對(duì)癥下藥即可解決問(wèn)題。不過(guò)博主五年來(lái)的經(jīng)驗(yàn)發(fā)現(xiàn)，日志打印真的是門藝術(shù)，在這個(gè)方面，Spring框架和Dubbo以及Apollo配置中心框架就是日志打印的典范，不管發(fā)生什么異常，日志里都會(huì)輸出詳細(xì)的上下文環(huán)境，異常的原因，建議的解決方法，如果涉及到相關(guān)的配置，也會(huì)打印該怎么配置最好。反觀kafka client的這條TimeoutException就顯的信息量有點(diǎn)過(guò)少了，如果能把相關(guān)的配置信息和排查的方向?qū)懨鲿?huì)更好。最后安利一波kafka test，輕松搭建多Borker的kafka集群，一個(gè)注解就ok了。詳情參考我的這篇博文《深入研究spring boot集成kafka之spring-kafka底層原理》

以上就是kafka并發(fā)寫大消息異常TimeoutException排查記錄的詳細(xì)內(nèi)容，更多關(guān)于kafka并發(fā)異常TimeoutException排查的資料請(qǐng)關(guān)注腳本之家其它相關(guān)文章！