Kafka Producer偶现ACK响应超时（10秒）问题排查求助

我们在AWS c5.4xlarge实例部署了3个Kafka 1.1.1版本Broker，集群包含750个主题、1800个分区，暂无法升级。有业务团队反馈，生产者设置acks=1时偶现ACK接收时间超过10秒，但ACK的p95响应时间仅约11ms，需排查原因。

环境信息 #

Java版本 #

openjdk version "1.8.0_382"
OpenJDK Runtime Environment (build 1.8.0_382-b05)
OpenJDK 64-Bit Server VM (build 25.382-b05, mixed mode)

Broker节点状态 #

Broker节点CPU使用率通常约3%，负载极低。

生产者侧日志（同步发送send().get()） #

2023-12-05 19:27:15.036 TRACE 1664 --- [ | TestProducer] o.a.k.clients.producer.internals.Sender  : [Producer clientId=TestProducer] Nodes with data ready to send: [kafka1:6667 (id: 1001 rack: us-west-2a)]
2023-12-05 19:27:15.036 TRACE 1664 --- [ | TestProducer] o.a.k.clients.producer.internals.Sender  : [Producer clientId=TestProducer] Sent produce request to 1001: (type=ProduceRequest, acks=1, timeout=30000, partitionRecords=({test-producer-2=[(record=DefaultRecord(offset=0, timestamp=1701804435036, key=0 bytes, value=3 bytes))]}), transactionalId=''
2023-12-05 19:27:25.062 TRACE 1664 --- [ | TestProducer] o.a.k.clients.producer.internals.Sender  : [Producer clientId=TestProducer] Received produce response from node 1001 with correlation id 59645
2023-12-05 19:27:25.062 TRACE 1664 --- [ | TestProducer] o.a.k.c.p.internals.ProducerBatch        : Successfully produced messages to test-producer-2 with base offset 283532.
2023-12-05 19:27:25.062  INFO 1664 --- [   scheduling-1] com.company.kafkatest.Service             : Publish completed in 10025ms, Start: 2023-12-05T19:27:15.036Z, End: 2023-12-05T19:27:25.062Z. Metadata test-producer-2@283532

核心现象：生产者19:27:15发送请求，19:27:25收到响应，总耗时10025ms。

Broker侧请求日志 #

Completed request:RequestHeader(apiKey=PRODUCE, apiVersion=5, clientId=TestProducer, correlationId=59645) -- {acks=1,timeout=30000,numPartitions=1},response:{responses=[{topic=produce-test,partition_responses=[{partition=2,error_code=0,base_offset=283532,log_append_time=-1,log_start_offset=91996}]}],throttle_time_ms=0} from connection 10.0.0.13:6667-[redacted broker IP]:37072-52576;totalTime:15.921,requestQueueTime:0.025,localTime:0.51,remoteTime:0.0,throttleTime:0.017,responseQueueTime:15.174,sendTime:0.213,securityProtocol:SASL_OAUTHBEARER,principal:User:[redacted],listener:SASL_OAUTHBEARER (kafka.request.logger)

核心数据：Broker处理该请求总耗时仅15.921ms，其中responseQueueTime占15.174ms，无节流、无错误码。

Broker非默认配置 #

num.partitions=3
num.recovery.threads.per.data.dir=32

# replica timings
max.incremental.fetch.session.cache.slots=20000
replica.lag.time.max.ms=90000
num.replica.fetchers=8
num.io.threads=16
num.network.threads=32
heartbeat.interval.ms=9000
session.timeout.ms=30000

生产者配置（1.1.1版本，acks=1） #

2023-12-05 19:24:58.971  INFO 1664 --- [   scheduling-1] o.a.k.clients.producer.ProducerConfig    : ProducerConfig values:
        acks = 1
        batch.size = 16384
        bootstrap.servers = [kafka1:6667, kafka2:6667, kafka3:6667]
        buffer.memory = 33554432
        client.id = TestProducer
        compression.type = none
        connections.max.idle.ms = 540000
        enable.idempotence = false
        interceptor.classes = []
        key.serializer = class org.apache.kafka.common.serialization.StringSerializer
        linger.ms = 0
        max.block.ms = 60000
        max.in.flight.requests.per.connection = 5
        max.request.size = 1048576
        metadata.max.age.ms = 300000
        metric.reporters = []
        metrics.num.samples = 2
        metrics.recording.level = INFO
        metrics.sample.window.ms = 30000
        partitioner.class = class org.apache.kafka.clients.producer.internals.DefaultPartitioner
        receive.buffer.bytes = 32768
        reconnect.backoff.max.ms = 1000
        reconnect.backoff.ms = 50
        request.timeout.ms = 30000
        retries = 0
        retry.backoff.ms = 100
        sasl.jaas.config = [hidden]

        [removed some sasl configs]

        sasl.kerberos.kinit.cmd = /usr/bin/kinit
        sasl.kerberos.min.time.before.relogin = 60000
        sasl.kerberos.service.name = null
        sasl.kerberos.ticket.renew.jitter = 0.05
        sasl.kerberos.ticket.renew.window.factor = 0.8
        sasl.mechanism = OAUTHBEARER
        security.protocol = SASL_OAUTHBEARER
        send.buffer.bytes = 131072
        ssl.cipher.suites = null
        ssl.enabled.protocols = [TLSv1.2, TLSv1.1, TLSv1]
        ssl.endpoint.identification.algorithm = null
        ssl.key.password = null
        ssl.keymanager.algorithm = SunX509
        ssl.keystore.location = null
        ssl.keystore.password = null
        ssl.keystore.type = JKS
        ssl.protocol = TLS
        ssl.provider = null
        ssl.secure.random.implementation = null
        ssl.trustmanager.algorithm = PKIX
        ssl.truststore.location = null
        ssl.truststore.password = null
        ssl.truststore.type = JKS
        transaction.timeout.ms = 60000
        transactional.id = null
        value.serializer = class org.apache.kafka.common.serialization.StringSerializer

JVM参数配置 #

KAFKA_HEAP_OPTS="-Xmx4G -Xms4G"
KAFKA_JVM_PERFORMANCE_OPTS="-server -XX:+UseCompressedOops -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+CMSClassUnloadingEnabled -XX:+CMSScavengeBeforeRemark -XX:+DisableExplicitGC -Djava.awt.headless=true"

排查方向建议 #

1. 网络链路排查：抓取生产者和Broker侧对应时间段的tcpdump包，分析是否存在网络丢包、重传或链路延迟。虽然Broker处理耗时极短，但数据包可能在AWS网络、安全组等中间环节出现延迟。
2. Broker响应队列监控：查看Broker指标kafka.network:type=RequestMetrics,name=ResponseQueueTimeMs的最大值，确认是否偶发出现响应队列阻塞，比如大请求占用资源导致小请求延迟发送。
3. 生产者Sender线程阻塞排查：检查生产者JVM的GC日志，确认是否有长时间CMS停顿；排查SASL OAUTHBEARER认证环节是否偶发token获取超时，导致Sender线程阻塞。
4. 版本已知Bug核对：查阅Kafka 1.1.1官方Release Notes，确认是否存在与Sender线程唤醒、连接池管理相关的已知Bug，比如max.in.flight.requests.per.connection配置导致的请求排队问题。
5. 时间同步校验：确认生产者和Broker的系统时间是否同步，避免时间偏差导致的日志时间误导。

内容的提问来源于stack exchange，提问作者jsmaupin