longhorn: [BUG] orphaned pod pod_id found, but error not a directory occurred when trying to remove the volumes dir

I ended up using this script (not I’m not a longhorn dev, I cannot guarantee this is safe)

while true ; do
for o in $(tail /var/log/syslog | grep -o  -E 'orphaned pod \\"((\w|-)+)\\' | cut -d" " -f3 | grep -oE '(\w|-)+' | uniq); do
	p="/var/lib/kubelet/pods/$o/volumes/*"
	if [ -d "$p" ] ; then
	  echo "Removing $o"
	  rm -rf "$p"
	fi
done
sleep 2
done

Two options:

“You don’t need to delete the dangling vol_data.json in the old mountpoint directory by manual. After restart of the longhorn-csi plugin automatically and waiting for several minutes, the pod with a new volume mountpoint will be at Running state again.” - in case crashed replica is rescheduled on same node.

But If replica has been rescheduled to different node and you have dangling vol_data.json you need to go to /var/lib/kubelet/pods/$pod_id/volumes/kubernetes.io~csi/pvc_$pvc_id/ and delete vol_data.json after making sure this is not “live” volume.

As Derek said, this is not longhorn bug, that’s how kubelet is handling folder cleanup (calling rmdir will always fail if this directory contains anything)

I can confirm this bug running v1.2.3. I spotted it on my environment after my k3s master was powered down by mistake, while the nodes were still were running.

k3s[797]: E0123 21:15:24.559660 797 kubelet_volumes.go:245] “There were many similar errors. Turn up verbosity to see them.” err=“orphaned pod "7316f31a-e2cb-4d92-8667-46ba6b610228" found, but error not a directory occurred when trying to remove the volumes dir” numErrs=1

After removing the vol_data.json file manually, the system recovered by itself.

k3s[797]: I0123 21:15:26.597356 797 kubelet_volumes.go:160] “Cleaned up orphaned pod volumes dir” podUID=7316f31a-e2cb-4d92-8667-46ba6b610228 path=“/var/lib/kubelet/pods/7316f31a-e2cb-4d92-8667-46ba6b610228/volumes”

Also seeing this error on microk8s 1.26.4 and Longhorn 1.4.1 it was flooding my kubelite syslogs.

No idea how it started, I believe it happened after I rebooted the nodes. Deleted one of these “orphaned pod” and another shows up instead. Ended up having to delete about 15. On all nodes.

Would be interesting to have a more robust solution than running a script that delete files manually. Why does this happen, how can we prevent it from happening?

Had to remove the /* after volumes/ in @alexnederlof script above otherwise it would not pass the “if” check.

managed to adapt the script, here’s my take, feel free to improve:

i tried to target the problematic file itself, so kubelet takes care of the rest

while true ; do
for o in $(journalctl -u k3s-agent -n 10 -o cat | grep -o  -E 'orphaned pod \\"((\w|-)+)\\' | cut -d" " -f3 | grep -oE '(\w|-)+' | uniq); do
	p="/var/lib/kubelet/pods/$o/volumes/kubernetes.io~csi/*/vol_data.json"
	if [ -f $p ] ; then
    echo "hello"
	  echo "Removing $o"
	  rm -rfi $p
	fi
  echo "goodbye"
done
sleep 2
done

@shuo-wu Yes. But the CSI plugin can restart automatically after the restart of the node and kubelet now, so we don’t need to do any change. The influence of vol_data.json in the restart node’s old volume is the repeated error log messages. It should be fixed in kubelet.

@rlex

Sorry for being late reply. I can reproduce the issue by increasing the power outage period.

I noticed the error messages in the reboot node’ kubelet log.

Nov 21 15:02:44 ku60-worker2 k3s[888]: I1121 15:02:44.682813     888 csi_mounter.go:367] kubernetes.io/csi: Unmounter.TearDown(/var/lib/kubelet/pods/7c718603-7246-49e4-86df-c77a4a8fe868/volumes/kubernetes.io~csi/pvc-67390d16-c7aa-440d-8b5e-3fbbea279dbf/mount)
Nov 21 15:02:44 ku60-worker2 k3s[888]: E1121 15:02:44.682841     888 operation_generator.go:858] UnmountVolume.MarkVolumeMountAsUncertain failed for volume "" (UniqueName: "pvc-67390d16-c7aa-440d-8b5e-3fbbea279dbf") pod "7c718603-7246-49e4-86df-c77a4a8fe868" (UID: "7c718603-7246-49e4-86df-c77a4a8fe868") : no volume with the name "pvc-67390d16-c7aa-440d-8b5e-3fbbea279dbf" exists in the list of attached volumes
Nov 21 15:02:44 ku60-worker2 k3s[888]: E1121 15:02:44.682873     888 nestedpendingoperations.go:301] Operation for "{volumeName:pvc-67390d16-c7aa-440d-8b5e-3fbbea279dbf podName:7c718603-7246-49e4-86df-c77a4a8fe868 nodeName:}" failed. No retries permitted until 2021-11-21 15:02:45.182853428 +0000 UTC m=+13.435234264 (durationBeforeRetry 500ms). Error: UnmountVolume.TearDown failed for volume "" (UniqueName: "pvc-67390d16-c7aa-440d-8b5e-3fbbea279dbf") pod "7c718603-7246-49e4-86df-c77a4a8fe868" (UID: "7c718603-7246-49e4-86df-c77a4a8fe868") : kubernetes.io/csi: mounter.SetUpAt failed to get CSI client: driver name driver.longhorn.io not found in the list of registered CSI drivers

The root cause is that the connection to CSI driver was broken, so the remove of vol_data.json in UnmountVolume.TearDown cannot be executed and lead to the Rmdir failure of the old volume mountpoint.

So, there were lots of error messages in the kubelet log.

Nov 21 15:48:02 ku60-worker2 k3s[888]: E1121 15:48:02.200715     888 kubelet_volumes.go:245] "There were many similar errors. Turn up verbosity to see them." err="orphaned pod \"7c718603-7246-49e4-86df-c77a4a8fe868\" found, but error not a directory occurred when trying to remove the volumes dir" numErrs=1
Nov 21 15:48:02 ku60-worker2 k3s[888]: I1121 15:48:02.200758     888 kubelet_volumes.go:247] "Orphan pod" err="orphaned pod \"7c718603-7246-49e4-86df-c77a4a8fe868\" found, but error not a directory occurred when trying to remove the volumes dir"

You don’t need to delete the dangling vol_data.json in the old mountpoint directory by manual. After restart of the longhorn-csi plugin automatically and waiting for several minutes, the pod with a new volume mountpoint will be at Running state again.

The issue is related to the kubelet logic and does not impact on the usage of Longhorn.

Related to https://github.com/kubernetes/kubernetes/issues/105536

I’ve been trying to get this script to work for my setup using crontab for a while now (my coding isnt the best) that wouldnt infinite loop but still loop thru to get all of the orphaned pods before exiting. I think I finally got it. Sharing for anyone that wants to schedule this rather than have it constantly running.

@migs35323 I like your “let kubelet handle itself” approach but your if statement was throwing “binary operator expected” errors for me when a pod had >1 pvc. I had to change it to look at a directory and then appended the file to delete.

while true ; do
for o in $(journalctl -n 10 -o cat | grep -o  -E 'orphaned pod \\"((\w|-)+)\\' | cut -d" " -f3 | grep -oE '(\w|-)+' | uniq); do
  p="/var/lib/kubelet/pods/$o/volumes"
  if [ -d $p ] ; then
    echo "Orphaned Pod $o Found"
    echo "Removing $p/kubernetes.io~csi/"*"/vol_data.json"
    rm -rf "$p/kubernetes.io~csi/"*"/vol_data.json"
    loop=1
    echo "$p/kubernetes.io~csi/"*"/vol_data.json Removed"
    echo "Rechecking"
  else
    echo "No Orphaned Pods Found"
    loop=2
  fi
done
if [ $loop = 1 ] ; then
  sleep 2
else
  echo "Exiting"
  break
fi
done

If anyone has suggestions to make this more efficient, Im all ears.

Two options:

“You don’t need to delete the dangling vol_data.json in the old mountpoint directory by manual. After restart of the longhorn-csi plugin automatically and waiting for several minutes, the pod with a new volume mountpoint will be at Running state again.” - in case crashed replica is rescheduled on same node.

But If replica has been rescheduled to different node and you have dangling vol_data.json you need to go to var/lib/kubelet/pods/$pod_id/volumes/kubernetes.io~csi/pvc_$pvc_id/ and delete vol_data.json after making sure this is not “live” volume.

As Derek said, this is not longhorn bug, that’s how kubelet is handling folder cleanup (calling rmdir will always fail if this directory contains anything)

@weizhe0422 could you help with this knowledge base? please check with @derekbit if having any questions.