Crash loop with jbod cluster runs out of space

[robcxyz]

I have a strimzi cluster that I am doing some experimenting on to make sure I can recover if my jbod kafka data volumes fill up by adding another volume and I am stuck in a crash loop. When I initially crashed I had only 1 jbod volume and then I applied the config with a second jbod volume which then showed up in the kafka CRD as below:

│     Storage:                                                                                                                                                                                                    │
│       Type:  jbod                                                                                                                                                                                               │
│       Volumes:                                                                                                                                                                                                  │
│         Class:         block-storage-wait-retain                                                                                                                                                          │
│         Delete Claim:  true                                                                                                                                                                                     │
│         Id:            0                                                                                                                                                                                        │
│         Size:          10Gi                                                                                                                                                                                     │
│         Type:          persistent-claim                                                                                                                                                                         │
│         Class:         block-storage-wait-retain                                                                                                                                                          │
│         Delete Claim:  true                                                                                                                                                                                     │
│         Id:            1                                                                                                                                                                                        │
│         Size:          10Gi                                                                                                                                                                                     │
│         Type:          persistent-claim      

The kafka pods are now stuck in two different states.

One for a pod which was able to add the new jbod volume but is stuck in a terminating state:

Normal   Scheduled               35m                 default-scheduler        Successfully assigned icon-kafka/icon-kafka-main-a-kafka-0 to cc-cpu6-29f11f7b33ac                                              │
│   Normal   SuccessfulAttachVolume  35m                 attachdetach-controller  AttachVolume.Attach succeeded for volume "pvc-baa963e03b9548f5"                                                                 │
│   Warning  FailedAttachVolume      35m (x3 over 35m)   attachdetach-controller  AttachVolume.Attach failed for volume "pvc-b9a2398990d14b15" : rpc error: code = Aborted desc = cannot attach volume to node: { │
│ "error":"unable to attach: Server is currently locked","status":400}                                                                                                                                            │
│   Normal   SuccessfulAttachVolume  35m                 attachdetach-controller  AttachVolume.Attach succeeded for volume "pvc-b9a2398990d14b15"                                                                 │
│   Normal   Pulled                  33m (x5 over 35m)   kubelet                  Container image "quay.io/strimzi/kafka:0.28.0-kafka-3.1.0" already present on machine                                           │
│   Normal   Created                 33m (x5 over 35m)   kubelet                  Created container kafka                                                                                                         │
│   Normal   Started                 33m (x5 over 35m)   kubelet                  Started container kafka                                                                                                         │
│   Warning  BackOff                 30m (x24 over 35m)  kubelet                  Back-off restarting failed container

And the other pods are stuck in crash loops having mounted the new jbod volume with these logs:

2022-03-21 01:18:23,457 INFO [LogLoader partition=_schemas-0, dir=/var/lib/kafka/data-0/kafka-log1] Producer state recovery took 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.Un │
│ ifiedLog$) [log-recovery-/var/lib/kafka/data-0/kafka-log1]                                                                                                                                                      │
│ 2022-03-21 01:18:23,459 ERROR There was an error in one of the threads during logs loading: java.lang.InternalError: a fault occurred in a recent unsafe memory access operation in compiled Java code (kafka.l │
│ og.LogManager) [main]                                                                                                                                                                                           │
│ 2022-03-21 01:18:23,460 INFO [LogLoader partition=_confluent-controlcenter-6-1-0-1-MonitoringMessageAggregatorWindows-THREE_HOURS-changelog-10, dir=/var/lib/kafka/data-0/kafka-log1] Recovering unflushed segm │
│ ent 0 (kafka.log.LogLoader$) [log-recovery-/var/lib/kafka/data-0/kafka-log1]                                                                                                                                    │
│ 2022-03-21 01:18:23,460 INFO [LogLoader partition=_confluent-controlcenter-6-1-0-1-MonitoringMessageAggregatorWindows-THREE_HOURS-changelog-10, dir=/var/lib/kafka/data-0/kafka-log1] Loading producer state ti │
│ ll offset 0 with message format version 2 (kafka.log.UnifiedLog$) [log-recovery-/var/lib/kafka/data-0/kafka-log1]                                                                                               │
│ 2022-03-21 01:18:23,460 INFO [LogLoader partition=_confluent-controlcenter-6-1-0-1-MonitoringMessageAggregatorWindows-THREE_HOURS-changelog-10, dir=/var/lib/kafka/data-0/kafka-log1] Reloading from producer s │
│ napshot and rebuilding producer state from offset 0 (kafka.log.UnifiedLog$) [log-recovery-/var/lib/kafka/data-0/kafka-log1]                                                                                     │
│ 2022-03-21 01:18:23,460 INFO [LogLoader partition=_confluent-controlcenter-6-1-0-1-MonitoringMessageAggregatorWindows-THREE_HOURS-changelog-10, dir=/var/lib/kafka/data-0/kafka-log1] Producer state recovery t │
│ ook 0ms for snapshot load and 0ms for segment recovery from offset 0 (kafka.log.UnifiedLog$) [log-recovery-/var/lib/kafka/data-0/kafka-log1]                                                                    │
│ 2022-03-21 01:18:23,462 ERROR Error while writing to checkpoint file /var/lib/kafka/data-0/kafka-log1/_confluent-controlcenter-6-1-0-1-MonitoringMessageAggregatorWindows-THREE_HOURS-changelog-10/leader-epoch │
│ -checkpoint (kafka.server.LogDirFailureChannel) [log-recovery-/var/lib/kafka/data-0/kafka-log1]                                                                                                                 │
│ java.io.IOException: No space left on device                                                                                                                                                                    │
│     at java.base/java.io.FileOutputStream.writeBytes(Native Method)

Is there anything I can do to recover the cluster? Unfortunately I am not able to resize the volumes easily in my cloud provider so the options mentioned in resizing-persistent-volumes blog won't help.

[scholzj]

Adding volumes does not help you -> you have to make sure that the volumes have space. So you either need to clean some files from the full volume or you need to increase its capacity (assuming your infrastructure supports it).

[robcxyz]

@scholzj - Thank you for your help. I was able to get into the cluster by pausing reconciliation, modifiying the SS entrypoint / removing livliness/readiness, removing some topics that freed up around 300 Mb on each broker, after which I un-paused reconciliation and the cluster came back but the data is still going to the first jbod volume. Was there a step I missed for getting the data to distribute across the jbod disks?

Thanks again. Really appreciate your work.

[scholzj]

Each partition has a fixed assignment to a particular broker and particular disk. So you will need to reassign them to move them to other volume. If you are on Strimzi 0.28 you can use the intra-broker balancing with Cruise Control. You can also use the kafka-reassign-partitions.sh tool.

[robcxyz]

@scholzj - Sorry for late reply.

Thank you for the suggestion to use cruise control. I guess as one last follow up, are there any kafka metrics that would help monitoring the jbod PVs disk usage? Normally this would be done by the node exporter but I am having trouble relabeling to filter to the PV or getting the metrics out of my csi driver.

Thanks again for your time.

[scholzj]

Yeah, I think you might need to get this through Kubernetes I'm afraid. I think that Kafka gives you metrics about log size for different partition rpelicas. But I'm not sure it includes information about the volume where it is. Also, it IMHO gives another numbers than the actual disk usage (since there are some additional files on the disks as well).