Skip to content

Watchdog permanently deadlocks in check_process_name() when a mount is hung #374

Closed

Description

@gcolombeau

I'm running image processing workloads on EFS mounts and I sometimes get node hangs due to processes entering uninterruptible sleep (D). I'm trying to investigate with Claude the different causes for quite some times now and on the last node hang it appeared that it was the watchdog process that permanently deadlocked. According to Claude, it is because of the check_process_name() function that blocks on the cat /proc/<pid>/cmdline call when the mmap_lock is held by an NFS task that is blocked.

Here is a raw summary from Claude of the incident.

Environment

  • aws-efs-csi-driver image:
  • Kernel: 6.12.x (Amazon Linux 2023)
  • Platform: EKS 1.35, Karpenter-managed nodes
  • Mount options: driver defaults: nfsvers=4.1,rsize=1048576,wsize=1048576,hard,noresvport,timeo=600,retrans=2

Stacks

The watchdog is blocked in poll() waiting on 1188470 cat D __access_remote_vm:

# cat /proc/4905/wchan
do_poll.constprop.0

# cat /proc/4905/stack
[<0>] do_poll.constprop.0+0x235/0x360
[<0>] do_sys_poll+0x164/0x240
[<0>] __x64_sys_poll+0x39/0x130
[<0>] do_syscall_64+0x5b/0x170
[<0>] entry_SYSCALL_64_after_hwframe+0x76/0x7e

While the process whose cmdline is being read:

# cat /proc/1186726/stack
[<0>] folio_wait_bit_common+0x12a/0x360
[<0>] folio_wait_writeback+0x27/0x80
[<0>] __filemap_fdatawait_range+0x7d/0xd0
[<0>] filemap_write_and_wait_range+0x85/0xb0
[<0>] nfs_wb_all+0x22/0x120 [nfs]
[<0>] nfs4_file_flush+0x65/0xa0 [nfsv4]
[<0>] filp_flush+0x30/0x70
[<0>] __x64_sys_close+0x2e/0x80
[<0>] do_syscall_64+0x5b/0x170
[<0>] entry_SYSCALL_64_after_hwframe+0x76/0x7e

Logs

The watchdog logs just stopped after the hang and the process was still running:

# tail -30 /proc/4905/root/var/log/amazon/efs/mount-watchdog.log
2026-09-08 13:39:46 UTC - WARNING - TLS tunnel is not running for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.2ef8ca24-1408-4cc0-a433-a2e53cc8d58f.volumes.kubernetes.io~csi.pvc-b3151de9-cbf4-4cf0-b59a-206814a77113.mount.20648
2026-09-08 13:39:46 UTC - INFO - TLS tunnel: 33671 is no longer running, cleaning up state
2026-09-08 13:40:07 UTC - INFO - No mount found for "fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.208f0d7e-c7d6-4266-a914-38a884bad38f.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20546"
2026-09-08 13:40:37 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.208f0d7e-c7d6-4266-a914-38a884bad38f.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20546
2026-09-08 13:40:37 UTC - INFO - Sending signal SIGTERM(15) to stunnel. PID: 33872, group ID: 33872
2026-09-08 13:40:37 UTC - INFO - TLS tunnel: 33872 is still running, will retry termination
2026-09-08 13:40:38 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.208f0d7e-c7d6-4266-a914-38a884bad38f.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20546
2026-09-08 13:40:38 UTC - WARNING - TLS tunnel is not running for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.208f0d7e-c7d6-4266-a914-38a884bad38f.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20546
2026-09-08 13:40:38 UTC - INFO - TLS tunnel: 33872 is no longer running, cleaning up state
2026-09-08 13:45:47 UTC - INFO - No mount found for "fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.e920b883-c668-4b1f-adc8-782874fd716a.volumes.kubernetes.io~csi.pvc-f358f553-96d0-45f3-bc63-0ce49bb7fac0.mount.20546"
2026-09-08 13:46:17 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.e920b883-c668-4b1f-adc8-782874fd716a.volumes.kubernetes.io~csi.pvc-f358f553-96d0-45f3-bc63-0ce49bb7fac0.mount.20546
2026-09-08 13:46:17 UTC - INFO - Sending signal SIGTERM(15) to stunnel. PID: 34348, group ID: 34348
2026-09-08 13:46:17 UTC - INFO - TLS tunnel: 34348 is still running, will retry termination
2026-09-08 13:46:18 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.e920b883-c668-4b1f-adc8-782874fd716a.volumes.kubernetes.io~csi.pvc-f358f553-96d0-45f3-bc63-0ce49bb7fac0.mount.20546
2026-09-08 13:46:18 UTC - WARNING - TLS tunnel is not running for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.e920b883-c668-4b1f-adc8-782874fd716a.volumes.kubernetes.io~csi.pvc-f358f553-96d0-45f3-bc63-0ce49bb7fac0.mount.20546
2026-09-08 13:46:18 UTC - INFO - TLS tunnel: 34348 is no longer running, cleaning up state
2026-09-08 13:50:52 UTC - INFO - No mount found for "fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.1633df2b-8128-4668-93bf-909842ce9fef.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20177"
2026-09-08 13:51:23 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.1633df2b-8128-4668-93bf-909842ce9fef.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20177
2026-09-08 13:51:23 UTC - INFO - Sending signal SIGTERM(15) to stunnel. PID: 34777, group ID: 34777
2026-09-08 13:51:23 UTC - INFO - TLS tunnel: 34777 is still running, will retry termination
2026-09-08 13:51:24 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.1633df2b-8128-4668-93bf-909842ce9fef.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20177
2026-09-08 13:51:24 UTC - WARNING - TLS tunnel is not running for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.1633df2b-8128-4668-93bf-909842ce9fef.volumes.kubernetes.io~csi.pvc-4b9648e7-1c65-45cb-85a1-bad66929dc53.mount.20177
2026-09-08 13:51:24 UTC - INFO - TLS tunnel: 34777 is no longer running, cleaning up state
2026-09-08 13:52:16 UTC - INFO - No mount found for "fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.c42a7d99-28c2-45c9-8583-74f3f87d6497.volumes.kubernetes.io~csi.pvc-4826a317-423a-48bb-bc02-ffe29ddfe20a.mount.20392"
2026-09-08 13:52:46 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.c42a7d99-28c2-45c9-8583-74f3f87d6497.volumes.kubernetes.io~csi.pvc-4826a317-423a-48bb-bc02-ffe29ddfe20a.mount.20392
2026-09-08 13:52:46 UTC - INFO - Sending signal SIGTERM(15) to stunnel. PID: 35045, group ID: 35045
2026-09-08 13:52:46 UTC - INFO - TLS tunnel: 35045 is still running, will retry termination
2026-09-08 13:52:47 UTC - INFO - Unmount grace period expired for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.c42a7d99-28c2-45c9-8583-74f3f87d6497.volumes.kubernetes.io~csi.pvc-4826a317-423a-48bb-bc02-ffe29ddfe20a.mount.20392
2026-09-08 13:52:47 UTC - WARNING - TLS tunnel is not running for fs-04cad6b30d7e7e80a.var.lib.kubelet.pods.c42a7d99-28c2-45c9-8583-74f3f87d6497.volumes.kubernetes.io~csi.pvc-4826a317-423a-48bb-bc02-ffe29ddfe20a.mount.20392
2026-09-08 13:52:47 UTC - INFO - TLS tunnel: 35045 is no longer running, cleaning up state

All mounts unsupervised

State files for the three mounts still present in /proc/1/mounts, at now=1788942313 (2026-09-09 08:25:13 UTC):

port   recorded pid   last_stunnel_check_time   mount age
20949  35550 (dead)   absent                    66497s
21024  35599 (dead)   absent                    66479s
21039  24624 (dead)   66471s stale              74893s

Ports 20949 and 21024 were mounted after the watchdog froze, so they have never
had a health check and have no last_stunnel_check_time field at all. Every recorded
pid is dead.

Orphaned proxies accumulate

15 live efs-proxy processes for 3 mounts; only 2 hold a listening socket:

# ls -l /proc/[0-9]*/exe | grep -c efs-proxy
15

# for P in 20949 21024 21039; do ss -ltnp "sport = :$P"; done
(20949)  no listener
LISTEN 0 1024 127.0.0.1:21024 0.0.0.0:*  users:(("efs-proxy",pid=1186974,fd=9))
LISTEN 0 1024 127.0.0.1:21039 0.0.0.0:*  users:(("efs-proxy",pid=771625,fd=9))

Downstream symptom on the affected mount

Before intervention, port 20949 had a bound listener with a large unaccepted backlog
and all upstream connections in CLOSE-WAIT. EFS had closed them, the proxy never
noticed, and the watchdog was not running to restart it:

== 20949 srv=694 cli=1
LISTEN 713 1024 127.0.0.1:20949 0.0.0.0:*  users:(("efs-proxy",pid=1185482,fd=9))

# ss -tnp | grep :2049
CLOSE-WAIT 41 0 10.100.26.236:55050 10.100.23.199:2049 users:(("efs-proxy",pid=1185482,fd=12))
CLOSE-WAIT 41 0 10.100.26.236:55060 10.100.23.199:2049 users:(("efs-proxy",pid=1185482,fd=13))
CLOSE-WAIT 41 0 10.100.26.236:55066 10.100.23.199:2049 users:(("efs-proxy",pid=1185482,fd=14))
CLOSE-WAIT 41 0 10.100.26.236:55082 10.100.23.199:2049 users:(("efs-proxy",pid=1185482,fd=15))

The NFSv4 state manager kthread could not renew the lease:

# cat /proc/1196637/stack
[<0>] rpc_wait_bit_killable+0xd/0x70 [sunrpc]
[<0>] nfs4_proc_sequence+0x2a/0x80 [nfsv4]
[<0>] nfs4_state_manager+0x402/0x9c0 [nfsv4]
[<0>] nfs4_run_state_manager+0x5e/0x170 [nfsv4]
[<0>] kthread+0xcf/0x100

Activity

  1. DavidXU12345 commented on Oct 27, 2026

    @DavidXU12345
    Contributor

    We fixed it by reading /proc/<pid>/stat instead of cmdline

    Refer to

    def check_process_name_and_state(pid):
    """Return `(name, state)` for `pid`, or `(None, None)` if it cannot be read.
    Reads /proc/<pid>/stat, never /proc/<pid>/cmdline: a cmdline read enters the
    target's address space and can block forever on a wedged process. `state` is
    the run state, and is None on macOS, which has no procfs.
    """

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions