Hi,
I'm running some tests with Kafka (4 broker setup, version 3.2.0) using
kafka-consumer-perf-test.sh. After starting it multiple times in sequence with
e.g.
kafka-consumer-perf-test.sh --bootstrap-server <BROKER_IP>:9092 --topic
test-topic --messages 5000 --show-detailed-stats --print-metrics
then it often works, but sometimes times out without consuming messages. The
test-topic topic has three partitions with three replicas each, and as part of
a previous test I ran a partition reassignment on this topic from brokers 0,1,2
to 1,2,3.
The detailed metrics in the end include
consumer-coordinator-metrics:failed-rebalance-rate-per-hour:{client-id=perf-consumer-client}
: 8635.055
consumer-coordinator-metrics:failed-rebalance-total:{client-id=perf-consumer-client}
: 95.000
and by running it with the logging level set to DEBUG, I repeatedly get the
following lines in the log (broker IP redacted):
[2022-08-03 17:29:03,517] INFO [Consumer clientId=perf-consumer-client,
groupId=perf-consumer-61424] Requesting disconnect from last known coordinator
<IP_ADDRESS>:9092 (id: 2147483645 rack: null)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
[2022-08-03 17:29:03,614] INFO [Consumer clientId=perf-consumer-client,
groupId=perf-consumer-61424] Discovered group coordinator <IP_ADDRESS>:9092
(id: 2147483645 rack: null)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
[2022-08-03 17:29:03,615] INFO [Consumer clientId=perf-consumer-client,
groupId=perf-consumer-61424] (Re-)joining group
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
[2022-08-03 17:29:03,617] INFO [Consumer clientId=perf-consumer-client,
groupId=perf-consumer-61424] Group coordinator <IP_ADDRESS>:9092 (id:
2147483645 rack: null) is unavailable or invalid due to cause: error response
NOT_COORDINATOR.isDisconnected: false. Rediscovery will be attempted.
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
[2022-08-03 17:29:03,617] INFO [Consumer clientId=perf-consumer-client,
groupId=perf-consumer-61424] Requesting disconnect from last known coordinator
<IP_ADDRESS>:9092 (id: 2147483645 rack: null)
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
[2022-08-03 17:29:03,617] INFO [Consumer clientId=perf-consumer-client,
groupId=perf-consumer-61424] JoinGroup failed: This is not the correct
coordinator. Marking coordinator unknown. Sent generation was
Generation{generationId=-1, memberId='', protocol='null'}
(org.apache.kafka.clients.consumer.internals.ConsumerCoordinator)
Am I missing some obvious problem here? Is there something I could look for in
the broker logs to give me a hint of what is causing this?
Thanks in advance,
Afonso
