Kafka inactive

[saloni-2404]

Hey Jakub,
We observed for 1 of kafka operator there was no any activity for almost 1 hour on production environment.

Observations:

1. Pods kafka-2 and zookeeper-2 restarted 32h ago, kafka exporter is continously restarting/crashing

2. Verbose logs from kafka-1 and kafka-2:

kafka-1:
2021-09-02 10:24:51,492 INFO Failed to delete log /var/lib/kafka/data/kafka-log1/__consumer_offsets-41/00000000000000000000.log.deleted because it does not exist. (kafka.log.LogSegment) [kafka-scheduler-8]
2021-09-02 10:24:51,493 INFO Failed to delete offset index /var/lib/kafka/data/kafka-log1/__consumer_offsets-41/00000000000000000000.index.deleted because it does not exist. (kafka.log.LogSegment) [kafka-scheduler-8]
2021-09-02 10:24:51,493 INFO Failed to delete time index /var/lib/kafka/data/kafka-log1/__consumer_offsets-41/00000000000000000000.timeindex.deleted because it does not exist. (kafka.log.LogSegment) [kafka-scheduler-8]

kafka-2:
2021-09-02 12:17:35,442 INFO Failed to delete log /var/lib/kafka/data/kafka-log2/__consumer_offsets-39/00000000240201648852.log.deleted because it does not exist. (kafka.log.LogSegment) [kafka-scheduler-2]
2021-09-02 12:17:35,442 INFO Failed to delete offset index /var/lib/kafka/data/kafka-log2/__consumer_offsets-39/00000000240201648852.index.deleted because it does not exist. (kafka.log.LogSegment) [kafka-scheduler-2]
2021-09-02 12:17:35,442 INFO Failed to delete time index /var/lib/kafka/data/kafka-log2/__consumer_offsets-39/00000000240201648852.timeindex.deleted because it does not exist. (kafka.log.LogSegment) [kafka-scheduler-2]

3. Logs from zookeeper pods:

zookeeper-1:
2021-09-01 15:39:50,430 WARN Connection broken for id 2, my id = 1, error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) [RecvWorker:2]
2021-09-01 15:51:34,609 WARN Connection broken for id 3, my id = 1, error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) [RecvWorker:3]

zookeeper-2:
2021-09-01 03:51:34,498 WARN Connection broken for id 3, my id = 2, error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) [RecvWorker:3]
2021-09-01 15:39:50,431 WARN Connection broken for id 1, my id = 2, error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) [RecvWorker:1]
2021-09-01 15:51:34,609 WARN Connection broken for id 3, my id = 2, error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) [RecvWorker:3]

zookeeper-3:
2021-09-01 15:51:34,611 WARN Connection broken for id 1, my id = 3, error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) [RecvWorker:1]
2021-09-01 15:51:34,611 WARN Connection broken for id 2, my id = 3, error = (org.apache.zookeeper.server.quorum.QuorumCnxManager) [RecvWorker:2]

4. Strimzi operator logs:

2021-09-01 23:34:24 ERROR Util:85 - Exceeded timeout of 300000ms while waiting for Deployment resource kafka-opstate-kafka-exporter in namespace sedsep-prod1 to be ready
2021-09-01 23:34:24 ERROR AbstractOperator:124 - Reconciliation #30269(timer) Kafka(sedsep-prod1/kafka-opstate): createOrUpdate failed

Attaching the complete logs of kafka, zookeeper, operator pods.

[saloni-2404]

kafka-0-logs.txt
kafka-1-logs.txt
kafka-2-logs.txt
zookeeper-0-logs.txt
zookeeper-1-logs.txt
operator-logs.txt
zookeeper-2-logs.txt

[scholzj]

I'm sorry, but can you please be a bit more specific about the issue? From your description it is not really clear to me what is the problem you are asking about.

[saloni-2404]

Hey Jakub, the application connecting to kafka, faced connection issues and went inactive for an hour, trying to understand what caused it.

Time message
Sep 1, 2021 @ 09:11:59.862 NetworkClient - [Producer clientId=producer-1] Connection to node 2 (kafka-cluster-kafka-2.kafka-cluster-kafka-brokers.ns.svc/240.1.11.39:9093) could not be established. Broker may not be available.

FetchSessionHandler - [Consumer clientId=consumer-1, groupId=oas-consumer] Error sending fetch request (sessionId=298312131, epoch=1947067) to node 2: org.apache.kafka.common.errors.DisconnectException.

We can see that the kafka-2 pod restarted hours ago, so that would explain the connection issue, but why it restarted is something we are trying to understand.

[scholzj]

but why it restarted is something we are trying to understand.

You would need to look into the logs - that should say why it was restarted.

[saloni-2404]

From the console logs, it appears that the pods kafka-2 and zookeeper-2 got deleted and recreated (not restarted, because the restart count =0) and were unavailable for a good 10mins. (The next set of logs started from 10mins later)
Is there any known bug that could cause this sort of an issue?

[scholzj]

Well, if the operator did it it should be in the operator log. Other option is that Kubernetes did it for example because of some node failure etc.