search

iovisor / bcc

BCC - Tools for BPF-based Linux IO analysis, networking, monitoring, and more
Apache License 2.0
20.56k stars 3.88k forks source link

Get message cannot attach uprobe, Device or resource busy when using memleak #3060

Open sandeepkalekar opened 4 years ago

sandeepkalekar commented 4 years ago

I am using bcc memleak for debugging mysql OOM - I see following message when I start memleak -

nohup /usr/share/bcc/tools/memleak -p pgrep -n mysqld & cannot attach uprobe, Device or resource busy Attaching to pid 32439, Ctrl+C to quit. [12:45:24] Top 10 stacks with outstanding allocations: [12:45:29] Top 10 stacks with outstanding allocations: [12:45:34] Top 10 stacks with outstanding allocations: [12:45:39] Top 10 stacks with outstanding allocations:

yonghong-song commented 4 years ago

What is your kernel version? Could you pose a strace log to show which syscall returns -EBUSY? This will help check what is the root cause?

sandeepkalekar commented 4 years ago

uname -r 4.14.35-1902.303.5.3.el7uek.x86_64

bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=14, insns=0x7f340a7ac6b8, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="pvalloc_enter", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = -1 E2BIG (Argument list too long) bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=14, insns=0x7f340a7ac6b8, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = 33 open("/sys/bus/event_source/devices/uprobe/type", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/bus/event_source/devices/uprobe/format/retprobe", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/kernel/debug/tracing/uprobe_events", O_WRONLY|O_APPEND) = 34 open("/proc/self/ns/mnt", O_RDONLY) = 35 open("/proc/26200/ns/mnt", O_RDONLY) = 36 fstat(35, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 fstat(36, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 close(35) = 0 close(36) = 0 write(34, "p:uprobes/pusr_lib64_libc_2_17"..., 91) = 91 close(34) = 0 open("/sys/kernel/debug/tracing/events/uprobes/pusr_lib64_libc_2_17_so_0x87510_26200_bcc_22755/id", O_RDONLY) = 34 read(34, "1881\n", 4096) = 5 close(34) = 0 perf_event_open({type=PERF_TYPE_TRACEPOINT, size=0 / PERF_ATTRSIZE??? /, config=1881, ...}, 26200, -1, -1, PERF_FLAG_FD_CLOEXEC) = 34 ioctl(34, PERF_EVENT_IOC_SET_BPF, 33) = 0 ioctl(34, PERF_EVENT_IOC_ENABLE, 0) = 0 open("/proc/26200/maps", O_RDONLY) = 35 fstat(35, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f340a7aa000 read(35, "00400000-03933000 r-xp 00000000 "..., 1024) = 1024 read(35, "00024000 fc:06 3388 "..., 1024) = 1024 read(35, "0 /usr/lib"..., 1024) = 1024 read(35, " /usr/lib64/libnssmyhostna"..., 1024) = 1024 read(35, " /usr/lib64/"..., 1024) = 1024 read(35, "00:00 0 \n7efd5ecd6000-7efd5f4d60"..., 1024) = 1024 read(35, "0000 00:00 0 \n7efd5f7a6000-7efd5"..., 1024) = 1024 read(35, " 00000000 00:00 0 \n7efd5fa77000-"..., 1024) = 1024 read(35, " rw-p 00000000 00:00 0 \n7efd5fd8"..., 1024) = 1024 read(35, "5f000 ---p 00000000 00:00 0 \n7ef"..., 1024) = 1024 read(35, "fd60376000 rw-p 00000000 00:00 0"..., 1024) = 1024 read(35, "00-7efd60647000 ---p 00000000 00"..., 1024) = 1024 read(35, "000000 00:00 0 \n7efd67f8e000-7ef"..., 1024) = 1024 read(35, "-p 00000000 00:00 0 \n7efd6d79800"..., 1024) = 1024 read(35, "00 rw-p 00000000 00:00 0 \n7f0084"..., 1024) = 1024 read(35, "0086c2b000-7f0086c2c000 r--p 000"..., 1024) = 1024 read(35, "748 /usr/l"..., 1024) = 1024 read(35, " /usr/lib64/libcom"..., 1024) = 1024 read(35, " /usr/lib64/libgssapi_k"..., 1024) = 1024 read(35, " /usr/lib64/libplc4.s"..., 1024) = 1024 read(35, "66000 r-xp 00000000 fc:06 14897 "..., 1024) = 1024 read(35, "00 fc:06 14899 "..., 1024) = 1024 read(35, "225000-7f0089227000 rw-p 0000000"..., 1024) = 1024 close(35) = 0 munmap(0x7f340a7aa000, 4096) = 0 open("/proc/26200/ns/mnt", O_RDONLY) = 35 open("/proc/self/ns/mnt", O_RDONLY) = 36 fstat(36, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 fstat(35, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 close(36) = 0 close(35) = 0 open("/usr/lib64/libc-2.17.so", O_RDONLY) = 35 fcntl(35, F_GETFD) = 0 fstat(35, {st_mode=S_IFREG|0755, st_size=2156224, ...}) = 0 pread64(35, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0&\2\0\0\0\0\0"..., 64, 0) = 64 pread64(35, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4800, 2151424) = 4800 pread64(35, "\0.data\0.rodata\0.tdata\0.symtab\0.s"..., 1265, 2150156) = 1265 pread64(35, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0w\213\0\344\336B\243\7\352R\3319w\232\301"..., 36, 624) = 36 access("/usr/lib/debug/.build-id/77/8b00e460de42a307ea52d939779ac19d89535c.debug", F_OK) = -1 ENOENT (No such file or directory) pread64(35, "libc-2.17.so.debug\0\0\304y\20\323", 24, 2150132) = 24 stat("/usr/lib64/libc-2.17.so.debug", 0x7ffd2e462690) = -1 ENOENT (No such file or directory) access("/usr/lib64/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) access("/usr/lib64/.debug/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) access("/usr/lib/debug/usr/lib64/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) pread64(35, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0Q:\0\0!\0\0\0"..., 53832, 15752) = 53832 pread64(35, "\0xdr_u_long\0wctomb_chk\0getmnte"..., 23293, 69584) = 23293 close(35) = 0 open("/usr/lib64/libc-2.17.so", O_RDONLY) = 35 fcntl(35, F_GETFD) = 0 fstat(35, {st_mode=S_IFREG|0755, st_size=2156224, ...}) = 0 pread64(35, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`&\2\0\0\0\0\0"..., 64, 0) = 64 close(35) = 0 bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=72, insns=0x7f340a7ad9b0, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="pvalloc_exit", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = -1 E2BIG (Argument list too long) bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=72, insns=0x7f340a7ad9b0, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = 35 open("/sys/bus/event_source/devices/uprobe/type", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/bus/event_source/devices/uprobe/format/retprobe", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/kernel/debug/tracing/uprobe_events", O_WRONLY|O_APPEND) = 36 open("/proc/self/ns/mnt", O_RDONLY) = 37 open("/proc/26200/ns/mnt", O_RDONLY) = 38 fstat(37, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 fstat(38, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 close(37) = 0 close(38) = 0 write(36, "r:uprobes/rusr_lib64_libc_2_17"..., 91) = 91 close(36) = 0 open("/sys/kernel/debug/tracing/events/uprobes/rusr_lib64_libc_2_17_so_0x87510_26200_bcc_22755/id", O_RDONLY) = 36 read(36, "1882\n", 4096) = 5 close(36) = 0 perf_event_open({type=PERF_TYPE_TRACEPOINT, size=0 / PERF_ATTRSIZE??? /, config=1882, ...}, 26200, -1, -1, PERF_FLAG_FD_CLOEXEC) = 36 ioctl(36, PERF_EVENT_IOC_SET_BPF, 35) = 0 ioctl(36, PERF_EVENT_IOC_ENABLE, 0) = 0 open("/proc/26200/maps", O_RDONLY) = 37 fstat(37, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f340a7aa000 read(37, "00400000-03933000 r-xp 00000000 "..., 1024) = 1024 read(37, "00024000 fc:06 3388 "..., 1024) = 1024 read(37, "0 /usr/lib"..., 1024) = 1024 read(37, " /usr/lib64/libnssmyhostna"..., 1024) = 1024 read(37, " /usr/lib64/"..., 1024) = 1024 read(37, "00:00 0 \n7efd5ecd6000-7efd5f4d60"..., 1024) = 1024 read(37, "0000 00:00 0 \n7efd5f7a6000-7efd5"..., 1024) = 1024 read(37, " 00000000 00:00 0 \n7efd5fa77000-"..., 1024) = 1024 read(37, " rw-p 00000000 00:00 0 \n7efd5fd8"..., 1024) = 1024 read(37, "5f000 ---p 00000000 00:00 0 \n7ef"..., 1024) = 1024 read(37, "fd60376000 rw-p 00000000 00:00 0"..., 1024) = 1024 read(37, "00-7efd60647000 ---p 00000000 00"..., 1024) = 1024 read(37, "000000 00:00 0 \n7efd67f8e000-7ef"..., 1024) = 1024 read(37, "-p 00000000 00:00 0 \n7efd6d79800"..., 1024) = 1024 read(37, "00 rw-p 00000000 00:00 0 \n7f0084"..., 1024) = 1024 read(37, "0086c2b000-7f0086c2c000 r--p 000"..., 1024) = 1024 read(37, "748 /usr/l"..., 1024) = 1024 read(37, " /usr/lib64/libcom"..., 1024) = 1024 read(37, " /usr/lib64/libgssapi_k"..., 1024) = 1024 read(37, " /usr/lib64/libplc4.s"..., 1024) = 1024 read(37, "66000 r-xp 00000000 fc:06 14897 "..., 1024) = 1024 read(37, "00 fc:06 14899 "..., 1024) = 1024 read(37, "225000-7f0089227000 rw-p 0000000"..., 1024) = 1024 close(37) = 0 munmap(0x7f340a7aa000, 4096) = 0 open("/proc/26200/ns/mnt", O_RDONLY) = 37 open("/proc/self/ns/mnt", O_RDONLY) = 38 fstat(38, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 fstat(37, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 close(38) = 0 close(37) = 0 open("/usr/lib64/libc-2.17.so", O_RDONLY) = 37 fcntl(37, F_GETFD) = 0 fstat(37, {st_mode=S_IFREG|0755, st_size=2156224, ...}) = 0 pread64(37, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0&\2\0\0\0\0\0"..., 64, 0) = 64 pread64(37, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4800, 2151424) = 4800 pread64(37, "\0.data\0.rodata\0.tdata\0.symtab\0.s"..., 1265, 2150156) = 1265 pread64(37, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0w\213\0\344\336B\243\7\352R\3319w\232\301"..., 36, 624) = 36 access("/usr/lib/debug/.build-id/77/8b00e460de42a307ea52d939779ac19d89535c.debug", F_OK) = -1 ENOENT (No such file or directory) pread64(37, "libc-2.17.so.debug\0\0\304y\20\323", 24, 2150132) = 24 stat("/usr/lib64/libc-2.17.so.debug", 0x7ffd2e462690) = -1 ENOENT (No such file or directory) access("/usr/lib64/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) access("/usr/lib64/.debug/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) access("/usr/lib/debug/usr/lib64/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) pread64(37, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0Q:\0\0!\0\0\0"..., 53832, 15752) = 53832 pread64(37, "\0xdr_u_long\0__wctomb_chk\0getmnte"..., 23293, 69584) = 23293 close(37) = 0 open("/usr/lib64/libc-2.17.so", O_RDONLY) = 37 fcntl(37, F_GETFD) = 0 fstat(37, {st_mode=S_IFREG|0755, st_size=2156224, ...}) = 0 pread64(37, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`&\2\0\0\0\0\0"..., 64, 0) = 64 close(37) = 0 bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=14, insns=0x7f340a7ade78, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="aligned_alloc_e", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = -1 E2BIG (Argument list too long) bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=14, insns=0x7f340a7ade78, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = 37 open("/sys/bus/event_source/devices/uprobe/type", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/bus/event_source/devices/uprobe/format/retprobe", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/kernel/debug/tracing/uprobe_events", O_WRONLY|O_APPEND) = 38 open("/proc/self/ns/mnt", O_RDONLY) = 39 open("/proc/26200/ns/mnt", O_RDONLY) = 40 fstat(39, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 fstat(40, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 close(39) = 0 close(40) = 0 write(38, "p:uprobes/pusr_lib64_libc_2_17"..., 91) = -1 EBUSY (Device or resource busy) write(2, "cannot attach uprobe, Device or "..., 46cannot attach uprobe, Device or resource busy ) = 46 close(38) = 0 open("/proc/26200/maps", O_RDONLY) = 38 fstat(38, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f340a7aa000 read(38, "00400000-03933000 r-xp 00000000 "..., 1024) = 1024 read(38, "00024000 fc:06 3388 "..., 1024) = 1024 read(38, "0 /usr/lib"..., 1024) = 1024 read(38, " /usr/lib64/libnssmyhostna"..., 1024) = 1024 read(38, " /usr/lib64/"..., 1024) = 1024 read(38, "00:00 0 \n7efd5ecd6000-7efd5f4d60"..., 1024) = 1024 read(38, "0000 00:00 0 \n7efd5f7a6000-7efd5"..., 1024) = 1024 read(38, " 00000000 00:00 0 \n7efd5fa77000-"..., 1024) = 1024 read(38, " rw-p 00000000 00:00 0 \n7efd5fd8"..., 1024) = 1024 read(38, "5f000 ---p 00000000 00:00 0 \n7ef"..., 1024) = 1024 read(38, "fd60376000 rw-p 00000000 00:00 0"..., 1024) = 1024 read(38, "00-7efd60647000 ---p 00000000 00"..., 1024) = 1024 read(38, "000000 00:00 0 \n7efd67f8e000-7ef"..., 1024) = 1024 read(38, "-p 00000000 00:00 0 \n7efd6d79800"..., 1024) = 1024 read(38, "00 rw-p 00000000 00:00 0 \n7f0084"..., 1024) = 1024 read(38, "0086c2b000-7f0086c2c000 r--p 000"..., 1024) = 1024 read(38, "748 /usr/l"..., 1024) = 1024 read(38, " /usr/lib64/libcom"..., 1024) = 1024 read(38, " /usr/lib64/libgssapi_k"..., 1024) = 1024 read(38, " /usr/lib64/libplc4.s"..., 1024) = 1024 read(38, "66000 r-xp 00000000 fc:06 14897 "..., 1024) = 1024 read(38, "00 fc:06 14899 "..., 1024) = 1024 read(38, "225000-7f0089227000 rw-p 0000000"..., 1024) = 1024 close(38) = 0 munmap(0x7f340a7aa000, 4096) = 0 open("/proc/26200/ns/mnt", O_RDONLY) = 38 open("/proc/self/ns/mnt", O_RDONLY) = 39 fstat(39, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 fstat(38, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 close(39) = 0 close(38) = 0 open("/usr/lib64/libc-2.17.so", O_RDONLY) = 38 fcntl(38, F_GETFD) = 0 fstat(38, {st_mode=S_IFREG|0755, st_size=2156224, ...}) = 0 pread64(38, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0&\2\0\0\0\0\0"..., 64, 0) = 64 pread64(38, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4800, 2151424) = 4800 pread64(38, "\0.data\0.rodata\0.tdata\0.symtab\0.s"..., 1265, 2150156) = 1265 pread64(38, "\4\0\0\0\24\0\0\0\3\0\0\0GNU\0w\213\0\344\336B\243\7\352R\3319w\232\301"..., 36, 624) = 36 access("/usr/lib/debug/.build-id/77/8b00e460de42a307ea52d939779ac19d89535c.debug", F_OK) = -1 ENOENT (No such file or directory) pread64(38, "libc-2.17.so.debug\0\0\304y\20\323", 24, 2150132) = 24 stat("/usr/lib64/libc-2.17.so.debug", 0x7ffd2e4628a0) = -1 ENOENT (No such file or directory) access("/usr/lib64/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) access("/usr/lib64/.debug/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) access("/usr/lib/debug/usr/lib64/libc-2.17.so.debug", F_OK) = -1 ENOENT (No such file or directory) pread64(38, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0Q:\0\0!\0\0\0"..., 53832, 15752) = 53832 pread64(38, "\0xdr_u_long\0wctomb_chk\0getmnte"..., 23293, 69584) = 23293 close(38) = 0 open("/usr/lib64/libc-2.17.so", O_RDONLY) = 38 fcntl(38, F_GETFD) = 0 fstat(38, {st_mode=S_IFREG|0755, st_size=2156224, ...}) = 0 pread64(38, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`&\2\0\0\0\0\0"..., 64, 0) = 64 close(38) = 0 bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=51, insns=0x7f340a7aee48, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="free_enter", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = -1 E2BIG (Argument list too long) bpf(BPF_PROG_LOAD, {prog_type=BPF_PROG_TYPE_KPROBE, insn_cnt=51, insns=0x7f340a7aee48, license="GPL", log_level=0, log_size=0, log_buf=NULL, kern_version=KERNEL_VERSION(4, 14, 35), prog_flags=0, prog_name="", prog_ifindex=0, expected_attach_type=BPF_CGROUP_INET_INGRESS}, 112) = 38 open("/sys/bus/event_source/devices/uprobe/type", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/bus/event_source/devices/uprobe/format/retprobe", O_RDONLY) = -1 ENOENT (No such file or directory) open("/sys/kernel/debug/tracing/uprobe_events", O_WRONLY|O_APPEND) = 39 open("/proc/self/ns/mnt", O_RDONLY) = 40 open("/proc/26200/ns/mnt", O_RDONLY) = 41 fstat(40, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 fstat(41, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0 close(40) = 0 close(41) = 0 write(39, "p:uprobes/pusr_lib64_libc_2_17"..., 91) = 91 close(39) = 0 open("/sys/kernel/debug/tracing/events/uprobes/p__usr_lib64_libc_2_17_so_0x85ad0_26200_bcc_22755/id", O_RDONLY) = 39 read(39, "1883\n", 4096) = 5 close(39) = 0 perf_event_open({type=PERF_TYPE_TRACEPOINT, size=0 / PERF_ATTRSIZE??? /, config=1883, ...}, 26200, -1, -1, PERF_FLAG_FD_CLOEXEC) = 39 ioctl(39, PERF_EVENT_IOC_SET_BPF, 38) = 0 ioctl(39, PERF_EVENT_IOC_ENABLE, 0) = 0 select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:17] Top 10 stacks with ou"..., 55[19:21:17] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:22] Top 10 stacks with ou"..., 55[19:21:22] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:27] Top 10 stacks with ou"..., 55[19:21:27] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:32] Top 10 stacks with ou"..., 55[19:21:32] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:37] Top 10 stacks with ou"..., 55[19:21:37] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:42] Top 10 stacks with ou"..., 55[19:21:42] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:47] Top 10 stacks with ou"..., 55[19:21:47] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:52] Top 10 stacks with ou"..., 55[19:21:52] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:21:57] Top 10 stacks with ou"..., 55[19:21:57] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0 write(1, "[19:22:02] Top 10 stacks with ou"..., 55[19:22:02] Top 10 stacks with outstanding allocations: ) = 55 bpf(BPF_MAP_GET_NEXT_KEY, {map_fd=6, key=NULL, next_key=0x7f33fa0b7ac0}, 112) = -1 ENOENT (No such file or directory) select(0, NULL, NULL, NULL, {tv_sec=5, tv_usec=0}) = 0 (Timeout)

yonghong-song commented 4 years ago

From the above, perf_event attachment seems fine.

perf_event_open({type=PERF_TYPE_TRACEPOINT, size=0 / PERF_ATTR_SIZE_??? */, config=1883, ...}, 26200, -1, -1, PERF_FLAG_FD_CLOEXEC) = 39
ioctl(39, PERF_EVENT_IOC_SET_BPF, 38) = 0
ioctl(39, PERF_EVENT_IOC_ENABLE, 0) = 0

But there is no element populating into the map, so all BPF_MAP_GET_NEXT_KEY bpf syscall failed.

sandeepkalekar commented 4 years ago

Hi @yonghong-song Can you please suggest if I can use any workaround or local fix to proceed using memleak ?

yonghong-song commented 4 years ago

Okay, now I see where the uprobe attaching failure comes from

...
open("/sys/kernel/debug/tracing/uprobe_events", O_WRONLY|O_APPEND) = 38
open("/proc/self/ns/mnt", O_RDONLY) = 39
open("/proc/26200/ns/mnt", O_RDONLY) = 40
fstat(39, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
fstat(40, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
close(39) = 0
close(40) = 0
write(38, "p:uprobes/p__usr_lib64_libc_2_17"..., 91) = -1 EBUSY (Device or resource busy)
write(2, "cannot attach uprobe, Device or "..., 46cannot attach uprobe, Device or resource busy
) = 46
close(38) = 0
...

It happens when writing to file descriptor 38 (/sys/kernel/debug/tracing/uprobe_events). 

write(38, "p:uprobes/p__usr_lib64_libc_2_17"..., 91) = -1 EBUSY (Device or resource busy)
write(2, "cannot attach uprobe, Device or "..., 46cannot attach uprobe, Device or resource busy
) = 46

Not exactly sure what is the reason for the failure. Could you check whether /sys/kernel/debug/tracing/uprobe_events already has the event p__usr_lib64_..., if it is, you may want to remove it manually if not used by anybody else.

What file system you are using? For old kernels, overfs won't work.

Your kernel probably old <= 4.17? That is why you are still using debugfs. The newer kernel has better support and will not use debugfs (e.g., write to the debugfs file), etc.

etherandrius commented 3 years ago

What file system you are using? For old kernels, overfs won't work.

@yonghong-song Could you elaborate on this? I am attaching uprobes successfully to files that are backed by overlayfs. However, detaching fails with the same error device or resource busy

Kernel 4.15

Update

I have nailed down my issue.

I was not closing file descriptors returned by the SYS_PERF_EVENT_OPEN syscall

For context: I am not using bcc but raw syscalls which might be render this irrelevant for iovisor/bcc.