[ https://issues.apache.org/jira/browse/KAFKA-7802?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17732540#comment-17732540 ]
Lubos Hozzan commented on KAFKA-7802: ------------------------------------- Hello. The problem is still persistent. We using version *3.4.1* in KRaft mode (3 instances in Kubernetes cluster). Warning looks like (in fact, it is avalanche of same or very similar records from each Kafka instance): {noformat} [2023-06-13 12:21:25,771] WARN [ReplicaFetcher replicaId=0, leaderId=2, fetcherId=0] Error in response for fetch request (type=FetchRequest, replicaId=0, maxWait=500, minBytes=1, maxBytes=10485760, fetchData={tsttopic-1=PartitionData(topicId=4UDBTCegTPy5mdCbL5fLyg, fetchOffset=0, logStartOffset=0, maxBytes=1048576, currentLeaderEpoch=Optional[6], lastFetchedEpoch=Optional.empty)}, isolationLevel=READ_UNCOMMITTED, removed=, replaced=, metadata=(sessionId=INVALID, epoch=INITIAL), rackId=) (kafka.server.ReplicaFetcherThread) {noformat} Please, focus to the {{metadata}}: *{{sessionId=INVALID, epoch=INITIAL}}* This problem begin in empty cluster (= PVCs for instances pods are empty) at first start. Affected are all instances. I attempted: - restart instances one-by-one = no change - stop all instances at once and start them again at once = no change - stop all instances and delete PVCs (Kafka cluster start as a empty) = problem sometimes disappeared Is the problem in stored data? When problem disappeared, restarting instances not have effect, cluster is running fine. I mean, if instances made their folders structure correctly, they are working without any problems. Next strange thing based on my observation are metrics, particular {{BrokerTopicMetrics BytesInPerSec}}: !BytesInput.png! As you can see, when problem begin, it looks like, that cluster have two leaders (correct leader and some fake) and both generating the metrics (before 14:20). When problem disappeared (after 14:20), the metrics are emitted only from one instance, which was in the time elected leader. Hope that helps get closer to solve the problem. Best regards. > Connection to Broker Disconnected Taking Down the Whole Cluster > --------------------------------------------------------------- > > Key: KAFKA-7802 > URL: https://issues.apache.org/jira/browse/KAFKA-7802 > Project: Kafka > Issue Type: Bug > Components: core > Affects Versions: 2.1.0 > Reporter: Candice Wan > Priority: Critical > Attachments: BytesInput.png, thread_dump.log > > > We recently upgraded to 2.1.0. Since then, several times per day, we observe > some brokers were disconnected when other brokers were trying to fetch the > replicas. This issue took down the whole cluster, making all the producers > and consumers not able to publish or consume messages. It could be quickly > fixed by restarting the problematic broker. > Here is an example of what we're seeing in the broker which was trying to > send fetch request to the problematic one: > 2019-01-09 08:05:10.445 [ReplicaFetcherThread-0-3] INFO > o.a.k.clients.FetchSessionHandler - [ReplicaFetcher replicaId=1, leaderId=3, > fetcherId=0] Error sending fetch request (sessionId=937967566, epoch=1599941) > to node 3: java.io.IOException: Connection to 3 was disconnected before the > response was read. > 2019-01-09 08:05:10.445 [ReplicaFetcherThread-1-3] INFO > o.a.k.clients.FetchSessionHandler - [ReplicaFetcher replicaId=1, leaderId=3, > fetcherId=1] Error sending fetch request (sessionId=506217047, epoch=1375749) > to node 3: java.io.IOException: Connection to 3 was disconnected before the > response was read. > 2019-01-09 08:05:10.445 [ReplicaFetcherThread-0-3] WARN > kafka.server.ReplicaFetcherThread - [ReplicaFetcher replicaId=1, leaderId=3, > fetcherId=0] Error in response for fetch request (type=FetchRequest, > replicaId=1, maxWait=500, minBytes=1, maxBytes=10485760, > fetchData={__consumer_offsets-11=(offset=421032847, logStartOffset=0, > maxBytes=1048576, currentLeaderEpoch=Optional[178])}, > isolationLevel=READ_UNCOMMITTED, toForget=, metadata=(sessionId=937967566, > epoch=1599941)) > java.io.IOException: Connection to 3 was disconnected before the response > was read > at > org.apache.kafka.clients.NetworkClientUtils.sendAndReceive(NetworkClientUtils.java:100) > at > kafka.server.ReplicaFetcherBlockingSend.sendRequest(ReplicaFetcherBlockingSend.scala:99) > at > kafka.server.ReplicaFetcherThread.fetchFromLeader(ReplicaFetcherThread.scala:199) > at > kafka.server.AbstractFetcherThread.kafka$server$AbstractFetcherThread$$processFetchRequest(AbstractFetcherThread.scala:241) > at > kafka.server.AbstractFetcherThread$$anonfun$maybeFetch$1.apply(AbstractFetcherThread.scala:130) > at > kafka.server.AbstractFetcherThread$$anonfun$maybeFetch$1.apply(AbstractFetcherThread.scala:129) > at scala.Option.foreach(Option.scala:257) > at > kafka.server.AbstractFetcherThread.maybeFetch(AbstractFetcherThread.scala:129) > at kafka.server.AbstractFetcherThread.doWork(AbstractFetcherThread.scala:111) > at kafka.utils.ShutdownableThread.run(ShutdownableThread.scala:82) > > > Below is the suspicious log of the problematic broker when the issue > happened: > 2019-01-09 08:04:50.177 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-2-7d46fda9-afef-4705-b632-17f0255d5045 in group talon-instance1 has > failed, rem > oving it from the group > 2019-01-09 08:04:50.177 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Preparing to > rebalance group talon-instance1 in state PreparingRebalance with old > generation 27 > 0 (__consumer_offsets-47) (reason: removing member > consumer-2-7d46fda9-afef-4705-b632-17f0255d5045 on heartbeat expiration) > 2019-01-09 08:04:50.297 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-5-94b7eb6d-bc39-48ed-99b8-2e0f55edd60b in group > Notifications.ASIA1546980352799 has failed, removing it from the group > 2019-01-09 08:04:50.297 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Preparing to > rebalance group Notifications.ASIA1546980352799 in state PreparingRebalance > with old generation 1 (__consumer_offsets-44) (reason: removing member > consumer-5-94b7eb6d-bc39-48ed-99b8-2e0f55edd60b on heartbeat expiration) > 2019-01-09 08:04:50.297 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Group > Notifications.ASIA1546980352799 with generation 2 is now empty > (__consumer_offsets-44) > 2019-01-09 08:04:50.388 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-3-0a4c55c2-9f31-4e7a-b0d7-1f057dceb03d in group talon-instance1 has > failed, removing it from the group > 2019-01-09 08:04:50.419 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-1-f7253f75-c626-47b1-842e-4eca3b0551c4 in group talon-kafka-vision > has failed, removing it from the group > 2019-01-09 08:04:50.419 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Preparing to > rebalance group talon-kafka-vision in state PreparingRebalance with old > generation 9 (__consumer_offsets-26) (reason: removing member > consumer-1-f7253f75-c626-47b1-842e-4eca3b0551c4 on heartbeat expiration) > 2019-01-09 08:04:50.419 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Group > talon-kafka-vision with generation 10 is now empty (__consumer_offsets-26) > 2019-01-09 08:04:50.419 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-2-5e7d051c-be6c-4893-bdaf-16ea180a54d9 in group > talon-hades-instance1 has failed, removing it from the group > 2019-01-09 08:04:50.419 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Preparing to > rebalance group talon-hades-instance1 in state PreparingRebalance with old > generation 122 (__consumer_offsets-11) (reason: removing member > consumer-2-5e7d051c-be6c-4893-bdaf-16ea180a54d9 on heartbeat expiration) > 2019-01-09 08:04:50.419 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Group > talon-hades-instance1 with generation 123 is now empty (__consumer_offsets-11) > 2019-01-09 08:04:50.422 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-4-a527e579-7a14-471b-b19d-ffec50074bb8 in group talon-instance1 has > failed, removing it from the group > 2019-01-09 08:04:50.434 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-4-0c470e05-5e9a-4cae-a493-9854a6d0c8a7 in group talon-instance1 has > failed, removing it from the group > 2019-01-09 08:04:50.514 [executor-Heartbeat] INFO > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Member > consumer-2-155ea6c8-c90f-4af6-b65e-138a151d77d9 in group talon-instance1 has > failed, removing it from the group > 2019-01-09 08:04:55.297 [executor-Produce] WARN > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Failed to write > empty metadata for group Notifications.ASIA1546980352799: The group is > rebalancing, so a rejoin is needed. > 2019-01-09 08:04:55.419 [executor-Produce] WARN > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Failed to write > empty metadata for group talon-kafka-vision: The group is rebalancing, so a > rejoin is needed. > 2019-01-09 08:04:55.420 [executor-Produce] WARN > k.coordinator.group.GroupCoordinator - [GroupCoordinator 3]: Failed to write > empty metadata for group talon-hades-instance1: The group is rebalancing, so > a rejoin is needed. > > We also took the thread dump of the problematic broker (attached). We found > all the kafka-request-handler were hanging and waiting for some locks, which > seemed to be a resource leak there. > > The java version we are running is 11.0.1 -- This message was sent by Atlassian Jira (v8.20.10#820010)