背景
某個應用需要配置 Kafka 叢集資訊，且需要在驗證叢集是否可達。基本實現思路是建立一個生產者物件，然後傳送一條測試資料，呼叫 Producer 的 send 方法傳送訊息後，再呼叫 get() 方法，即同步傳送訊息，測試透過後再關閉 Producer 物件。
近期碰到了一個機器服務正常，非同步訊息能正常傳送，但是同步一直報異常：
org.apache.kafka.common.errors.TimeoutException: Expiring 1 record(s) for topicxxx-0: 20024 ms has passed since batch creation plus linger time
問題排查
Kafka 狀態正常，在機器 A 上使用生產者命令非同步傳送資料，Kafka伺服器上消費資料能正常消費：
應用透過同步傳送 API 時一直報超時異常。
解決辦法
調大生產者測試程式碼的超時時間：
//預設是30000ms
producerConfig.put("request.timeout.ms", "300000");
producerConfig.put("transaction.timeout.ms", "300000");
producerConfig.put("max.block.ms", "300000");
producerConfig.put("batch.size", "1048576");
producerConfig.put("linger.ms", "1");
producerConfig.put("buffer.memory", "33554432");
Kafka 生產者和消費者測試命令
對於包含認證的 Kafka 訪問自帶的生產者和消費者應用時，可以建立一個 config 配置檔案 config.properties ，內容主要是 Kafka 地址和訪問協議：
security.protocol=SASL_PLAINTEXT sasl.mechanism=SCRAM-SHA-256 sasl.jaas.config=org.apache.kafka.common.security.scram.ScramLoginModule required username="admin" password="xxx";
新增配置後，常用的三個命令也新增認證：
./kafka-topics.sh --bootstrap-server IP:PORT --list --command-config ../config/config.properties ./kafka-console-producer.sh --bootstrap-server IP:port --topic test-topic --producer.config ../config/config.properties ./kafka-console-consumer.sh --bootstrap-server IP:port --topic test-topic --consumer.config ../config/config.properties
啓示錄
排查這個問題的時候，我發現了一個顛覆之前對 Kafka 認知連線認知的資訊。之前以為 Kafka 使用 Java API 連線且設定了認證資訊後，只有在認證成功後纔會出現一句登入成功的日誌資訊：
AbstractLogin 類的 login 方法 53 行列印的：
Successfully logged in.
一直對這句話迷惑了，以為只有連線認證資訊正確纔會列印這句話呢，所以就沒有懷疑過認證資訊。後面試了一下其他正常的 Kafka 連線資訊，發現因網路問題，還是同樣的超時問題，而且這次輸入的 Kafka 認證資訊是錯誤了，但是日誌中也列印了登入成功的資訊。
在網路正常的環境下測試輸入錯誤的 Kafka 認證資訊，也列印這個日誌了，但是後面卻會出現認證失敗異常：
2024-10-26 06:48:55.431 [http-nio-xx-exec-2] INFO o.a.k.c.s.a.AbstractLogin - [login,53] - Successfully logged in. 2024-10-26 06:48:55.434 [http-nio-xx-exec-2] WARN o.a.k.c.p.ProducerConfig - [logUnused,246] - The configuration 'producer.type' was supplied but isn't a known config. 2024-10-26 06:48:55.435 [http-nio-xx-exec-2] INFO o.a.k.c.u.AppInfoParser - [<init>,109] - Kafka version : 1.0.2 2024-10-26 06:48:55.436 [http-nio-xx-exec-2] INFO o.a.k.c.u.AppInfoParser - [<init>,110] - Kafka commitId : 2a121f7b1d402825 2024-10-26 06:48:55.576 [kafka-producer-network-thread | producer-8] ERROR o.a.k.c.NetworkClient - [error,296] - [Producer clientId=producer-8] Connection to node -1 failed authentication due to: Authentication failed during authentication due to invalid credentials with SASL mechanism SCRAM-SHA-256
從日誌列印的執行緒來看，登入成功操作是在主執行緒中，真正的認證失敗資訊發生在生產者執行緒發生資料並呼叫 get() 方法獲取同步響應結果的時候。
再輸入一個無效的 Kafka 連線地址，照樣列印了登入成功資訊，只是生產者傳送時報 Broker 不可達：
2024-10-26 06:51:33.906 [http-nio-xx-exec-8] INFO o.a.k.c.s.a.AbstractLogin - [login,53] - Successfully logged in. 2024-10-26 06:51:33.909 [http-nio-xx-exec-8] WARN o.a.k.c.p.ProducerConfig - [logUnused,246] - The configuration 'producer.type' was supplied but isn't a known config. 2024-10-26 06:51:33.910 [http-nio-xx-exec-8] INFO o.a.k.c.u.AppInfoParser - [<init>,109] - Kafka version : 1.0.2 2024-10-26 06:51:33.910 [http-nio-xx-exec-8] INFO o.a.k.c.u.AppInfoParser - [<init>,110] - Kafka commitId : 2a121f7b1d402825 2024-10-26 06:51:53.930 [kafka-producer-network-thread | producer-9] WARN o.a.k.c.NetworkClient - [warn,241] - [Producer clientId=producer-9] Connection to node -1 could not be established. Broker may not be available.
結論：基本可以確定一個事實，當使用 Kafka 連線配置認證資訊時，無論什麼情況「1、密碼正確+地址正確；2、都錯誤；3、地址正確+密碼錯誤」，這句 「Successfully logged in」都會列印，沒有任何意義。
跟蹤原始碼可知，它只代表執行了 jaas 的 login 方法，實際沒有任何認證相關的操作。想起上週整理過阿里開發者規範的日誌規範，這句話應該屬於無效日誌。正確的日誌列印應該在真正資料傳送時且認證成功的地方列印登入成功纔是合理的。
