bpftrace

상황

k8s 이미지를 pull 하는 과정에 containerd-mount 쪽에서 umount 실패가 발생되고 있다.
실패 원인으로, mount / umount 중간에 chdir 가 들어오는걸로 추정된다.

가시성을 제공해줄수 있는 툴이 필요하다.

목적

구체적으로는
1) 커널 이벤트 mount / umount / chdir 가 어떤 순서로 들어오는 지와
2) 받는 parameter 값 확인이 필요하다.

bpftrace 를 사용한다.

예시

mount_umount_chdir.bt

#!/usr/bin/bpftrace
 
// kprobe
// https://github.com/bpftrace/bpftrace/blob/master/man/adoc/bpftrace.adoc#preprocessor-options
 
// tracepoint
// https://github.com/bpftrace/bpftrace/blob/master/man/adoc/bpftrace.adoc#bpftrace-language
 
#include <linux/path.h>
#include <linux/dcache.h>
#include <linux/mount.h>
 
// print path and timestamp
// arg0 : const char *dev_name
// arg1 : const struct path *path
kprobe:security_sb_mount {
    printf("[mount] %s %d (dev_name :%s, path:%s)\n", comm, tid, str(arg0), str(((struct path *)arg1)->dentry->d_name.name));
}
 
// arg0 : struct vfsmount *mnt
//kprobe:security_sb_umount {
 
// arg0 : char __user *name
tracepoint:syscalls:sys_enter_umount {
    printf("[umount] %s %d (%s)\n", comm, tid, str(args->name));
}

// arg0 : char __user *filename
tracepoint:syscalls:sys_enter_chdir {
    printf("[%s][chdir] %s %d (%s)\n",
                strftime("%H:%M:%S", nsecs), comm, tid, str(args->filename));
}

테스트 실행내역

// kprobe 와 tracepoint 설치
root@ubuntu22-virtual-machine bin (master) $ bpftrace mount_umount.bt
Attaching 2 probes...

// pull 실패 확인
[root@m06 v3net]# nerdctl pull FOO.com/BAR/BAZ:1.6.13.1
WARN[0000] skipping verifying HTTPS certs for "FOO.com"
FOO.com/BAR/BAZ:1.6.13.1:                                                         resolved       |++++++++++++++++++++++++++++++++++++++|
manifest-sha256:4a77cfa7392464f48e4e38d102f3dac818244fc22acb06d118b128f23270f76f: waiting        |--------------------------------------|
config-sha256:6c97ffa6d4b2535f03ac4d87bdb4d98df70d5ddc45f04ccc2062a9b388f5a5af:   done           |++++++++++++++++++++++++++++++++++++++|
layer-sha256:2d473b07cdd5f0912cd6f1a703352c82b512407db6b05b43f2553732b55df3bc:    exists         |++++++++++++++++++++++++++++++++++++++|
layer-sha256:966c76ab8189122a484c69ebaacf1eb592651a6ad2fded78da74cd581ea5656b:    done           |++++++++++++++++++++++++++++++++++++++|
layer-sha256:e56f2a3c42be4b2344c05809cf6f65165cc61dca3e6858d7370237b73be81c4c:    exists         |++++++++++++++++++++++++++++++++++++++|
layer-sha256:de6f56e3f0c51aa1958320f80435eabd40b4a731ad06dea2080e2dc2ee567470:    exists         |++++++++++++++++++++++++++++++++++++++|
layer-sha256:e9ae42ed82d1375a693288bc9cd5738946e34aeb51c511999c6359e69b92aa16:    exists         |++++++++++++++++++++++++++++++++++++++|
layer-sha256:535c2eaa069c5cdf75a9b7652bcb853196892b801b541716f889ca3644ce1d45:    exists         |++++++++++++++++++++++++++++++++++++++|
layer-sha256:e51a6d47fa459cc02774a4fb2691b2ff13bca016740124c896140815bf68a22b:    done           |++++++++++++++++++++++++++++++++++++++|
layer-sha256:0675d075a2dc8e8f2e65e2290bc5438147084b4570319a0630b388470d62a479:    done           |++++++++++++++++++++++++++++++++++++++|
elapsed: 6.3 s                                                                    total:  186.8  (29.6 MiB/s)                    
FATA[0006] failed to extract layer sha256:174f5685490326fc0a1c0f5570b8663732189b327007e47ff13d2ca59673db02: failed to unmount /var/lib/containerd/tmpmounts/containerd-mount3001516937: failed to unmount target /var/lib/containerd/tmpmounts/containerd-mount3001516937: device or resource busy: unknown

//// 아래부터는 트레이스 로그

// - containerd 의 tmpmount 생성
[18:13:41][mount] containerd 36532 (dev_name :/var/lib/containerd/io.containerd.snapshotter.v1.native/snapsho, path:containerd-mount3001516937)

// - umount 50회 시도, '중간에' chdir 로 진입한 프로세스는 확인되지 않음
[18:13:43][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:43][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:44][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 3205166 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][chdir] runc 581898 (/run/containerd/io.containerd.runtime.v2.task/k8s.io/2a1e68d56a)
[18:13:45][mount] exe 581898 (dev_name :/proc/self/exe, path:runc.3ollvz)
[18:13:45][mount] exe 581898 (dev_name :, path:runc)
[18:13:45][umount] exe 581898 (/run/containerd/runc/k8s.io/2a1e68d56a5db879ed7971f228acde7b6af)
[18:13:45][umount] containerd 1267841 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][chdir] runc:[2:INIT] 581900 (/)
[18:13:45][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][chdir] sv 581922 (/etc/service/enabled/confd)
[18:13:45][chdir] sv 581922 (log)
[18:13:45][chdir] sv 581923 (/etc/service/enabled/bird)
[18:13:45][chdir] sv 581923 (log)
[18:13:45][umount] containerd 4154896 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 1267841 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 1267841 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 1267841 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 1267841 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 39265 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:45][umount] containerd 1267841 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:46][umount] containerd 394707 (/var/lib/containerd/tmpmounts/containerd-mount3001516937)
[18:13:46][chdir] (time-dir) 581925 (/)
[18:13:46][mount] systemd-user-ru 581925 (dev_name :tmpfs, path:0)
[18:13:46][chdir] (systemd) 581927 (/)
[18:13:47][chdir] systemd 581927 ()
[18:13:47][chdir] runc 581943 (/run/containerd/io.containerd.runtime.v2.task/k8s.io/2a1e68d56a)
[18:13:47][mount] exe 581943 (dev_name :/proc/self/exe, path:runc.WKlpc1)
[18:13:47][mount] exe 581943 (dev_name :, path:runc)
[18:13:47][umount] exe 581943 (/run/containerd/runc/k8s.io/2a1e68d56a5db879ed7971f228acde7b6af)
[18:13:47][chdir] runc:[2:INIT] 581946 (/)
[18:13:47][chdir] (ystemctl) 581965 (/root)
[18:13:51][chdir] runc 581986 (/run/containerd/io.containerd.runtime.v2.task/k8s.io/796a4523b7)
[18:13:51][mount] exe 581986 (dev_name :/proc/self/exe, path:runc.DIVITg)
[18:13:51][mount] exe 581986 (dev_name :, path:runc)
[18:13:51][umount] exe 581986 (/run/containerd/runc/k8s.io/796a4523b7cd4e223e1405a65a6d6540f38)
[18:13:52][chdir] runc:[2:INIT] 581988 (/)
[18:13:52][chdir] runc 582051 (/run/containerd/io.containerd.runtime.v2.task/k8s.io/796a4523b7)
[18:13:52][mount] exe 582051 (dev_name :/proc/self/exe, path:runc.g6R4sc)
[18:13:52][mount] exe 582051 (dev_name :, path:runc)
[18:13:52][umount] exe 582051 (/run/containerd/runc/k8s.io/796a4523b7cd4e223e1405a65a6d6540f38)
[18:13:52][chdir] runc:[2:INIT] 582064 (/)