Re: tracing: user events UAF crash report

On 22.07.24 13:13, Ajay Kaher wrote:

On Sat, Jul 20, 2024 at 2:17 AM Mathias Krause [off-list ref] wrote:

quoted

I noticed, the user events ftrace selftest is crashing every now and
then in our automated tests. Digging into, I found that the following
is triggering the issue very reliable:

- in one shell, as root:
  # while true; do ./kselftest/user_events/ftrace_test; done

- in a second shell, again as root:
  # cd /sys/kernel/tracing
  # while true; do cat events/user_events/__test_event/format; done 2>/dev/null

Tried to reproduced on 6.10.0-rc7-100.ph5+, only getting repeated output as:

I don't know what that version refers to, but, in case the .config
matters, I'm attaching mine. It has KASAN enabled and works in a QEMU VM
(Debian bullseye amd64 userland, in case it matters).

# while true; do cat events/user_events/__test_event/format; done 2>/dev/null
print fmt: ""
name: __test_event
ID: 2390
format:
field:unsigned short common_type; offset:0; size:2; signed:0;
field:unsigned char common_flags; offset:2; size:1; signed:0;
field:unsigned char common_preempt_count; offset:3; size:1; signed:0;
field:int common_pid; offset:4; size:4; signed:1;

# while true; do ./kselftest/user_events/ftrace_test; done
TAP version 13
1..6
# Starting 6 tests from 1 test cases.
#  RUN           user.register_events ...
#            OK  user.register_events
ok 1 user.register_events
#  RUN           user.write_events ...
#            OK  user.write_events
ok 2 user.write_events
#  RUN           user.write_empty_events ...
#            OK  user.write_empty_events
ok 3 user.write_empty_events
#  RUN           user.write_fault ...
#            OK  user.write_fault
ok 4 user.write_fault
#  RUN           user.write_validator ...
#            OK  user.write_validator
ok 5 user.write_validator
#  RUN           user.print_fmt ...
#            OK  user.print_fmt
ok 6 user.print_fmt
# PASSED: 6 / 6 tests passed.
# Totals: pass:6 fail:0 xfail:0 xpass:0 skip:0 error:0

Am I missing any step?

Hmm, for me the output looks like this:

TAP version 13
1..6
# Starting 6 tests from 1 test cases.
#  RUN           user.register_events ...
#            OK  user.register_events
ok 1 user.register_events
#  RUN           user.write_events ...
# ftrace_test.c:348:write_events:Expected after (515) > before (515)
# write_events: Test terminated by assertion
#          FAIL  user.write_events
not ok 2 user.write_events
#  RUN           user.write_empty_events ...
# ftrace_test.c:386:write_empty_events:Expected after (515) > before (515)
# write_empty_events: Test terminated by assertion
#          FAIL  user.write_empty_events
not ok 3 user.write_empty_events
#  RUN           user.write_fault ...
#            OK  user.write_fault
ok 4 user.write_fault
#  RUN           user.write_validator ...
# ftrace_test.c:468:write_validator:Expected after (515) > before (515)
# write_validator: Test terminated by assertion
#          FAIL  user.write_validator
not ok 5 user.write_validator
#  RUN           user.print_fmt ...
#            OK  user.print_fmt
ok 6 user.print_fmt
# FAILED: 3 / 6 tests passed.
# Totals: pass:3 fail:3 xfail:0 xpass:0 skip:0 error:0

And that's v6.10 with only the additional patch from below applied on
top. But even without any changes, plain v6.10 with my config triggers
the bug easily.

quoted

Ignoring that the selftest fails for half of its tests -- which is a
regression and therefore yet another bug, I guess -- this triggers an
access fault (GFP/PF/NULL deref) after a few iterations, usually within
a minute, mostly mere seconds. With KASAN enabled it generates a splat
almost instantly, like following:

[   23.790955] ==================================================================
[   23.791692] BUG: KASAN: slab-use-after-free in f_show+0x43b/0x470
[...]
[   23.828018] ==================================================================

If you add "kasan_multi_shot" you should see loads of reports in the
kernel log while running both loops instead of only the first one.

Thanks,
Mathias