Bpftrace: ubuntu snap uprobes not working

[brendangregg]

Trying on Ubuntu Bionic:

# /snap/bin/bpftrace bashreadline.bt 
Attaching 2 probes...
Tracing bash commands... Hit Ctrl-C to end.
TIME      PID    COMMAND
^C

# /usr/bin/bpftrace bashreadline.bt 
Attaching 2 probes...
Tracing bash commands... Hit Ctrl-C to end.
TIME      PID    COMMAND
20:18:22  26319  ls -lh
20:18:23  26319  date
^C

The /snap/bin version isn't picking up the events.

There are other differences with the snap version as well: I took a quick look with strace and saw that the snap version calls clone(2) six times on startup (why? not easy to answer: stacks are broken), whereas the normal build does not. I also noticed we're calling more clone(2) than necessary due to resolve_binary_path() from semantic analyzer -- for this particular tool -- but that's a bpftrace problem.

I can get more detail using bpftool(8), but that's better with a newer kernel than this 4.15.

[fbs]

iirc the BEGIN probe is a uprobe too, so maybe it's connecting to a libc in snap instead of the one bash uses (the host)?

This doesn't work with snap either, it just doesn't print:

sudo  bpftrace --unsafe -e 'BEGIN{printf("test\n"); } i:s:1 { printf("ls:\n"); system("ls /"); }'
Attaching 2 probes...
test
ls:
ls:

Stracing that shows a segv

strace: Process 2861 attached
[pid  2861] 1563369801.730908 execve("/bin/sh", ["sh", "-c", "ls /"], 0x7ffc3d36a470 /* 33 vars */) = 0
[pid  2861] 1563369801.732147 --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=NULL} ---
[pid  2861] 1563369801.823956 +++ killed by SIGSEGV (core dumped) +++
1563369801.823983 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_DUMPED, si_pid=2861, si_uid=0, si_status=SIGSEGV, si_utime=0, si_stime=0} ---

In a vagrant vm:

strace: Process 18282 attached
[pid 18282] 1563369876.485739 execve("/bin/sh", ["sh", "-c", "ls /"], 0x7fffd6438400 /* 14 vars */) = 0
strace: Process 18283 attached
[pid 18283] 1563369876.488025 execve("/bin/ls", ["ls", "/"], 0x5624dd17fb68 /* 15 vars */) = 0
[pid 18283] 1563369876.501678 +++ exited with 0 +++
[pid 18282] 1563369876.501701 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=18283, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
[pid 18282] 1563369876.501967 +++ exited with 0 +++
1563369876.501983 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=18282, si_uid=0, si_status=0, si_utime=0, si_stime=0} ---
bin
boot
dev

[mmarchini]

dmesg output when I try to run bashreadline.bt with snap installed from snap:

[ 1956.159364] kauditd_printk_skb: 6 callbacks suppressed
[ 1956.159368] audit: type=1400 audit(1563385943.615:71): apparmor="ALLOWED" operation="open" profile="snap.bpftrace.bpftrace" name="/home/mmarchini/workspace/iovisor/bpftrace/tools/bashreadline.bt" pid=12875 comm="bpftrace" requested_mask="r" denied_mask="r" fsuid=0 ouid=1000
[ 1956.159993] audit: type=1400 audit(1563385943.615:72): apparmor="ALLOWED" operation="open" profile="snap.bpftrace.bpftrace" name="/home/mmarchini/workspace/iovisor/bpftrace/tools/bashreadline.bt" pid=12875 comm="bpftrace" requested_mask="r" denied_mask="r" fsuid=0 ouid=1000
[ 1956.161622] sh[12901]: segfault at 0 ip 0000000000000000 sp 00007ffc8a91d368 error 14 in dash[564f19aaf000+24000]
[ 1956.161632] Code: Bad RIP value.
[ 1956.247025] sh[12903]: segfault at 0 ip 0000000000000000 sp 00007ffe7ff47ba8 error 14 in dash[5634e93e0000+24000]
[ 1956.247028] Code: Bad RIP value.
[ 1956.299098] sh[12905]: segfault at 0 ip 0000000000000000 sp 00007fffc42307a8 error 14 in dash[560f50f2c000+24000]
[ 1956.299100] Code: Bad RIP value.
[ 1956.357332] sh[12907]: segfault at 0 ip 0000000000000000 sp 00007ffe35040118 error 14 in dash[559685ee8000+24000]
[ 1956.357334] Code: Bad RIP value.
[ 1956.410834] sh[12909]: segfault at 0 ip 0000000000000000 sp 00007ffc1f86bc98 error 14 in dash[562c1d739000+24000]
[ 1956.410837] Code: Bad RIP value.
[ 1956.462868] sh[12911]: segfault at 0 ip 0000000000000000 sp 00007fff7e7464b8 error 14 in dash[55c1ceb36000+24000]
[ 1956.462870] Code: Bad RIP value.
[ 1956.514375] sh[12913]: segfault at 0 ip 0000000000000000 sp 00007fff68c506a8 error 14 in dash[5593a7dba000+24000]
[ 1956.514377] Code: Bad RIP value.
[ 1956.566342] sh[12915]: segfault at 0 ip 0000000000000000 sp 00007ffe9c564248 error 14 in dash[562645e3e000+24000]
[ 1956.566345] Code: Bad RIP value.

The BEGIN probe is working here though:

$ sudo /snap/bin/bpftrace --unsafe -e 'BEGIN{printf("test\n"); } i:s:1 { printf("ls:\n"); system("pwd"); }'
Attaching 2 probes...
test
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
ls:
^C

But the system("pwd") didn't work. dmesg printed this every second:

[ 2090.709249] sh[13235]: segfault at 0 ip 0000000000000000 sp 00007ffe1ea286f8 error 14 in dash[55e9128ba000+24000]
[ 2090.709259] Code: Bad RIP value.
[ 2091.709154] sh[13237]: segfault at 0 ip 0000000000000000 sp 00007ffe2d587c18 error 14 in dash[55793d1d1000+24000]
[ 2091.709162] Code: Bad RIP value.
[ 2092.708481] sh[13239]: segfault at 0 ip 0000000000000000 sp 00007ffc75122c08 error 14 in dash[56465de55000+24000]
[ 2092.708485] Code: Bad RIP value.
[ 2093.708798] sh[13241]: segfault at 0 ip 0000000000000000 sp 00007ffd6d9f6ae8 error 14 in dash[5607eba78000+24000]
[ 2093.708811] Code: Bad RIP value.
[ 2094.708373] sh[13244]: segfault at 0 ip 0000000000000000 sp 00007fffe8f0a978 error 14 in dash[55d28710e000+24000]
[ 2094.708377] Code: Bad RIP value.
[ 2095.708529] sh[13246]: segfault at 0 ip 0000000000000000 sp 00007ffdea25cd38 error 14 in dash[5628a641f000+24000]
[ 2095.708535] Code: Bad RIP value.
[ 2096.708232] sh[13248]: segfault at 0 ip 0000000000000000 sp 00007ffd0a158a28 error 14 in dash[55839c6a4000+24000]
[ 2096.708235] Code: Bad RIP value.
[ 2097.708487] sh[13250]: segfault at 0 ip 0000000000000000 sp 00007ffc3eac8b58 error 14 in dash[563d88de5000+24000]
[ 2097.708493] Code: Bad RIP value.
[ 2098.708345] sh[13252]: segfault at 0 ip 0000000000000000 sp 00007ffeaa1c4f98 error 14 in dash[55d1067d3000+24000]
[ 2098.708350] Code: Bad RIP value.
[ 2099.708441] sh[13254]: segfault at 0 ip 0000000000000000 sp 00007ffe455ccc98 error 14 in dash[55932f65d000+24000]
[ 2099.708446] Code: Bad RIP value.
[ 2100.708389] sh[13256]: segfault at 0 ip 0000000000000000 sp 00007fff1311f7a8 error 14 in dash[5643825c7000+24000]
[ 2100.708394] Code: Bad RIP value.
[ 2101.708112] sh[13258]: segfault at 0 ip 0000000000000000 sp 00007ffcb0e303f8 error 14 in dash[55d4f7a13000+24000]
[ 2101.708116] Code: Bad RIP value.
[ 2102.708964] sh[13260]: segfault at 0 ip 0000000000000000 sp 00007fff1ce02a38 error 14 in dash[561748319000+24000]
[ 2102.708973] Code: Bad RIP value.
[ 2103.708418] sh[13262]: segfault at 0 ip 0000000000000000 sp 00007ffda5cd93d8 error 14 in dash[5643528d5000+24000]
[ 2103.708424] Code: Bad RIP value.
[ 2104.708604] sh[13264]: segfault at 0 ip 0000000000000000 sp 00007ffe801a8638 error 14 in dash[562216677000+24000]
[ 2104.708620] Code: Bad RIP value.
[ 2105.708453] sh[13266]: segfault at 0 ip 0000000000000000 sp 00007ffc07302d58 error 14 in dash[55bca1577000+24000]
[ 2105.708458] Code: Bad RIP value.
[ 2106.708785] sh[13293]: segfault at 0 ip 0000000000000000 sp 00007ffc87296ba8 error 14 in dash[55a7cdd3f000+24000]
[ 2106.708793] Code: Bad RIP value.
[ 2107.708437] sh[13295]: segfault at 0 ip 0000000000000000 sp 00007ffe0ea240b8 error 14 in dash[55cdc8394000+24000]
[ 2107.708443] Code: Bad RIP value.
[ 2108.708150] sh[13297]: segfault at 0 ip 0000000000000000 sp 00007ffc675f4f28 error 14 in dash[561f46351000+24000]
[ 2108.708155] Code: Bad RIP value.

Everything works fine if I use bpftrace built from source. Nothing is reported to dmesg.

[mmarchini]

I copied bash to my home directory, and tried tracing it instead:

$ sudo /snap/bin/bpftrace -e 'uretprobe:/home/mmarchini/bash:readline { printf("test %s\n", str(retval)); }'
Attaching 1 probe...
test asd
test foo

It works. Seems like the snap doesn't have enough privilege to access /bin/bash. bcc snapcraft has two interfaces we don't have in bpftrace: mount-observe and system-observe. Not sure if adding those will fix the issue, but it's worth a shot. There's also system-files, which might make sense since we have things like cat which should be able to read any file the user running bpftrace has access to.

@ColinIanKing any suggestions? Also, do you mind adding the snapcraft files to this repository (as we have in bcc)?

[ColinIanKing]

Currently on vacation. I'll look into this and get back to you.

On Wed, 17 Jul 2019, 20:09 Matheus Marchini, [e-mail]
wrote:

I copied bash to my home directory, and tried tracing it instead:

$ sudo /snap/bin/bpftrace -e 'uretprobe:/home/mmarchini/bash:readline { printf("test %s\n", str(retval)); }'
Attaching 1 probe...
test asd
test foo

It works. Seems like the snap doesn't have enough privilege to access
/bin/bash. bcc snapcraft has two interfaces we don't have in bpftrace:
mount-observe and system-observe. Not sure if adding those will fix the
issue, but it's worth a shot. There's also system-files, which might make
sense since we have things like cat which should be able to read any file
the user running bpftrace has access to.

@ColinIanKing https://github.com/ColinIanKing any suggestions? Also, do
you mind adding the snapcraft files to this repository (as we have in bcc
https://github.com/iovisor/bcc/tree/master/snapcraft)?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/iovisor/bpftrace/issues/829?email_source=notifications&email_token=ACHCRL6U57UTE3BDZDTPXDTP75U5JA5CNFSM4IEHXOVKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD2GJDSQ#issuecomment-512528842,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACHCRL5Q7QJ6KTFD45ZEUALP75U5JANCNFSM4IEHXOVA
.

[fbs]

@ColinIanKing poke

[fbs]

@ColinIanKing do you have time to look at this? Would be good to hook this into the CI so that we can publish new releases. If you don't have time I can give it a try.

[ColinIanKing]

I'm going to try and schedule time time in this week to sort this out. If I can't I'll let you know ASAP.

[udzura]

bpftrace invoked via snap will create its own mount namespace and do pivot_root.

Host's /bin/bash will be mounted to /var/lib/snapd/hostfs/bin/bash in the new namespace.

So, this rewrote version of bashreadline.bt will work as we intended.

BEGIN
{
        printf("Tracing bash commands... Hit Ctrl-C to end.\n");
        printf("%-9s %-6s %s\n", "TIME", "PID", "COMMAND");
}

uretprobe:/var/lib/snapd/hostfs/bin/bash:readline
{
        time("%H:%M:%S  ");
        printf("%-6d %s\n", pid, str(retval));
}

root@ubuntu-bionic:~# /snap/bin/bpftrace bashreadline.bt
Attaching 2 probes...
Tracing bash commands... Hit Ctrl-C to end.
TIME      PID    COMMAND
09:28:57  5259   pwd
09:29:00  5259   ls -l
09:29:06  5259   ping 8.8.8.8

This is the restriction of snap.