Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

invalid indirect read from stack off -16+4 size 16 (when tracing spinlocks) #2623

Open
pavlix opened this issue Dec 1, 2019 · 1 comment

Comments

@pavlix
Copy link

pavlix commented Dec 1, 2019

Hello! I jumped right into the hard job, tracing spinlocks. I have issues copying a pointer value from the argument of _raw_spin_lock to a BPF_PERF_OUTPUT.

#include <uapi/linux/ptrace.h>
#include <linux/irq.h>
#include <linux/spinlock.h>

struct event {
    int direction;
    u64 lock;
};

BPF_PERF_OUTPUT(events);

int kprobe___raw_spin_lock(struct pt_regs *ctx, u64 lock)
{
    struct event event = {
        .direction = 0,
        .lock = lock,
    };
    events.perf_submit(ctx, &event, sizeof event);
    bpf_trace_printk("lock %ld\n", lock);
    return 0;
}

This cannot be loaded to the kernel.

bpf: Failed to load program: Permission denied
; u64 lock = ctx->di;
0: (79) r6 = *(u64 *)(r1 +112)
; struct event event = {
1: (7b) *(u64 *)(r10 -8) = r6
2: (b7) r2 = 0
3: (63) *(u32 *)(r10 -16) = r2
last_idx 3 first_idx 0
regs=4 stack=0 before 2: (b7) r2 = 0
; bpf_perf_event_output(ctx, bpf_pseudo_fd(1, -1), CUR_CPU_IDENTIFIER, &event, sizeof event);
4: (18) r2 = 0xffff904e72e57600
6: (bf) r4 = r10
; 
7: (07) r4 += -16
; bpf_perf_event_output(ctx, bpf_pseudo_fd(1, -1), CUR_CPU_IDENTIFIER, &event, sizeof event);
8: (18) r3 = 0xffffffff
10: (b7) r5 = 16
11: (85) call bpf_perf_event_output#25
invalid indirect read from stack off -16+4 size 16
processed 10 insns (limit 1000000) max_states_per_insn 0 total_states 0 peak_states 0 mark_read 0

Surprisingly, a trivial change from static initialization from the arguments to an individual assignment worked for me. Is there a reason for that or is this a bug?

The following modification works.

int kprobe___raw_spin_lock(struct pt_regs *ctx, u64 lock)
{
    struct event event = {
        .direction = 0,
    };
    event.lock = lock,
    events.perf_submit(ctx, &event, sizeof event);
    bpf_trace_printk("lock %ld\n", lock);
    return 0;
}

P. S. I read that tracing spinlocks might be tricky and that kretprobes are rightfully forbidden for some raw spinlock functions but kprobes aren't. For _raw_spin_lock I understand it, we can trace before locked. For _raw_spin_unlock we don't seem to care but for _raw_spin_unlock_irqrestore there must be some reason. How does that cause a lockup?

@yonghong-song
Copy link
Collaborator

@pavlix this is not a bug. The difference is due to how compiler generates code for data structures with padding.

For the case

    struct event event = {
        .direction = 0,
        .lock = lock,
    };

padding is not initialized and the verifier rightfully complained.

For

    struct event event = {
        .direction = 0,
    };
    event.lock = lock,

The compiler actually generated two 64bit loads so padding are initialized so the verifier is happy.

The recommended portable way is actually like below:

   __builtin_memset(&event, 0, sizeof(event));
   event.lock = lock;

This will ensure padding is always zeroed.

jsitnicki added a commit to jsitnicki/ebpf that referenced this issue Mar 8, 2021
When starting unixdump, BPF verifier complains about invalid read from
stack:

  177: (85) call bpf_perf_event_output#25
  invalid indirect read from stack off -208+35 size 208

This is because struct notify_t object that we allocate on stack might not
be initialized. See similar issue description at:

iovisor/bcc#2623 (comment)

Zero the data allocated on stack that we pass to bpf_perf_event_output().

Observed with:
 - linux 5.10.14
 - bcc 0.18.0
Rtoax added a commit to Rtoax/bcc that referenced this issue Jun 15, 2022
ERROR:

 $ sudo ./xfsslower.py
 [...]
 80: (07) r4 += -104
 ; bpf_perf_event_output(ctx, bpf_pseudo_fd(1, -2), CUR_CPU_IDENTIFIER, &data, sizeof(data));
 81: (bf) r1 = r6
 82: (18) r3 = 0xffffffff
 84: (b7) r5 = 96
 85: (85) call bpf_perf_event_output#25
 invalid indirect read from stack R4 off -104+92 size 96
 processed 82 insns (limit 1000000) max_states_per_insn 0 total_states 4 peak_states 4 mark_read 3

 Traceback (most recent call last):
   File "/home/rongtao/Git/rtoax/bcc/tools/./xfsslower.py", line 271, in <module>
     b.attach_kretprobe(event="xfs_file_read_iter", fn_name="trace_read_return")
   File "/usr/lib/python3.9/site-packages/bcc/__init__.py", line 868, in attach_kretprobe
     fn = self.load_func(fn_name, BPF.KPROBE)
   File "/usr/lib/python3.9/site-packages/bcc/__init__.py", line 522, in load_func
     raise Exception("Failed to load BPF program %s: %s" %
 Exception: Failed to load BPF program b'trace_read_return': Permission denied

Solve according to iovisor#2623
Rtoax added a commit to Rtoax/bcc that referenced this issue Jun 16, 2022
ERROR:

 $ sudo ./xfsslower.py
 [...]
 80: (07) r4 += -104
 ; bpf_perf_event_output(ctx, bpf_pseudo_fd(1, -2), CUR_CPU_IDENTIFIER, &data, sizeof(data));
 81: (bf) r1 = r6
 82: (18) r3 = 0xffffffff
 84: (b7) r5 = 96
 85: (85) call bpf_perf_event_output#25
 invalid indirect read from stack R4 off -104+92 size 96
 processed 82 insns (limit 1000000) max_states_per_insn 0 total_states 4 peak_states 4 mark_read 3

 Traceback (most recent call last):
   File "/home/rongtao/Git/rtoax/bcc/tools/./xfsslower.py", line 271, in <module>
     b.attach_kretprobe(event="xfs_file_read_iter", fn_name="trace_read_return")
   File "/usr/lib/python3.9/site-packages/bcc/__init__.py", line 868, in attach_kretprobe
     fn = self.load_func(fn_name, BPF.KPROBE)
   File "/usr/lib/python3.9/site-packages/bcc/__init__.py", line 522, in load_func
     raise Exception("Failed to load BPF program %s: %s" %
 Exception: Failed to load BPF program b'trace_read_return': Permission denied

Solve according to iovisor#2623
yonghong-song pushed a commit that referenced this issue Jun 16, 2022
ERROR:

 $ sudo ./xfsslower.py
 [...]
 80: (07) r4 += -104
 ; bpf_perf_event_output(ctx, bpf_pseudo_fd(1, -2), CUR_CPU_IDENTIFIER, &data, sizeof(data));
 81: (bf) r1 = r6
 82: (18) r3 = 0xffffffff
 84: (b7) r5 = 96
 85: (85) call bpf_perf_event_output#25
 invalid indirect read from stack R4 off -104+92 size 96
 processed 82 insns (limit 1000000) max_states_per_insn 0 total_states 4 peak_states 4 mark_read 3

 Traceback (most recent call last):
   File "/home/rongtao/Git/rtoax/bcc/tools/./xfsslower.py", line 271, in <module>
     b.attach_kretprobe(event="xfs_file_read_iter", fn_name="trace_read_return")
   File "/usr/lib/python3.9/site-packages/bcc/__init__.py", line 868, in attach_kretprobe
     fn = self.load_func(fn_name, BPF.KPROBE)
   File "/usr/lib/python3.9/site-packages/bcc/__init__.py", line 522, in load_func
     raise Exception("Failed to load BPF program %s: %s" %
 Exception: Failed to load BPF program b'trace_read_return': Permission denied

Solve according to #2623
javierhonduco added a commit to javierhonduco/parca-agent that referenced this issue Jun 30, 2022
The BPF verifier checks that every byte in the data structures we use
are initialised, including padding [1]. In order to do this in
Rust, implementing the Default trait isn't enough, as it just
initialises the explicit fields but not the padding.

For that reason, we are using `MaybeUninit::Zeroed` that allows as to
set the entirety of the struct with zeroes.

Note that while this is always safe in C-like structs, as initialising
some Rust other data structures initialised in this way will lead to
undefined behaviour

- [1]: iovisor/bcc#2623
Rtoax added a commit to Rtoax/bcc that referenced this issue Jan 29, 2023
ENV: LLVM 13.0.1, Kernel 5.15.67, aarch64

Overview of the error:

The verifier is unhappy, if '(r10 -32)' is not initialized, see also [0].

  $ sudo ./ttysnoop.py 10
  bpf: Failed to load program: Permission denied
  3: (7b) *(u64 *)(r10 -8) = r6
  4: (7b) *(u64 *)(r10 -16) = r6
  5: (7b) *(u64 *)(r10 -24) = r6
  6: (bf) r1 = r10
  ...
  91: (67) r0 <<= 32
  92: (77) r0 >>= 32
  ; if (bpf_probe_read_user(&data->buf, BUFSIZE, (void *)buf))
  93: (55) if r0 != 0x0 goto pc+356
  R0_w=inv0 R6=invP0 R7=map_value(id=0,off=0,ks=4,vs=260,imm=0) R8=map_value(
    id=0,off=4,ks=4,vs=260,imm=0) R9=inv256 R10=fp0 fp-8=mmmmmmmm
    fp-16=mmmmmmmm fp-24=mmmmmmmm
  94: (79) r2 = *(u64 *)(r10 -32)
  invalid read from stack R10 off=-32 size=8
  processed 593 insns (limit 1000000) max_states_per_insn 1 total_states 48
    peak_states 48 mark_read 3

This issue can also be resolved by upgrading LLVM>=14  and recompile and install
bcc.

[0] iovisor#2623

Signed-off-by: Rong Tao <[email protected]>
yonghong-song pushed a commit that referenced this issue Feb 3, 2023
ENV: LLVM 13.0.1, Kernel 5.15.67, aarch64

Overview of the error:

The verifier is unhappy, if '(r10 -32)' is not initialized, see also [0].

  $ sudo ./ttysnoop.py 10
  bpf: Failed to load program: Permission denied
  3: (7b) *(u64 *)(r10 -8) = r6
  4: (7b) *(u64 *)(r10 -16) = r6
  5: (7b) *(u64 *)(r10 -24) = r6
  6: (bf) r1 = r10
  ...
  91: (67) r0 <<= 32
  92: (77) r0 >>= 32
  ; if (bpf_probe_read_user(&data->buf, BUFSIZE, (void *)buf))
  93: (55) if r0 != 0x0 goto pc+356
  R0_w=inv0 R6=invP0 R7=map_value(id=0,off=0,ks=4,vs=260,imm=0) R8=map_value(
    id=0,off=4,ks=4,vs=260,imm=0) R9=inv256 R10=fp0 fp-8=mmmmmmmm
    fp-16=mmmmmmmm fp-24=mmmmmmmm
  94: (79) r2 = *(u64 *)(r10 -32)
  invalid read from stack R10 off=-32 size=8
  processed 593 insns (limit 1000000) max_states_per_insn 1 total_states 48
    peak_states 48 mark_read 3

This issue can also be resolved by upgrading LLVM>=14  and recompile and install
bcc.

[0] #2623

Signed-off-by: Rong Tao <[email protected]>
Rtoax added a commit to Rtoax/bcc that referenced this issue Feb 10, 2023
The verifier is unhappy, if data struct _pad_ is not initialized, see [0][1].

    $ sudo ./nfsslower.py
    ...
    ; bpf_perf_event_output(ctx, (void *)bpf_pseudo_fd(1, -2), CUR_CPU_IDENTIFIER, &data, sizeof(data));
    83: (79) r1 = *(u64 *)(r10 -144)      ; R1_w=ctx(off=0,imm=0) R10=fp0
    84: (18) r3 = 0xffffffff              ; R3_w=4294967295
    86: (b7) r5 = 96                      ; R5_w=96
    87: (85) call bpf_perf_event_output#25
    invalid indirect read from stack R4 off -136+92 size 96
    processed 84 insns (limit 1000000) max_states_per_insn 0 total_states 4 peak_states 4 mark_read 4
    ...
    raise Exception("Failed to load BPF program %s: %s" %
    Exception: Failed to load BPF program b'raw_tracepoint__nfs_commit_done': Permission denied

[0] iovisor#2623
[1] iovisor#4453

Signed-off-by: Rong Tao <[email protected]>
chenhengqi pushed a commit that referenced this issue Feb 11, 2023
The verifier is unhappy, if data struct _pad_ is not initialized, see [0][1].

    $ sudo ./nfsslower.py
    ...
    ; bpf_perf_event_output(ctx, (void *)bpf_pseudo_fd(1, -2), CUR_CPU_IDENTIFIER, &data, sizeof(data));
    83: (79) r1 = *(u64 *)(r10 -144)      ; R1_w=ctx(off=0,imm=0) R10=fp0
    84: (18) r3 = 0xffffffff              ; R3_w=4294967295
    86: (b7) r5 = 96                      ; R5_w=96
    87: (85) call bpf_perf_event_output#25
    invalid indirect read from stack R4 off -136+92 size 96
    processed 84 insns (limit 1000000) max_states_per_insn 0 total_states 4 peak_states 4 mark_read 4
    ...
    raise Exception("Failed to load BPF program %s: %s" %
    Exception: Failed to load BPF program b'raw_tracepoint__nfs_commit_done': Permission denied

[0] #2623
[1] #4453

Signed-off-by: Rong Tao <[email protected]>
curu pushed a commit to curu/bcc that referenced this issue Apr 20, 2023
ENV: LLVM 13.0.1, Kernel 5.15.67, aarch64

Overview of the error:

The verifier is unhappy, if '(r10 -32)' is not initialized, see also [0].

  $ sudo ./ttysnoop.py 10
  bpf: Failed to load program: Permission denied
  3: (7b) *(u64 *)(r10 -8) = r6
  4: (7b) *(u64 *)(r10 -16) = r6
  5: (7b) *(u64 *)(r10 -24) = r6
  6: (bf) r1 = r10
  ...
  91: (67) r0 <<= 32
  92: (77) r0 >>= 32
  ; if (bpf_probe_read_user(&data->buf, BUFSIZE, (void *)buf))
  93: (55) if r0 != 0x0 goto pc+356
  R0_w=inv0 R6=invP0 R7=map_value(id=0,off=0,ks=4,vs=260,imm=0) R8=map_value(
    id=0,off=4,ks=4,vs=260,imm=0) R9=inv256 R10=fp0 fp-8=mmmmmmmm
    fp-16=mmmmmmmm fp-24=mmmmmmmm
  94: (79) r2 = *(u64 *)(r10 -32)
  invalid read from stack R10 off=-32 size=8
  processed 593 insns (limit 1000000) max_states_per_insn 1 total_states 48
    peak_states 48 mark_read 3

This issue can also be resolved by upgrading LLVM>=14  and recompile and install
bcc.

[0] iovisor#2623

Signed-off-by: Rong Tao <[email protected]>
captain5050 pushed a commit to captain5050/bcc that referenced this issue Oct 12, 2023
ENV: LLVM 13.0.1, Kernel 5.15.67, aarch64

Overview of the error:

The verifier is unhappy, if '(r10 -32)' is not initialized, see also [0].

  $ sudo ./ttysnoop.py 10
  bpf: Failed to load program: Permission denied
  3: (7b) *(u64 *)(r10 -8) = r6
  4: (7b) *(u64 *)(r10 -16) = r6
  5: (7b) *(u64 *)(r10 -24) = r6
  6: (bf) r1 = r10
  ...
  91: (67) r0 <<= 32
  92: (77) r0 >>= 32
  ; if (bpf_probe_read_user(&data->buf, BUFSIZE, (void *)buf))
  93: (55) if r0 != 0x0 goto pc+356
  R0_w=inv0 R6=invP0 R7=map_value(id=0,off=0,ks=4,vs=260,imm=0) R8=map_value(
    id=0,off=4,ks=4,vs=260,imm=0) R9=inv256 R10=fp0 fp-8=mmmmmmmm
    fp-16=mmmmmmmm fp-24=mmmmmmmm
  94: (79) r2 = *(u64 *)(r10 -32)
  invalid read from stack R10 off=-32 size=8
  processed 593 insns (limit 1000000) max_states_per_insn 1 total_states 48
    peak_states 48 mark_read 3

This issue can also be resolved by upgrading LLVM>=14  and recompile and install
bcc.

[0] iovisor#2623

Signed-off-by: Rong Tao <[email protected]>
captain5050 pushed a commit to captain5050/bcc that referenced this issue Oct 12, 2023
The verifier is unhappy, if data struct _pad_ is not initialized, see [0][1].

    $ sudo ./nfsslower.py
    ...
    ; bpf_perf_event_output(ctx, (void *)bpf_pseudo_fd(1, -2), CUR_CPU_IDENTIFIER, &data, sizeof(data));
    83: (79) r1 = *(u64 *)(r10 -144)      ; R1_w=ctx(off=0,imm=0) R10=fp0
    84: (18) r3 = 0xffffffff              ; R3_w=4294967295
    86: (b7) r5 = 96                      ; R5_w=96
    87: (85) call bpf_perf_event_output#25
    invalid indirect read from stack R4 off -136+92 size 96
    processed 84 insns (limit 1000000) max_states_per_insn 0 total_states 4 peak_states 4 mark_read 4
    ...
    raise Exception("Failed to load BPF program %s: %s" %
    Exception: Failed to load BPF program b'raw_tracepoint__nfs_commit_done': Permission denied

[0] iovisor#2623
[1] iovisor#4453

Signed-off-by: Rong Tao <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants