<p>My team is experiencing an issue with longhorn where sometimes our RWX PVCs are indefinitely terminating after running <code>kubectl delete</code>. A symptom of this is that the finalizers never get removed.</p>
<p>It was explained to me that the longhorn-csi-plugin containers should execute <code>ControllerUnpublishVolume</code> when no workload is using the volume and then execute <code>DeleteVolume</code> to remove the finalizer. Upon inspection of the logs when this issue occurs, the  <code>ControllerUnpublishVolume</code> event looks unsuccessful and <code>DeleteVolume</code> is never called. It looks like the response to <code>ControllerUnpublishVolume</code> is <code>{}</code> which does not seem right to me. The following logs are abridged and only include lines relevant to the volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1:</p>
<pre><code>2023-04-04T19:28:52.993226550Z time=&quot;2023-04-04T19:28:52Z&quot; level=info msg=&quot;CreateVolume: creating a volume by API client, name: pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1, size: 21474836480 accessMode: rwx&quot;
...
2023-04-04T19:29:01.119651932Z time=&quot;2023-04-04T19:29:01Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume created at 2023-04-04 19:29:01.119514295 +0000 UTC m=+2789775.717296902&quot;
2023-04-04T19:29:01.123721718Z time=&quot;2023-04-04T19:29:01Z&quot; level=info msg=&quot;CreateVolume: rsp: {\&quot;volume\&quot;:{\&quot;capacity_bytes\&quot;:21474836480,\&quot;volume_context\&quot;:{\&quot;fromBackup\&quot;:\&quot;\&quot;,\&quot;fsType\&quot;:\&quot;ext4\&quot;,\&quot;numberOfReplicas\&quot;:\&quot;3\&quot;,\&quot;recurringJobSelector\&quot;:\&quot;[{\\\&quot;name\\\&quot;:\\\&quot;backup-1-c9964a87-77074ba4\\\&quot;,\\\&quot;isGroup\\\&quot;:false}]\&quot;,\&quot;share\&quot;:\&quot;true\&quot;,\&quot;staleReplicaTimeout\&quot;:\&quot;30\&quot;},\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}}&quot;
...
2023-04-04T19:29:01.355417228Z time=&quot;2023-04-04T19:29:01Z&quot; level=info msg=&quot;ControllerPublishVolume: req: {\&quot;node_id\&quot;:\&quot;node1.example.com\&quot;,\&quot;volume_capability\&quot;:{\&quot;AccessType\&quot;:{\&quot;Mount\&quot;:{\&quot;fs_type\&quot;:\&quot;ext4\&quot;}},\&quot;access_mode\&quot;:{\&quot;mode\&quot;:5}},\&quot;volume_context\&quot;:{\&quot;fromBackup\&quot;:\&quot;\&quot;,\&quot;fsType\&quot;:\&quot;ext4\&quot;,\&quot;numberOfReplicas\&quot;:\&quot;3\&quot;,\&quot;recurringJobSelector\&quot;:\&quot;[{\\\&quot;name\\\&quot;:\\\&quot;backup-1-c9964a87-77074ba4\\\&quot;,\\\&quot;isGroup\\\&quot;:false}]\&quot;,\&quot;share\&quot;:\&quot;true\&quot;,\&quot;staleReplicaTimeout\&quot;:\&quot;30\&quot;,\&quot;storage.kubernetes.io/csiProvisionerIdentity\&quot;:\&quot;1677846786942-8081-driver.longhorn.io\&quot;},\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
...
2023-04-04T19:29:01.362958346Z time=&quot;2023-04-04T19:29:01Z&quot; level=debug msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 is ready to be attached, and the requested node is node1.example.com&quot;
2023-04-04T19:29:01.363013363Z time=&quot;2023-04-04T19:29:01Z&quot; level=info msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 with accessMode rwx requesting publishing to node1.example.com&quot;
...
2023-04-04T19:29:13.477036437Z time=&quot;2023-04-04T19:29:13Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume published at 2023-04-04 19:29:13.476922567 +0000 UTC m=+2789788.074705223&quot;
2023-04-04T19:29:13.479320941Z time=&quot;2023-04-04T19:29:13Z&quot; level=info msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 with accessMode rwx published to node1.example.com&quot;
...
2023-04-04T19:31:59.230234638Z time=&quot;2023-04-04T19:31:59Z&quot; level=info msg=&quot;ControllerUnpublishVolume: req: {\&quot;node_id\&quot;:\&quot;node1.example.com\&quot;,\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
2023-04-04T19:31:59.233597451Z time=&quot;2023-04-04T19:31:59Z&quot; level=debug msg=&quot;requesting Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 detachment for node1.example.com&quot;
...
2023-04-04T19:32:01.242531135Z time=&quot;2023-04-04T19:32:01Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume unpublished at 2023-04-04 19:32:01.242373423 +0000 UTC m=+2789955.840156051&quot;
2023-04-04T19:32:01.245744768Z time=&quot;2023-04-04T19:32:01Z&quot; level=debug msg=&quot;Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 unpublished from node1.example.com&quot;
...
2023-04-04T19:32:01.268399507Z time=&quot;2023-04-04T19:32:01Z&quot; level=info msg=&quot;ControllerUnpublishVolume: req: {\&quot;node_id\&quot;:\&quot;node1.example.com\&quot;,\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
2023-04-04T19:32:01.270584270Z time=&quot;2023-04-04T19:32:01Z&quot; level=debug msg=&quot;requesting Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 detachment for node1.example.com&quot;
...
2023-04-04T19:32:02.512117513Z time=&quot;2023-04-04T19:32:02Z&quot; level=info msg=&quot;ControllerPublishVolume: req: {\&quot;node_id\&quot;:\&quot;node2.example.com\&quot;,\&quot;volume_capability\&quot;:{\&quot;AccessType\&quot;:{\&quot;Mount\&quot;:{\&quot;fs_type\&quot;:\&quot;ext4\&quot;}},\&quot;access_mode\&quot;:{\&quot;mode\&quot;:5}},\&quot;volume_context\&quot;:{\&quot;fromBackup\&quot;:\&quot;\&quot;,\&quot;fsType\&quot;:\&quot;ext4\&quot;,\&quot;numberOfReplicas\&quot;:\&quot;3\&quot;,\&quot;recurringJobSelector\&quot;:\&quot;[{\\\&quot;name\\\&quot;:\\\&quot;backup-1-c9964a87-77074ba4\\\&quot;,\\\&quot;isGroup\\\&quot;:false}]\&quot;,\&quot;share\&quot;:\&quot;true\&quot;,\&quot;staleReplicaTimeout\&quot;:\&quot;30\&quot;,\&quot;storage.kubernetes.io/csiProvisionerIdentity\&quot;:\&quot;1677846786942-8081-driver.longhorn.io\&quot;},\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
...
2023-04-04T19:32:02.528810094Z time=&quot;2023-04-04T19:32:02Z&quot; level=debug msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 is ready to be attached, and the requested node is node2.example.com&quot;
2023-04-04T19:32:02.528829340Z time=&quot;2023-04-04T19:32:02Z&quot; level=info msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 with accessMode rwx requesting publishing to node2.example.com&quot;
...
2023-04-04T19:32:03.273890290Z time=&quot;2023-04-04T19:32:03Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume unpublished at 2023-04-04 19:32:03.272811565 +0000 UTC m=+2789957.870594214&quot;
2023-04-04T19:32:03.289152604Z time=&quot;2023-04-04T19:32:03Z&quot; level=debug msg=&quot;Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 unpublished from node1.example.com&quot;
...
2023-04-04T19:32:03.760644399Z time=&quot;2023-04-04T19:32:03Z&quot; level=info msg=&quot;ControllerPublishVolume: req: {\&quot;node_id\&quot;:\&quot;node1.example.com\&quot;,\&quot;volume_capability\&quot;:{\&quot;AccessType\&quot;:{\&quot;Mount\&quot;:{\&quot;fs_type\&quot;:\&quot;ext4\&quot;}},\&quot;access_mode\&quot;:{\&quot;mode\&quot;:5}},\&quot;volume_context\&quot;:{\&quot;fromBackup\&quot;:\&quot;\&quot;,\&quot;fsType\&quot;:\&quot;ext4\&quot;,\&quot;numberOfReplicas\&quot;:\&quot;3\&quot;,\&quot;recurringJobSelector\&quot;:\&quot;[{\\\&quot;name\\\&quot;:\\\&quot;backup-1-c9964a87-77074ba4\\\&quot;,\\\&quot;isGroup\\\&quot;:false}]\&quot;,\&quot;share\&quot;:\&quot;true\&quot;,\&quot;staleReplicaTimeout\&quot;:\&quot;30\&quot;,\&quot;storage.kubernetes.io/csiProvisionerIdentity\&quot;:\&quot;1677846786942-8081-driver.longhorn.io\&quot;},\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
2023-04-04T19:32:03.770050254Z time=&quot;2023-04-04T19:32:03Z&quot; level=debug msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 is ready to be attached, and the requested node is node1.example.com&quot;
2023-04-04T19:32:03.770093689Z time=&quot;2023-04-04T19:32:03Z&quot; level=info msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 with accessMode rwx requesting publishing to node1.example.com&quot;
...
2023-04-04T19:32:04.654700819Z time=&quot;2023-04-04T19:32:04Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume published at 2023-04-04 19:32:04.654500435 +0000 UTC m=+2789959.252283106&quot;
2023-04-04T19:32:04.657991819Z time=&quot;2023-04-04T19:32:04Z&quot; level=info msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 with accessMode rwx published to node2.example.com&quot;
2023-04-04T19:32:04.658583043Z time=&quot;2023-04-04T19:32:04Z&quot; level=info msg=&quot;ControllerPublishVolume: rsp: {}&quot;
...
2023-04-04T19:32:05.822264526Z time=&quot;2023-04-04T19:32:05Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume published at 2023-04-04 19:32:05.82208573 +0000 UTC m=+2789960.419868382&quot;
2023-04-04T19:32:05.826506892Z time=&quot;2023-04-04T19:32:05Z&quot; level=info msg=&quot;ControllerPublishVolume: volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 with accessMode rwx published to node1.example.com&quot;
2023-04-04T19:32:05.827051042Z time=&quot;2023-04-04T19:32:05Z&quot; level=info msg=&quot;ControllerPublishVolume: rsp: {}&quot;
...
2023-04-04T20:07:03.798730851Z time=&quot;2023-04-04T20:07:03Z&quot; level=info msg=&quot;ControllerUnpublishVolume: req: {\&quot;node_id\&quot;:\&quot;node1.example.com\&quot;,\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
2023-04-04T20:07:03.802360032Z time=&quot;2023-04-04T20:07:03Z&quot; level=debug msg=&quot;requesting Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 detachment for node1.example.com&quot;
2023-04-04T20:07:05.808796454Z time=&quot;2023-04-04T20:07:05Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume unpublished at 2023-04-04 20:07:05.808607472 +0000 UTC m=+2792060.406390073&quot;
2023-04-04T20:07:05.811653301Z time=&quot;2023-04-04T20:07:05Z&quot; level=debug msg=&quot;Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 unpublished from node1.example.com&quot;
...
2023-04-04T20:07:11.017524059Z time=&quot;2023-04-04T20:07:11Z&quot; level=info msg=&quot;ControllerUnpublishVolume: req: {\&quot;node_id\&quot;:\&quot;node2.example.com\&quot;,\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
2023-04-04T20:07:11.024127188Z time=&quot;2023-04-04T20:07:11Z&quot; level=debug msg=&quot;requesting Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 detachment for node2.example.com&quot;
...
2023-04-04T20:07:13.047834933Z time=&quot;2023-04-04T20:07:13Z&quot; level=debug msg=&quot;Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 unpublished from node2.example.com&quot;
2023-04-04T20:07:13.047839690Z time=&quot;2023-04-04T20:07:13Z&quot; level=info msg=&quot;ControllerUnpublishVolume: rsp: {}&quot;
2023-04-04T20:07:13.378731066Z time=&quot;2023-04-04T20:07:13Z&quot; level=info msg=&quot;ControllerUnpublishVolume: req: {\&quot;node_id\&quot;:\&quot;node2.example.com\&quot;,\&quot;volume_id\&quot;:\&quot;pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1\&quot;}&quot;
2023-04-04T20:07:13.384575838Z time=&quot;2023-04-04T20:07:13Z&quot; level=debug msg=&quot;requesting Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 detachment for node2.example.com&quot;
...
2023-04-04T20:07:13.385792532Z time=&quot;2023-04-04T20:07:13Z&quot; level=info msg=&quot;ControllerUnpublishVolume: rsp: {}&quot;
2023-04-04T20:07:15.386784410Z time=&quot;2023-04-04T20:07:15Z&quot; level=debug msg=&quot;Polling volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 state for volume unpublished at 2023-04-04 20:07:15.386596264 +0000 UTC m=+2792069.984378910&quot;
2023-04-04T20:07:15.391059508Z time=&quot;2023-04-04T20:07:15Z&quot; level=debug msg=&quot;Volume pvc-52d816a8-bbb2-4ac8-9e79-0b9950eafdc1 unpublished from node2.example.com&quot;
</code></pre>
<p>We are using Longhorn v1.2.2 on Rancher RKE v2.6.5.</p>
<p>We would expect that DeleteVolume would be called, the finalizers would be removed, and the PVC would be deleted, but none of those events occur.</p>
<p>As a workaround we tried forcefully removing the finalizer using the command <code>kubectl patch pvc my-pvc -p '{&quot;metadata&quot;:{&quot;finalizers&quot;:null}}' --type=merge</code>. This worked, but is not ideal to do every time.</p>
<p>Any ideas about what is wrong? If not, what should be my next steps in investigating this issue?</p>

Josh
<p>Probably some Pod mounts the volume you are trying to remove.</p>
<p>Check out this old answer of mine: <a href="https://stackoverflow.com/a/75768413/21404450">https://stackoverflow.com/a/75768413/21404450</a></p>
