I cannot find any clue in the support bundle. Since the longhorn-csi-plugin is being repeatedly restarted, even if it fails to listen on csi.sock one time, it should succeed the next time, and the system should stabilize.

My immediate guess was SELinux. However, SELinux should have been set to permissive given the Jenkins parameters (I am not able to confirm or deny this from any of the logs we have). Additionally, it should have affected all nodes similarly.

I kicked off https://ci.longhorn.io/job/private/job/longhorn-e2e-test/129/ to try to reproduce it for live debugging. If that doesn't work, we will likely need to wait for another occurence.

I hit this one when restarting a one-node cluster. I was planning to create a ticket but looks like one already exist here.
The issue in my case is that longhorn-csi-plugin stays in crashing loop for about 4-5 mins then it recovers. Not sure if this is just slowing issue

I kicked off https://ci.longhorn.io/job/private/job/longhorn-e2e-test/129/ to try to reproduce it for live debugging. If that doesn't work, we will likely need to wait for another occurrence.

This didn't help to reproduce the issue.

I hit this one when restarting a one-node cluster. I was planning to create a ticket but looks like one already exist here.
The issue in my case is that longhorn-csi-plugin stays in crashing loop for about 4-5 mins then it recovers. Not sure if this is just slowing issue

I'll look into this a bit when I have time to see if there is an improvement we can make. It seems different from the original event, since, in that case, the CSI components never recovered.

I'm having this same issue, what kind of troubleshooting can we actually perform to identify the cause? This is on a five node cluster and it was working fine until a power issue took it out, now one node's looping on this error:

Still connecting to unix:///csi/csi.sock

Hello @yaleman. Could we have a support bundle please to confirm the identical symptoms and look for additional clues?

Please upload a it (or a paste a link) here, or send it to longhorn-support-bundle@suse.com.

Also, per the analysis below:

• What version of longhornio/livenessprobe is the longhorn-csi-plugin pod running in your cluster?
• After you have captured a support bundle, does terminating the offending longhorn-csi-plugin pod resolve the issue? This worked in my reproduce.

• A 30 second timeout was introduced to github.com/kubernetes-csi/csi-lib-utils/connection.Connect in this commit. The commit is included in github.com/kubernetes-csi/csi-lib-utils >= v1.14.0.
• The latest version (v.2.11.0) of github.com/kubernetes-csi/livenessprobe picked up that change in this commit.
• In the support bundle provided by @longhorn/qa, we were running longhornio/livenessprobe:v2.11.0. I'm not sure yet why this was the case, since we deploy longhornio/livenessprobe:v2.9.0 by default still. Maybe we were actively testing an improvement?

Here are the latest longhorn-csi-plugin logs from the support bundle:

2023-11-16T03:13:13.665926468Z time="2023-11-16T03:13:13Z" level=info msg="CSI Driver: driver.longhorn.io version: v1.6.0-dev, manager URL http://longhorn-backend:9500/v1" func="csi.(*Manager).Run" file="manager.go:23"
2023-11-16T03:13:13.687607928Z time="2023-11-16T03:13:13Z" level=info msg="Enabling node service capability: GET_VOLUME_STATS" func=csi.getNodeServiceCapabilities file="node_server.go:756"
2023-11-16T03:13:13.687626652Z time="2023-11-16T03:13:13Z" level=info msg="Enabling node service capability: STAGE_UNSTAGE_VOLUME" func=csi.getNodeServiceCapabilities file="node_server.go:756"
2023-11-16T03:13:13.687648727Z time="2023-11-16T03:13:13Z" level=info msg="Enabling node service capability: EXPAND_VOLUME" func=csi.getNodeServiceCapabilities file="node_server.go:756"
2023-11-16T03:13:13.687698615Z time="2023-11-16T03:13:13Z" level=info msg="Enabling controller service capability: CREATE_DELETE_VOLUME" func=csi.getControllerServiceCapabilities file="controller_server.go:1264"
2023-11-16T03:13:13.687704255Z time="2023-11-16T03:13:13Z" level=info msg="Enabling controller service capability: PUBLISH_UNPUBLISH_VOLUME" func=csi.getControllerServiceCapabilities file="controller_server.go:1264"
2023-11-16T03:13:13.687707962Z time="2023-11-16T03:13:13Z" level=info msg="Enabling controller service capability: EXPAND_VOLUME" func=csi.getControllerServiceCapabilities file="controller_server.go:1264"
2023-11-16T03:13:13.687711070Z time="2023-11-16T03:13:13Z" level=info msg="Enabling controller service capability: CREATE_DELETE_SNAPSHOT" func=csi.getControllerServiceCapabilities file="controller_server.go:1264"
2023-11-16T03:13:13.687713239Z time="2023-11-16T03:13:13Z" level=info msg="Enabling controller service capability: CLONE_VOLUME" func=csi.getControllerServiceCapabilities file="controller_server.go:1264"
2023-11-16T03:13:13.687792201Z time="2023-11-16T03:13:13Z" level=info msg="Enabling volume access mode: SINGLE_NODE_WRITER" func=csi.getVolumeCapabilityAccessModes file="controller_server.go:1280"
2023-11-16T03:13:13.687797371Z time="2023-11-16T03:13:13Z" level=info msg="Enabling volume access mode: MULTI_NODE_MULTI_WRITER" func=csi.getVolumeCapabilityAccessModes file="controller_server.go:1280"
2023-11-16T03:13:13.688131494Z time="2023-11-16T03:13:13Z" level=info msg="Listening for connections on address: &net.UnixAddr{Name:\"//csi/csi.sock\", Net:\"unix\"}" func="csi.(*NonBlockingGRPCServer).serve" file="server.go:100"

There is no evidence of anything wrong with longhorn-csi-plugin in this latest run.

Here are the latest livenessprobe logs from the support bundle:

2023-11-16T03:15:31.406665514Z W1116 03:15:31.406497   17969 connection.go:183] Still connecting to unix:///csi/csi.sock
2023-11-16T03:15:41.406718665Z W1116 03:15:41.406526   17969 connection.go:183] Still connecting to unix:///csi/csi.sock
2023-11-16T03:15:51.406020666Z W1116 03:15:51.405855   17969 connection.go:183] Still connecting to unix:///csi/csi.sock
2023-11-16T03:15:51.406094710Z F1116 03:15:51.405889   17969 main.go:146] failed to establish connection to CSI driver: context deadline exceeded

30 seconds after livenessprobe starts, it fails. From the code livenessprobe is expected to loop here indefinitely instead of failing. Due to the changes mentioned above, that does not happen.

The following sequence of events seems possible (though I have not managed to reproduce it):

• longhorn-csi-plugin fails early and often. This is speculation, but maybe the longhorn-backend service is not up yet, so it cannot connect as it initializes.
• Instead of waiting forever to connect to longhorn-csi-plugin via csi.sock, livenessprobe fails every 30 seconds.
• Both longhorn-csi-plugin and livenessprobe fall into exponential restart backoff. As the backoff grows, it becomes possible for livenessprobe to start, fail to connect for 30 seconds, and die while longhorn-csi-plugin is waiting to start.
• Eventually, longhorn-csi-plugin is able to consistently start successfully (as seen in the logs above). However, it always manages to do so at a time when livenessprobe is down.
• Without livenessprobe, the liveness probe configured on longhorn-csi-plugin is guaranteed to fail. Kubernetes kills it.
• Without longhorn-csi-plugin, livenessprobe cannot start. It fails (as seen in the logs above), and Kubernetes restarts it.

Additional evidence:

• From the support bundle, longhorn-csi-plugin is in 5m0s exponential backoff. It last finished at 2023-11-16T03:15:51Z after having been up for 15s. Its exit code is 143, which is associated with graceful termination at the request of Kubernetes.
• From the support bundle, livenessprobe is in 5m0s exponential backoff. It last finished at 2023-11-16T03:15:51Z.
• If we continue this pattern, longhorn-csi-plugin and livenessprobe may eventually run successfully at the same time, but clearly the next many iterations will result in failure.

• In the support bundle provided by @longhorn/qa, we were running longhornio/livenessprobe:v2.11.0. I'm not sure yet why this was the case, since we deploy longhornio/livenessprobe:v2.9.0 by default still. Maybe we were actively testing an improvement?

One mystery solved. #6920 bumped the version of livenessprobe (and other CSI components) in deployment manifests. This change hasn't made it to any released versions yet, though. It is expected to see it in v1.5.x and master test builds, but not out in the wild.

Reproduce steps:

• kubectl edit -n longhorn-system service longhorn-backend and change the port from 9500 to 9501. This effectively breaks the longhorn-backend service temporarily.
• kubectl delete -n longhorn-system pod longhorn-csi-plugin-<xxxxxx>.
• Wait some length of time. All three containers go into CrashLoopBackoff.
• kubectl edit -n longhorn-system service longhorn-backend and restore the correct port.
• Monitor longhorn-csi-plugin. It can never recover (or at least not for a long time) and exhibits the behavior described above.

In the example below, I kept the longhorn-backend service broken for 6m30s. The situation was not improved 7m30s after that.

longhorn-csi-plugin-6zxtn                           0/3     CrashLoopBackOff   16 (1s ago)     6m36s
longhorn-csi-plugin-6zxtn                           2/3     CrashLoopBackOff   18 (2m11s ago)   8m46s
longhorn-csi-plugin-6zxtn                           0/3     CrashLoopBackOff   18 (2m41s ago)   9m16s
longhorn-csi-plugin-6zxtn                           0/3     CrashLoopBackOff   18 (1s ago)      9m17s
longhorn-csi-plugin-6zxtn                           1/3     CrashLoopBackOff   19 (2m27s ago)   11m
longhorn-csi-plugin-6zxtn                           1/3     CrashLoopBackOff   20 (2s ago)      11m
longhorn-csi-plugin-6zxtn                           0/3     CrashLoopBackOff   20 (1s ago)      12m
longhorn-csi-plugin-6zxtn                           2/3     CrashLoopBackOff   22 (2m16s ago)   14m
longhorn-csi-plugin-6zxtn                           0/3     CrashLoopBackOff   22 (2m46s ago)   14m
longhorn-csi-plugin-6zxtn                           0/3     CrashLoopBackOff   22 (2s ago)      14m

Deleting longhorn-csi-plugin-6zxtn immediately resolved the issue.

I replaced livenessprobe v2.11.0 with v2.10.0. While the other two containers went into a crash loop (as expected) when the longhorn-backend service was broken, the livenessprobe container did not.

W1218 22:53:48.550210  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:53:58.549453  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:54:08.549543  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:54:18.550311  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:54:28.550369  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:54:38.550120  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:54:48.549873  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:54:58.549510  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:55:08.549488  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:55:18.550327  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:55:28.549449  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:55:38.552287  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:55:48.549367  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:55:58.549464  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:56:08.549487  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:56:18.549671  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:56:28.549355  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:56:38.549645  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:56:48.549588  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:56:58.549452  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:57:08.549906  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:57:18.549325  114434 connection.go:173] Still connecting to unix:///csi/csi.sock
W1218 22:57:28.549934  114434 connection.go:173] Still connecting to unix:///csi/csi.sock

Since the containers were deep into backoff when I restored the service, it took still took a while to recover (had to wait for the longhorn-csi-plugin container to be allowed to restart). However, full recovery eventually occured.

longhorn-csi-plugin-dgrgh                           2/3     CrashLoopBackOff   10 (92s ago)    5m36s
longhorn-csi-plugin-dgrgh                           1/3     CrashLoopBackOff   10 (2m2s ago)   6m6s
longhorn-csi-plugin-dgrgh                           1/3     CrashLoopBackOff   10 (15s ago)    6m20s
longhorn-csi-plugin-dgrgh                           2/3     CrashLoopBackOff   11 (30s ago)    6m35s
longhorn-csi-plugin-dgrgh                           3/3     Running            12 (2m53s ago)   8m58s

Ideas to fix (in order of preference?):

1. Patch upstream livenessprobe to restore previous behavior. Revert to v2.10.0 (or v2.9.0, since we already have a Longhorn version of it) in the meantime.
2. Add a startup probe to the longhorn-csi-plugin container with a 5m window or configure its livenessProbe.initialDelaySeconds to 5m. Kubernetes will not kill this container for the first five minutes it is alive. This will keep it alive long enough for livenessprobe to connect with it whenever it comes back, but maintain the existing probe behavior after startup.
3. Rework longhorn-csi-plugin startup so that it does not crash if it cannot connect to the longhorn-backend service. This may prevent the offset CrashLoopBackoffs from occurring in the first place. Kubernetes liveness probes will still fail, since the container is not ready. This only works as a potential addendum to 2.

Mine seems to have been sorted by restarting the node, it's a transient weirdness unfortunately.. will send a support bundle once I get one.

Mine seems to have been sorted by restarting the node, it's a transient weirdness unfortunately.. will send a support bundle once I get one.

Yes, I think that fits with the analysis I've done. Even without the bundle, can you confirm which version of the livenessprobe image you are running in your cluster? For example:

eweber@laptop:~> kl get pod -l app=longhorn-csi-plugin -oyaml | grep livenessprobe
      image: longhornio/livenessprobe:v2.9.0
      image: docker.io/longhornio/livenessprobe:v2.9.0
      imageID: docker.io/longhornio/livenessprobe@sha256:555e27888f3692ab4130616ce4de62f950bdac16da3af4c432e13a71604e0261
      image: longhornio/livenessprobe:v2.9.0
      image: docker.io/longhornio/livenessprobe:v2.9.0
      imageID: docker.io/longhornio/livenessprobe@sha256:555e27888f3692ab4130616ce4de62f950bdac16da3af4c432e13a71604e0261
      image: longhornio/livenessprobe:v2.9.0
      image: docker.io/longhornio/livenessprobe:v2.9.0
      imageID: docker.io/longhornio/livenessprobe@sha256:555e27888f3692ab4130616ce4de62f950bdac16da3af4c432e13a71604e0261

I reviewed #6916 and it looks like we really do need to go to livenessprobe v2.11.0 if we want to mitigate the CVEs it mentions.

The upstream bug has some traction, but it's unlikely we'll see a version we can grab and test before v1.6.0 releases. I'll move forward with my mitigation PR.

• Create an issue to revert the mitigation when we upgrade livenessprobe if the mitigation changes are approved and merged.

Pre Ready-For-Testing Checklist

• Where is the reproduce steps/test steps documented?
  The reproduce steps are at [BUG] CSI components CrashLoopBackOff, failed to connect to unix://csi/csi.sock after cluster restart #7116 (comment).
  The mitigation test steps are at: Add a startup probe to the longhorn-csi-plugin container longhorn-manager#2388 (comment).

• Is there a workaround for the issue? If so, where is it documented?
  Delete the CSI pod. Assuming the original reason for the longhorn-csi-plugin container to fail is gone, a new running pod will be created in its place.

• Does the PR include the explanation for the fix or the feature?

• Have the backend code been merged (Manager, Engine, Instance Manager, BackupStore etc) (including backport-needed/*)?
  The PR is at: Add a startup probe to the longhorn-csi-plugin container longhorn-manager#2388

• Which areas/issues this PR might have potential impacts on?
  We are only mitigating the issue for now, and the mitigation has a drawback. See: Add a startup probe to the longhorn-csi-plugin container longhorn-manager#2388 (comment).

I reviewed #6916 and it looks like we really do need to go to livenessprobe v2.11.0 if we want to mitigate the CVEs it mentions.

The upstream bug has some traction, but it's unlikely we'll see a version we can grab and test before v1.6.0 releases. I'll move forward with my mitigation PR.

* [x]  Create an issue to revert the mitigation when we upgrade livenessprobe if the mitigation changes are approved and merged.

ref: #7428

Verified passed on master-head (longhorn-manager 859d438) following test steps #7116 (comment) and longhorn/longhorn-manager#2388 (comment). longhorn-csi-plugin pods can run stable after backend service restored.

Also ran negative test case Restart Cluster While Workload Heavy Writing for 60 times, didn't observe this issue. Test results:
https://ci.longhorn.io/job/private/job/longhorn-e2e-test/133/
https://ci.longhorn.io/job/private/job/longhorn-e2e-test/134/
https://ci.longhorn.io/job/private/job/longhorn-e2e-test/135/