pengzhan.dev/sample-content/posts/inotify-watcher-leaks-in-kubelet/index.md

title, date, author, category, tags, cover, excerpt

title	date	author	category	tags	cover	excerpt
How do we know if Kubelet leaks Inotify watchers	2024-04-18	Pengzhan Hao	Tech	Debug Inotify Kubelet Kubernetes	/posts-assets/inotify-watcher-leaks-in-kubelet/images/cover.webp	Kubelet as the node agent of Kubernetes OSS, always needs to monitor paths. Using Inotify to do so, Kubelet exposes to possibility of leaking of Inotify watchers. In recent, I obse...

Kubelet as the node agent of Kubernetes OSS, always needs to monitor paths. Using Inotify to do so, Kubelet exposes to possibility of leaking of Inotify watchers. In recent, I observed a case where the Kubelet was hung for enormous Inotify usage. This Post briefly discussed how I debug the process and locate the problem.

Symptom

Recently, I faced an issue where Kubelet on a node reported error message failed to create file descriptors.

error creating file watcher: too many open files
error creating file watcher: no space left on device

After short checking, I found the node has max_user_watches of 10000, but the TotalinotifyWatches is beyond this value. (P. S still not sure why watcher can initiate more than cap). In order to find which process occupied the most watchers. I used following command¹ to find it out.

echo -e "COUNT\tPID\tUSER\tCOMMAND"; sudo find /proc/[0-9]*/fdinfo -type f 2>/dev/null | sudo xargs grep ^inotify 2>/dev/null | cut -d/ -f 3 | uniq -c | sort -nr | { while read -rs COUNT PID; do echo -en "$COUNT\t$PID\t"; ps -p $PID -o user=,command=; done}

COUNT   PID USER    COMMAND
7491    8412    root /home/kubernetes/bin/kubelet --v=2 --cloud-provide=gce --experi
2620    1   root /sbin/init
....

Surprisingly, Kubelet initiated more than 7000 inotify watchers. I assumed there was an inotify leakage in Kubelet.

Leakage check

Clean Kubelet

To better understand the situation, I created a clean cluster with only 1 clean node on GKE. Roughly 70 inotify watchers were there. I created a single nginx pod and the number increased by 3. Theoretically, these 3 watchers are used by Kubelet to monitor any changes on rootfs, kube-api-access and PodSandbox. But to verify it, we need to check more details on which inodes are monitored by Kubelet.

Check inotify file descriptors

To do so, let's take a look how to track a single inotify file descriptor. Opened processes' fdinfo folder, we can examine each or them to find an inotify fd.

# Find kubelet pid
ps -aux | grep kubelet
KPID=2430

# File the an example fd
sudo ls /proc/2430/fdinfo

0 1 10 11 12 13 14 2 3 4 5 6 7 8 9

...

sudo cat /proc/2430/fdinfo/8

pos:    0
flags:  02004000
mnt_id: 15
ino:    1057
inotify wd:1 ino:3f327 sdev:800001 mask:fc6 ignored_mask:0 fhandle-bytes:8 fhandle-type:1 f_handle:27f30300e5059ea2

This is very confusing, so I rely on man proc^man_proc to understand every piece of them. In given fd, the needed information to continue sit in the last line. It's an inotify entry represents the 1 file or folder to be monitored. And the most useful data is ino:3f327 which represents the inode number of target file (in hexadecimal). And sdev:800001, which represents the ID of device where the inode sit on, and it's also in hex.

Using lsblk, I can see there's only 1 disk I'm using on the node, so finding the target file would be easy.

# Cast to decimal
ino=3f327
dec="$((16#${ino}))"

# Find the target file
loc="debugfs -R 'ncheck ${dec}' /dev/sda1"
sudo eval $loc 2>/dev/null

debugfd 1.46.5 (30-Dec-2021)
Inode   Pathname
258855  /etc/srv/kubernetes/pki/ca-certificates.crt

Put all processes above into one single script(please see the updated version in the appendix), I can retrieve all target files, that would help to understand if there's a real leakage. Also, I count the unique inode amount, this could also help to know which inode are monitored multiple times.

cat /dev/null | xargs grep ^inotify | cut -d " " -f 3 | cut -d ":" -f 2)
echo ${in_fds}
echo "Count: $(find /proc/${PID}/fdinfo -type f 2>/dev/null | xargs grep ^inotify | wc -l)"

uniq_fds=$(echo "${in_fds[@]}" | sort | uniq)
echo ${uniq_fds}

while read -r element;
do
  count=$(echo "${in_fds[@]}" | grep -o "${element}" | wc -l)
  dec="$((16#${element}))"
  loc="debugfs -R 'ncheck ${dec}' /dev/sda1"
  loc=$(eval $loc 2>/dev/null | tail -1 | cut -d " " -f 4)
  printf "%-6s %-10s %-6s %s\n" "${element}" "${dec}" "${count}" "${loc}"
done /dev/null | xargs grep ^inotify)
# echo ${inums_raw}
echo "Count: $(find /proc/${PID}/fdinfo -type f 2>/dev/null | xargs grep ^inotify | wc -l)"

while read -r line;
do
        reg="ino:([0-9a-f]*) sdev:([0-9a-f]*)"
        if [[ ${line} =~ $reg ]]; then
                ino="${BASH_REMATCH[1]}"
                sdev="${BASH_REMATCH[2]}"
                # echo $ino $sdev
        else
                echo "wrong line"
        fi

        sdev_in_dec=$((16#$sdev))
        minor=$((sdev_in_dec % 256))
        major=$((sdev_in_dec / 256))
        # echo "${major}:${minor}"

        in_fds_sdev+=("${ino}-${major}:${minor}")
done <<< "${inums_raw}"

uniq_pairs=($(echo "${in_fds_sdev[@]}" | sort | uniq))
echo "Unique target" ${#uniq_pairs[@]}

printf "%-10s %-10s %-6s %s\n" "INUM" "DEV" "COUNT" "TARGET"
for pair in "${uniq_pairs[@]}"
do
        count=$(echo "${in_fds_sdev[@]}" | grep -o "${pair}" | wc -l)
        fd_hex=$(echo ${pair} | cut -d "-" -f 1)
        dev=$(echo ${pair} | cut -d "-" -f 2)
        fd_dec="$((16#${fd_hex}))"

        mount_info=$(grep ${dev} /proc/$PID/mountinfo)
        if [[ -z $mount_info ]]; then
                echo "Can't find mount info for" $dev
        else
                tmpfs_path=$(echo $mount_info | cut -d " " -f 5)
                # echo $tmpfs_path
                loc=$(find ${tmpfs_path} -inum ${fd_dec})
                printf "%-10s %-10s %-6s %s\n" "${fd_dec}" "${dev}" "${count}" "${loc}"
        fi
done

References

---

1. Fluentbit error "cannot adjust chunk size" on GKE ↩︎