Readiness failed: brokerState is 2

[teimyBr]

We have Kafka Broker what is not getting healthy because of Readiness Probe fails

curl: (22) The requested URL returned error: 503

Have Investagating a little bit the Readiness lead to

kafka_readiness.sh -> kafka_readiness_kraft.sh -> curl http://localhost:8080/v1/ready/ --fail

executing this curl http://localhost:8080/v1/ready/ in Kafka Shell give this Info

Readiness failed: brokerState is 2

Any Idea how to fix that ?

[scholzj]

Please share full configurations and full logs from the operator, brokers, etc.! Without that, nobody can tell you anything more detailed than that your readiness is failing.

[teimyBr]

{"@timestamp":"2025-02-12T14:20:38.477Z","source_host":"kafka-kafka-3","file":"CruiseControlMetricsReporter.java","method":"onCompletion","level":"WARN","line_number":"465","thread_name":"kafka-producer-network-thread | CruiseControlMetricsReporter","@version":1,"logger_name":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter","message":"Failed to send Cruise Control metric: [PARTITION_METRIC,PARTITION_SIZE,time=1739369918348,brokerId=3,partition=test-topic1,value=0.000], cause of failure: Expiring 4117 record(s) for strimzi.cruisecontrol.metrics-0:120005 ms has passed since batch creation","class":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter$1","mdc":{}}
{"@timestamp":"2025-02-12T14:20:38.477Z","source_host":"kafka-kafka-3","file":"CruiseControlMetricsReporter.java","method":"onCompletion","level":"WARN","line_number":"465","thread_name":"kafka-producer-network-thread | CruiseControlMetricsReporter","@version":1,"logger_name":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter","message":"Failed to send Cruise Control metric: [PARTITION_METRIC,PARTITION_SIZE,time=1739369918348,brokerId=3,partition=test-topic2,value=0.000], cause of failure: Expiring 4117 record(s) for strimzi.cruisecontrol.metrics-0:120005 ms has passed since batch creation","class":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter$1","mdc":{}}
{"@timestamp":"2025-02-12T14:20:38.477Z","source_host":"kafka-kafka-3","file":"CruiseControlMetricsReporter.java","method":"onCompletion","level":"WARN","line_number":"465","thread_name":"kafka-producer-network-thread | CruiseControlMetricsReporter","@version":1,"logger_name":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter","message":"Failed to send Cruise Control metric: [PARTITION_METRIC,PARTITION_SIZE,time=1739369918348,brokerId=3,partition=test-topic3,value=0.000], cause of failure: Expiring 4117 record(s) for strimzi.cruisecontrol.metrics-0:120005 ms has passed since batch creation","class":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter$1","mdc":{}}
{"@timestamp":"2025-02-12T14:20:38.477Z","source_host":"kafka-kafka-3","file":"CruiseControlMetricsReporter.java","method":"onCompletion","level":"WARN","line_number":"465","thread_name":"kafka-producer-network-thread | CruiseControlMetricsReporter","@version":1,"logger_name":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter","message":"Failed to send Cruise Control metric: [PARTITION_METRIC,PARTITION_SIZE,time=1739369918348,brokerId=3,partition=test-topic5,value=0.000], cause of failure: Expiring 4117 record(s) for strimzi.cruisecontrol.metrics-0:120005 ms has passed since batch creation","class":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter$1","mdc":{}}
{"@timestamp":"2025-02-12T14:20:38.477Z","source_host":"kafka-kafka-3","file":"CruiseControlMetricsReporter.java","method":"onCompletion","level":"WARN","line_number":"465","thread_name":"kafka-producer-network-thread | CruiseControlMetricsReporter","@version":1,"logger_name":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter","message":"Failed to send Cruise Control metric: [BROKER_METRIC,BROKER_CPU_UTIL,time=1739369918348,brokerId=3,value=0.206], cause of failure: Expiring 4117 record(s) for strimzi.cruisecontrol.metrics-0:120005 ms has passed since batch creation","class":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter$1","mdc":{}}
{"@timestamp":"2025-02-12T14:20:38.477Z","source_host":"kafka-kafka-3","file":"CruiseControlMetricsReporter.java","method":"run","level":"WARN","line_number":"427","thread_name":"CruiseControlMetricsReporterRunner","@version":1,"logger_name":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter","message":"Failed to send 4117 metrics for time 1739369918348","class":"com.linkedin.kafka.cruisecontrol.metricsreporter.CruiseControlMetricsReporter","mdc":{}}

[teimyBr]

Thats the last logs.

[teimyBr]

strimzi.cruisecontrol.metrics topic is on that broker

[teimyBr]

{"instant":{"epochSecond":1739370270,"nanoOfSecond":499974047},"thread":"vert.x-eventloop-thread-1","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.assembly.AbstractOperator","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Reconciliation is in progress","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":37,"threadPriority":5}
{"instant":{"epochSecond":1739370276,"nanoOfSecond":544480157},"thread":"vert.x-eventloop-thread-0","level":"ERROR","loggerName":"io.strimzi.operator.cluster.operator.VertxUtil","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Exceeded timeout of 900000ms while waiting for Pods resource kafka-kafka-3 in namespace prod-backbone to be ready","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1739370276,"nanoOfSecond":544971571},"thread":"vert.x-eventloop-thread-0","level":"WARN","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaRoller","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Error waiting for pod prod-backbone/kafka-kafka-3 to become ready: io.strimzi.operator.common.TimeoutException: Exceeded timeout of 900000ms while waiting for Pods resource kafka-kafka-3 in namespace prod-backbone to be ready","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1739370276,"nanoOfSecond":684705864},"thread":"kafka-roller","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaRoller","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Will temporarily skip verifying pod kafka-kafka-3/3 is up-to-date due to io.strimzi.operator.cluster.operator.resource.KafkaRoller$UnforceableProblem: Pod kafka-kafka-3 is not ready because the Kafka node is performing log recovery. There are 0 logs and 0 segments left to recover., retrying after at least 250ms","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":193,"threadPriority":5}
{"instant":{"epochSecond":1739370277,"nanoOfSecond":334633140},"thread":"kafka-roller","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaRoller","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Will temporarily skip verifying pod kafka-kafka-0/0 is up-to-date due to ForceableProblem: Pod kafka-kafka-0 is the active controller and there are other pods to verify first, retrying after at least 250ms","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":193,"threadPriority":5}
{"instant":{"epochSecond":1739370278,"nanoOfSecond":553424671},"thread":"kafka-admin-client-thread | adminclient-2","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaAvailability","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): dataanalytics.out.user-bdpadhrpmappl-output/3 will be under-replicated (ISR={0,1}, replicas=[3,0,1], min.insync.replicas=2) if broker 1 is restarted.","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":2975,"threadPriority":5}
{"instant":{"epochSecond":1739370278,"nanoOfSecond":554093699},"thread":"kafka-roller","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaRoller","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Will temporarily skip verifying pod kafka-kafka-1/1 is up-to-date due to io.strimzi.operator.cluster.operator.resource.KafkaRoller$UnforceableProblem: Pod kafka-kafka-1 cannot be updated right now., retrying after at least 250ms","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":193,"threadPriority":5}
{"instant":{"epochSecond":1739370279,"nanoOfSecond":561934866},"thread":"kafka-admin-client-thread | adminclient-2","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaAvailability","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): dataanalytics.out.user-bdpadhrpmappl-output/4 will be under-replicated (ISR={1,2}, replicas=[1,3,2], min.insync.replicas=2) if broker 2 is restarted.","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":2975,"threadPriority":5}
{"instant":{"epochSecond":1739370279,"nanoOfSecond":562356894},"thread":"kafka-roller","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaRoller","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Will temporarily skip verifying pod kafka-kafka-2/2 is up-to-date due to io.strimzi.operator.cluster.operator.resource.KafkaRoller$UnforceableProblem: Pod kafka-kafka-2 cannot be updated right now., retrying after at least 250ms","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":193,"threadPriority":5}
{"instant":{"epochSecond":1739370279,"nanoOfSecond":848312941},"thread":"kafka-roller","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.resource.KafkaRoller","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Will temporarily skip verifying pod kafka-kafka-4/4 is up-to-date due to ForceableProblem: Pod kafka-kafka-4 is the active controller and there are other pods to verify first, retrying after at least 250ms","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":193,"threadPriority":5}
{"instant":{"epochSecond":1739370330,"nanoOfSecond":441465930},"thread":"vert.x-eventloop-thread-1","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.assembly.AbstractOperator","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Reconciliation is in progress","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":37,"threadPriority":5}
{"instant":{"epochSecond":1739370331,"nanoOfSecond":151746841},"thread":"vert.x-eventloop-thread-0","level":"INFO","loggerName":"io.strimzi.operator.cluster.ClusterOperator","message":"Triggering periodic reconciliation for namespace *","endOfBatch":false,"loggerFqcn":"org.apache.logging.log4j.spi.AbstractLogger","contextMap":{},"threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1739370390,"nanoOfSecond":441975425},"thread":"vert.x-eventloop-thread-1","level":"INFO","loggerName":"io.strimzi.operator.cluster.operator.assembly.AbstractOperator","marker":{"name":"Kafka(prod-backbone/kafka)"},"message":"Reconciliation #1(watch) Kafka(prod-backbone/kafka): Reconciliation is in progress","endOfBatch":false,"loggerFqcn":"io.strimzi.operator.common.ReconciliationLogger","contextMap":{},"threadId":37,"threadPriority":5}

Last Logs from the operator

[teimyBr]

Looks like a Pod kafka-kafka-3 is not ready because the Kafka node is performing log recovery. There are 0 logs and 0 segments left to recover.

[teimyBr]

Readiness failed: brokerState is 2 is now gone but now we have a other issue will create a new discussion for that