Kafka Broker kept crashing by Operator every 14min

[srujan07]

Hi Team,

We were facing an issue with one of our kafka cluster managing by Strimzi operator v0.27.1. One of our kafka brokers pods(sac-cluster-kafka-2) got abruptly restarted and since then we started seeing errors like "error getting broker config". Also post restart, the pod took more than 30 min to come up with ready status and since it takes longer time to get ready, the operator had to forcefully restart after making several attempts. This went in an infinite loop for so long until we stopped the operator pod. Then the broker got enough time to come up with ready status while the operator pod was stopped. So we wanted to understand few things here.

1. Why the broker pod(sac-cluster-kafka-2) was restarted at the first place even without making any changes in the CR or pod deployment?
2. Why the Operator pod can't wait for the pod to come up with ready status. The expectation here is that the operator should be aware that broker pods takes longer time to get ready especially when it has more data/topics/partition logs to recover after restart. It shouldn't kill when the broker pod is actually doing it's recovery job.
3. Our operator pod is still not running as we are worried that it would cause the same problem again like restarting pods. We wanted to understand the root cause before we get confidence to bring that back up.

Appreciate your help and advice on this. This happened in our prod cluster and any quicker response would be really appreciated.

Error Logs when this issue occured.

"2022-10-18 22:28:12 DEBUG KafkaRoller:275 - Reconciliation #11300(timer) Kafka(sedsac-prod-infra/sac-cluster): Considering restart of pod 2 after delay of 0 MILLISECONDS",
2022-10-18 22:28:12 DEBUG KafkaAssemblyOperator:3558 - Reconciliation #11300(timer) Kafka(sedsac-prod-infra/sac-cluster): Rolling update of sedsac-prod-infra/sac-cluster-kafka: pod sac-cluster-kafka-2 has strimzi.io/generation=8; sts has strimzi.io/generation=8"
"2022-10-18 22:28:12 DEBUG KafkaAssemblyOperator:3686 - Reconciliation #11300(timer) Kafka(sedsac-prod-infra/sac-cluster): Rolling update of sedsac-prod-infra/sac-cluster-kafka: pod sac-cluster-kafka-2 has strimzi.io/custom-listener-cert-thumbprints=; sts has strimzi.io/custom-listener-cert-thumbprints=",
"2022-10-18 22:28:14 DEBUG PoolThreadCache:224 - Freed 15 thread-local buffer(s) from thread: epollEventLoopGroup-11174-1",
"2022-10-18 22:28:42 DEBUG Reflector:125 - Event received MODIFIED Pod resourceVersion 1625617886",
"2022-10-18 22:28:42 DEBUG StrimziPodSetController:165 - Pod sac-cluster-kafka-2 in namespace sedsac-prod-infra was MODIFIED",
"2022-10-18 22:28:42 DEBUG StrimziPodSetController:182 - Pod sac-cluster-kafka-2 in namespace sedsac-prod-infra which was MODIFIED does not seem to be controlled by any StrimziPodSet and will be ignored",
"2022-10-18 22:28:42 INFO  KafkaRoller:299 - Reconciliation #11300(timer) Kafka(sedsac-prod-infra/sac-cluster): Could not roll pod 2 due to io.strimzi.operator.cluster.operator.resource.KafkaRoller$ForceableProblem: Error getting broker config, retrying after at least 250ms",
"2022-10-18 22:28:42 DEBUG KafkaRoller:275 - Reconciliation #11300(timer) Kafka(sedsac-prod-infra/sac-cluster): Considering restart of pod 3 after delay of 0 MILLISECONDS",

Please do let me know if you need any additional information.

[scholzj]

The Kafka broker was probably uncleanly shutdown as you say and now needs long startup time to recover the indexes. The operator currently doesn't handle it well - this is a known issue (I do not have the issue number at hand right now, sorry). You should stop the oeprator or pause the reconciliation for a while until the broker recovers to avoid this issue.

[srujan07]

@scholzj , thanks for confirming this is a known bug. Can you confirm if this is fixed in the latest versions? Also can you please let us know if there is a way to reduce the recovery time of a broker after every restart.

[srujan07]

We are actually looking for a permanent solution to avoid this in future. Do you think increasing the readiness probe of Kafka pods would help avoiding this problem?

[scholzj]

I don't think there is any permanent solution -> ideally in the first place, you should not have the broker to recover the data. But apart from that it is a bug which needs to be fixed.

[srujan07]

@scholzj got it, is it possible to skip recovering the data post restart or any way to minimize the recovery time?

[scholzj]

No. If the shurdown was unclean, this is needed.

[srujan07]

@scholzj Is this issue fixed in the latest operator v0.32.0? If not, is there any ETA when can we expect this fix?

[scholzj]

Well, first of all, you did not share any logs. So it is quite hard to confirm what exactly the issue is. If it was the issue I suggested, then no, that was not fixed.

[srujan07]

@scholzj We were able to recover our cluster by pausing the operator. Since this is a known issue with handling unclean shutdown of Kafka brokers, we would like to know if this is prioritised or any ETA when can we expect the fix.

[scholzj]

I don't have any ETA for this.