Kafka Readiness Issue

General
1

Dear MOSIP Team,

We are facing issues with Kafka pods since 6 weeks. Prior it was all working fine. Now it restarts and takes longer time to become healthy.

Issue

Kafka broker (5-broker StatefulSet, ~1,977 partitions each, image mosipint/kafka:3.2.1-debian-11-r9, NFSv4 storage via nfs-client provisioner) takes 1–3+ hours to recover on restart, instead of minutes. Progress shows in logs (N/1977 loaded) but with intermittent multi-minute gaps.

Root cause

  • NFS server’s nfsd thread pool (default 8) exhausted under 5 concurrent brokers’ recovery I/O
  • NFSv4’s stateful lease-renewal occasionally lost under this load (__nfs4_reclaim_open_state: Lock reclaim failed!)
  • Kafka’s default livenessProbe.failureThreshold: 3 (30s) killed the broker mid-recovery during legitimate I/O stalls, forcing restarts that couldn’t resume cleanly — turning a slow recovery into a repeating cycle

Fixes applied

  • nfsd threads: 8 → 16
  • livenessProbe.failureThreshold: 3 → 45 (biggest single improvement — let the broker survive stalls instead of being killed)
  • I/O scheduler on NFS disk: none → mq-deadline
  • NFS lease/grace time: 90s → 120s

Even after applying above fixed, the issue is not resolved.

Here is the log for your review and guidance. Attaching the last 50 lines as there is no option to upload the entire log.

[2026-10-07 07:10:25,174] INFO [LogLoader partition=bio-dedupe-update-bus-out-5, dir=/bitnami/kafka/data] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,181] INFO Completed load of Log(dir=/bitnami/kafka/data/bio-dedupe-update-bus-out-5, topicId=jA0gi8SBSkOixso-G9OD2A, topic=bio-dedupe-update-bus-out, partition=5, highWatermark=0, lastStableOffset=0, logStartOffset=0, logEndOffset=0) with 1 segments in 25ms (1548/1977 loaded in /bitnami/kafka/data) (kafka.log.LogManager)
[2026-10-07 07:10:25,188] INFO [LogLoader partition=packet-classifier-bus-in-12, dir=/bitnami/kafka/data] Recovering unflushed segment 26 (kafka.log.LogLoader)
[2026-10-07 07:10:25,188] INFO [LogLoader partition=packet-classifier-bus-in-12, dir=/bitnami/kafka/data] Loading producer state till offset 26 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,188] INFO [LogLoader partition=packet-classifier-bus-in-12, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 26 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,190] INFO Deleted producer state snapshot /bitnami/kafka/data/packet-classifier-bus-in-12/00000000000000000027.snapshot (kafka.log.SnapshotFile)
[2026-10-07 07:10:25,193] INFO [ProducerStateManager partition=packet-classifier-bus-in-12] Wrote producer snapshot at offset 26 with 0 producer ids in 3 ms. (kafka.log.ProducerStateManager)
[2026-10-07 07:10:25,193] INFO [LogLoader partition=packet-classifier-bus-in-12, dir=/bitnami/kafka/data] Producer state recovery took 2ms for snapshot load and 3ms for segment recovery from offset 26 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,207] INFO [ProducerStateManager partition=packet-classifier-bus-in-12] Wrote producer snapshot at offset 27 with 0 producer ids in 3 ms. (kafka.log.ProducerStateManager)
[2026-10-07 07:10:25,214] INFO [LogLoader partition=packet-classifier-bus-in-12, dir=/bitnami/kafka/data] Loading producer state till offset 27 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,214] INFO [LogLoader partition=packet-classifier-bus-in-12, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 27 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,215] INFO Deleted producer state snapshot /bitnami/kafka/data/packet-classifier-bus-in-12/00000000000000000026.snapshot (kafka.log.SnapshotFile)
[2026-10-07 07:10:25,215] INFO [ProducerStateManager partition=packet-classifier-bus-in-12] Loading producer state from snapshot file ‘SnapshotFile(/bitnami/kafka/data/packet-classifier-bus-in-12/00000000000000000027.snapshot,27)’ (kafka.log.ProducerStateManager)
[2026-10-07 07:10:25,216] INFO [LogLoader partition=packet-classifier-bus-in-12, dir=/bitnami/kafka/data] Producer state recovery took 2ms for snapshot load and 0ms for segment recovery from offset 27 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,218] INFO Completed load of Log(dir=/bitnami/kafka/data/packet-classifier-bus-in-12, topicId=rnBeR4ffRsSol2YEuiJ_xA, topic=packet-classifier-bus-in, partition=12, highWatermark=26, lastStableOffset=26, logStartOffset=26, logEndOffset=27) with 1 segments in 37ms (1549/1977 loaded in /bitnami/kafka/data) (kafka.log.LogManager)
[2026-10-07 07:10:25,227] INFO [LogLoader partition=packet-validator-opencrvs_new-bus-out-0, dir=/bitnami/kafka/data] Recovering unflushed segment 0 (kafka.log.LogLoader)
[2026-10-07 07:10:25,228] INFO [LogLoader partition=packet-validator-opencrvs_new-bus-out-0, dir=/bitnami/kafka/data] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,228] INFO [LogLoader partition=packet-validator-opencrvs_new-bus-out-0, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,228] INFO [LogLoader partition=packet-validator-opencrvs_new-bus-out-0, dir=/bitnami/kafka/data] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,242] INFO [LogLoader partition=packet-validator-opencrvs_new-bus-out-0, dir=/bitnami/kafka/data] Loading producer state till offset 0 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,242] INFO [LogLoader partition=packet-validator-opencrvs_new-bus-out-0, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,242] INFO [LogLoader partition=packet-validator-opencrvs_new-bus-out-0, dir=/bitnami/kafka/data] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,243] INFO Completed load of Log(dir=/bitnami/kafka/data/packet-validator-opencrvs_new-bus-out-0, topicId=bZTfE6CQRAKQb85V3VOmWQ, topic=packet-validator-opencrvs_new-bus-out, partition=0, highWatermark=0, lastStableOffset=0, logStartOffset=0, logEndOffset=0) with 1 segments in 25ms (1550/1977 loaded in /bitnami/kafka/data) (kafka.log.LogManager)
[2026-10-07 07:10:25,249] INFO [LogLoader partition=finalization-new-bus-out-13, dir=/bitnami/kafka/data] Recovering unflushed segment 19 (kafka.log.LogLoader)
[2026-10-07 07:10:25,249] INFO [LogLoader partition=finalization-new-bus-out-13, dir=/bitnami/kafka/data] Loading producer state till offset 19 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,249] INFO [LogLoader partition=finalization-new-bus-out-13, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 19 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,252] INFO [ProducerStateManager partition=finalization-new-bus-out-13] Wrote producer snapshot at offset 19 with 0 producer ids in 3 ms. (kafka.log.ProducerStateManager)
[2026-10-07 07:10:25,252] INFO [LogLoader partition=finalization-new-bus-out-13, dir=/bitnami/kafka/data] Producer state recovery took 0ms for snapshot load and 3ms for segment recovery from offset 19 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,267] INFO [LogLoader partition=finalization-new-bus-out-13, dir=/bitnami/kafka/data] Loading producer state till offset 19 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,267] INFO [LogLoader partition=finalization-new-bus-out-13, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 19 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,269] INFO Deleted producer state snapshot /bitnami/kafka/data/finalization-new-bus-out-13/00000000000000000019.snapshot (kafka.log.SnapshotFile)
[2026-10-07 07:10:25,269] INFO [LogLoader partition=finalization-new-bus-out-13, dir=/bitnami/kafka/data] Producer state recovery took 2ms for snapshot load and 0ms for segment recovery from offset 19 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,270] INFO Completed load of Log(dir=/bitnami/kafka/data/finalization-new-bus-out-13, topicId=ts2Edt2KRY28lqDIrVl6-Q, topic=finalization-new-bus-out, partition=13, highWatermark=19, lastStableOffset=19, logStartOffset=19, logEndOffset=19) with 1 segments in 26ms (1551/1977 loaded in /bitnami/kafka/data) (kafka.log.LogManager)
[2026-10-07 07:10:25,276] INFO [LogLoader partition=packet-uploader-bus-in-8, dir=/bitnami/kafka/data] Recovering unflushed segment 59 (kafka.log.LogLoader)
[2026-10-07 07:10:25,276] INFO [LogLoader partition=packet-uploader-bus-in-8, dir=/bitnami/kafka/data] Loading producer state till offset 59 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,276] INFO [LogLoader partition=packet-uploader-bus-in-8, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 59 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,279] INFO [ProducerStateManager partition=packet-uploader-bus-in-8] Wrote producer snapshot at offset 59 with 0 producer ids in 4 ms. (kafka.log.ProducerStateManager)
[2026-10-07 07:10:25,279] INFO [LogLoader partition=packet-uploader-bus-in-8, dir=/bitnami/kafka/data] Producer state recovery took 0ms for snapshot load and 3ms for segment recovery from offset 59 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,294] INFO [LogLoader partition=packet-uploader-bus-in-8, dir=/bitnami/kafka/data] Loading producer state till offset 59 with message format version 2 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,294] INFO [LogLoader partition=packet-uploader-bus-in-8, dir=/bitnami/kafka/data] Reloading from producer snapshot and rebuilding producer state from offset 59 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,295] INFO Deleted producer state snapshot /bitnami/kafka/data/packet-uploader-bus-in-8/00000000000000000059.snapshot (kafka.log.SnapshotFile)
[2026-10-07 07:10:25,295] INFO [LogLoader partition=packet-uploader-bus-in-8, dir=/bitnami/kafka/data] Producer state recovery took 1ms for snapshot load and 0ms for segment recovery from offset 59 (kafka.log.UnifiedLog$)
[2026-10-07 07:10:25,296] INFO Completed load of Log(dir=/bitnami/kafka/data/packet-uploader-bus-in-8, topicId=WqPwvbsqRG6gPj8BNakhgA, topic=packet-uploader-bus-in, partition=8, highWatermark=59, lastStableOffset=59, logStartOffset=59, logEndOffset=59) with 1 segments in 27ms (1552/1977 loaded in /bitnami/kafka/data) (kafka.log.LogManager)

Please advise, if we are missing out something.
Your prompt response will be appreciated.

Best Regards,
Ranjan

2

Hi @Ranjan_mosip ,

Thank you for reaching out to us and for sharing your query.

We have forwarded it to our subject matter expert for review. They will look into the details and get back to you shortly with the appropriate information and guidance.

We appreciate your patience and understanding in the meantime.

Warm regards,
Pragya
Community Manager
MOSIP