Bpftrace: `pid` differs from PID of the traced process?

[avdi]

This is probably my own misunderstanding. Please enlighten me!

bpftrace --info

System
  OS: Linux 4.19.121-microsoft-standard #1 SMP Fri Jun 19 21:06:10 UTC 2020
  Arch: x86_64

Build
  version: v0.11.0
  LLVM: 7
  foreach_sym: yes
  unsafe uprobe: no
  bfd: yes
  bpf_attach_kfunc: yes
  bcc_usdt_addsem: yes
  libbpf: yes
  libbpf btf dump: no
  libbpf btf dump type decl: no

Kernel helpers
  probe_read: yes
  probe_read_str: yes
  probe_read_user: yes
  probe_read_user_str: yes
  probe_read_kernel: yes
  probe_read_kernel_str: yes
  get_current_cgroup_id: yes
  send_signal: yes
  override_return: yes

Kernel features
  Instruction limit: -1
  Loop support: no
  btf: no

Map types
  hash: yes
  percpu hash: yes
  array: yes
  percpu array: yes
  stack_trace: yes
  perf_event_array: yes

Probe types
  kprobe: no
  tracepoint: yes
  perf_event: yes
  kfunc: no

What reproduces the bug?

In terminal A:

$ bpftrace --include fcntl.h -e 'tracepoint:syscalls:sys_enter_openat,tracepoint:syscalls:sys_enter_open /(args->flags & (O_APPEND | O_CREAT)) && (strncmp("/tmp", str(args->filename), 4) == 0)/ { printf("%s: opened by %s (%d)\n", str(args->filename), comm, pid) }' 
Attaching 2 probes...

In terminal B:

$ cat blurp.sh
#!/bin/sh
echo "I am blurp ($$)"
echo "blurp" > /tmp/blurp$$.tmp

$ ./blurp.sh
I am blurp (6708)
$ ./blurp.sh 
I am blurp (6856)

Back in terminal A:

/tmp/blurp6708.tmp: opened by blurp.sh (17675)
/tmp/blurp6856.tmp: opened by blurp.sh (17829)

What I expected:

For the value of pid to reflect the PID of the triggering process.

What I got:

Value of pid changes with each hit, but it doesn't seem related to the PID of the process that triggered the probe. Nor does it seem to be in the numeric vicinity of recent PIDs.

[danobi]

Can you try writing a C/C++ program that makes the appropriate syscalls? sh could be doing all sorts of funny things under the hood, especially for output redirection.

[avdi]

Regardless of commands and subshells, the shell process writes its own PID (via $$) into the filename:

echo "blurp" > /tmp/blurp$$.tmp

/tmp/blurp6708.tmp: opened by blurp.sh (17675)

Here, $$ evaluated to 6708 but bpftrace's pid evaluated to 17675.

[avdi]

@jessitron has a theory: Bash sees its Docker container-internal PID, whereas bpftrace reports the global PID.

[avdi]

@danobi I should note that the PID that Bash sees (via $$) is the same as the PID that ps reports for it.

[fbs]

In a vagrant box it seems to work fine:

vagrant@ubuntu-eoan:~/bpftrace$ echo $$; echo $$ > /tmp/blurp
32514

$ sudo  bpftrace  -e 'tracepoint:syscalls:sys_enter_openat,tracepoint:syscalls:sys_enter_open /args->flags & (0|1|2) &&  (strncmp("/tmp", str(args->filename), 4) == 0)/ { printf("%s: opened by %s (%d)\n", str(args->filename), comm, pid) }'
/tmp/blurp: opened by bash (32514)
^C

What os is this?

OS: Linux 4.19.121-microsoft-standard #1 SMP Fri Jun 19 21:06:10 UTC 2020

@jessitron has a theory: Bash sees its Docker container-internal PID, whereas bpftrace reports the global PID.

bpf_get_current_pid_tgid return the root namespace pid:

vagrant@ubuntu-eoan:~/bpftrace$ sudo unshare --pid -f
root@ubuntu-eoan:/home/vagrant/bpftrace# echo $$; echo $$ > /tmp/xxx
1

/tmp/xxx: opened by bash (31926)

@danobi I should note that the PID that Bash sees (via $$) is the same as the PID that ps reports for it.

Are you running ps inside or outside the container?

[avdi]

What os is this?

Docker with WSL2 as a backend. Debian Buster inside the container.

Are you running ps inside or outside the container?

Inside.

[avdi]

I've tried switching Docker Desktop back to the legacy backend and I'm seeing the same behavior.

[fbs]

I've tried switching Docker Desktop back to the legacy backend and I'm seeing the same behavior.

Legacy?

Are you running ps inside or outside the container?

Inside.

What is the pid outside of the container?

[avdi]

I've tried switching Docker Desktop back to the legacy backend and I'm seeing the same behavior.

Legacy?

Docker Desktop is migrating to WSL2 as its backend, but it can still be run with the previous Docker-provided kernel.

What is the pid outside of the container?

TBH I'm not entirely sure how to find that out with docker desktop.

[fbs]

Not sure if you can access the vm, but if you have full docker access you can probably escape the container :)

I think this is not a bug but just the pid in the root namespace as it doesn't reproduce in a vagrant vm but we need the pid to verify.

[javierhonduco]

@jessitron has a theory: Bash sees its Docker container-internal PID, whereas bpftrace reports the global PID.

@jessitron and @fbs are right! This is the expected behaviour, but let's double check in case there's a bug!

I don't have docker installed, but this can be checked with something like:

[javierhonduco@taco ~] sudo unshare -pf
[root@taco ~] echo $$
1

and in some namespace above the one we just created:

[javierhonduco@taco ~] ps aux | grep '[u]nshare'
root      226558  0.0  0.0 241152  8048 pts/82   S    07:45   0:00 sudo unshare -pf
[javierhonduco@taco ~] pstree -p 226558
sudo(226558)───unshare(226559)───bash(226560)
[javierhonduco@taco ~] sudo cat /proc/226560/status | grep NSpid
NSpid:  226560  1

As we can see from its parent namespace, that in this case happens to be the initial pid namespace, it has PID 226560 from the root namespace and 1 from inside the PID namespace we just created.

Hope this helps!

[javierhonduco]

Oh, and @cneira's kernel patch to add a namespace aware pid helper will address this issue

[cneira]

Hi @javierhonduco,
That's right!, you could start using bpf_get_ns_current_pid_tgid() instead of bpf_get_current_pid_tgid(), if your kernel is >= 5.6.
Here is an example, on how this ebpf helper is used:
https://github.com/iovisor/bcc/blob/master/examples/tracing/hello_perf_output_using_ns.py

Bests!

[fbs]

I have some spare time this weekend, ill try and get a PR using that helper out :). Something like nspid and nstid should work I think

[fbs]

Closing this as it's not a bug and we got a feature request open for namespace tracing.