1. Messages
  2. Invalid filename/mode in openat tracepoint data

Re: Invalid filename/mode in openat tracepoint data

Tristan Mayfield
 

I don't have an answer, but I verified this with the following
bpftrace script and using the action of switching to zsh/oh-my-zsh
from bash.

---
tracepoint:syscalls:sys_enter_open,
tracepoint:syscalls:sys_enter_openat
{
printf("sys_enter_openat mode:%ld filename:%s (%ld)\n",
args->mode, str(args->filename), args->filename);
}
---

Here's some example data (not all the generated output) with spaces
around some of the issue lines:

sys_enter_openat mode:0 filename: (94797689127022)

sys_enter_openat mode:0 filename:/usr/lib/locale/locale-archive
(139635662831568)
sys_enter_openat mode:0 filename:/usr/share/locale/locale.alias
(140728940893664)
sys_enter_openat mode:0
filename:/usr/share/locale/en_US/LC_MESSAGES/git.mo (94797710736928)
sys_enter_openat mode:0
filename:/usr/share/locale/en/LC_MESSAGES/git.mo (94797710737472)
sys_enter_openat mode:0
filename:/usr/share/locale-langpack/en_US/LC_MESSAGES/git.mo
(94797710737712)
sys_enter_openat mode:0
filename:/usr/share/locale-langpack/en/LC_MESSAGES/git.mo
(94797710737584)
sys_enter_openat mode:438 filename:/dev/null (139809161489144)
sys_enter_openat mode:0 filename:/etc/ld.so.cache (140236659837824)
sys_enter_openat mode:0 filename:/lib/x86_64-linux-gnu/libpcre2-8.so.0
(140236659879440)
sys_enter_openat mode:0 filename:/lib/x86_64-linux-gnu/libz.so.1
(140236659639520)
sys_enter_openat mode:0 filename:/lib/x86_64-linux-gnu/libpthread.so.0
(140236659640784)
sys_enter_openat mode:0 filename:/lib/x86_64-linux-gnu/libc.so.6
(140236659642080)

sys_enter_openat mode:0 filename: (94426721874030)

sys_enter_openat mode:0 filename:/usr/lib/locale/locale-archive
(140236658581456)
sys_enter_openat mode:0 filename:/usr/share/locale/locale.alias
(140728357496384)

I'm tempted to think that this is some behavior of the system I don't
understand yet, rather than being a bug. But I can't say for sure.

Tristan

On 7/24/20, alessandro.gario@... <alessandro.gario@...> wrote:
Hello everyone,

I'll start with some backstory first: I wrote my own BPF library to
trace functions/syscalls and yesterday I noticed that I am sometimes
receiving broken openat() tracepoint data. This happens randomly, often
when processes are created in a short burst (like opening a new
terminal instance with zsh + oh-my-zsh installed).

I initially thought it was my fault, and proceeded to debug the
generated IR code and double check my tracepoint data definition
(which, for reference, can be found here:
https://github.com/trailofbits/ebpfpub/blob/master/ebpfpub/src/tracepointserializers.cpp#L425).

I ended up giving up, not finding the reason this was failing.

Today, I have tried to replicate the same functionality using BCC so I
could compare the output with my library and I ended up inside the same
weird behavior:

Full script here:
https://gist.github.com/alessandrogario/968b9c3ea78559f470bc650c8496449e#file-bcc_openat_tracepoint-py

--
bpf_trace_printk("sys_enter_openat mode:%ld "
"filename:%s (%ld)\\n",
args->mode,
args->filename,
args->filename);

2608.223222000 b'git' 8998 b'sys_enter_openat mode:0 filename:
(93849603522670)
--

I was able to replicate this problem on Ubuntu 20.20 (5.4.0), Arch
Linux (5.7.9) and Ubuntu 19.10 (5.3.0).

Has anyone ever encountered this problem, or has a few pointers as to
why it happening?

Thanks!

Alessandro
Join iovisor-dev@lists.iovisor.org to automatically receive all group messages.