Re: use-after-free in __perf_install_in_context

[Dmitry Vyukov <dvyukov@google.com>]

On Mon, Dec 7, 2015 at 12:06 PM, Dmitry Vyukov <dvyukov@google.com> wrote:
> On Mon, Dec 7, 2015 at 12:04 PM, Dmitry Vyukov <dvyukov@google.com> wrote:
>> On Fri, Dec 4, 2015 at 10:00 PM, Dmitry Vyukov <dvyukov@google.com> wrote:
>>> On Fri, Dec 4, 2015 at 9:32 PM, Alexei Starovoitov
>>> <alexei.starovoitov@gmail.com> wrote:
>>>> On Fri, Dec 04, 2015 at 09:04:35PM +0100, Dmitry Vyukov wrote:
>>>>> Hello,
>>>>>
>>>>> While running syzkaller fuzzer I am seeing lots of the following
>>>>> use-after-free reports. Unfortunately all my numerous attempts to
>>>>> reproduce them in a controlled environment failed. They pop up during
>>>>> fuzzing periodically (once in several hours in a single VM), but
>>>>> whenever I try to stress-replay what happened in the VM before the
>>>>> report, the use-after-free does not reproduce. Can somebody
>>>>> knowledgeable in perf subsystem look at the report? Maybe it is
>>>>> possible to figure out what happened based purely on the report. I can
>>>>> pretty reliably test any proposed fixes.
>>>>> All reports look like this one. Then it is usually followed by other
>>>>> reports and eventually kernel hangs or dies. What happens in the
>>>>> fuzzer is essentially random syscalls with random arguments, tasks
>>>>> born and die concurrently and so on. I was able to reproduce it by
>>>>> restricting syscalls only to perf_event_open, perf ioctls and bpf
>>>>> syscall.
>>>>
>>>> For the sake of trying to narrow it down:
>>>> does the error disappear when you stop using bpf syscall in your fuzzing?
>>>> If yes, then I could have missed some interaction between perf_event_free,
>>>> kprobe free and bpf_prog_free.
>>>> There was a race there before.
>>>> May be there is still something else.
>>>
>>>
>>> It is a good question. I will test it.
>>
>>
>> Testing without bpf, so far hit the following warning on a non-tainted kernel:
>>
>>
>> ------------[ cut here ]------------
>> WARNING: CPU: 0 PID: 26259 at kernel/events/core.c:2696
>> task_ctx_sched_out+0x12c/0x1c0()
>> Modules linked in:
>> CPU: 0 PID: 26259 Comm: syzkaller_execu Not tainted 4.4.0-rc3+ #150
>> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
>>  0000000000000000 ffff88006579f9a8 ffffffff82c6f2a8 0000000041b58ab3
>>  ffffffff8788bf8d ffffffff82c6f1f6 ffff88003dd32d00 ffff88003469b9c0
>>  ffffffff81626130 ffff88006579fa10 0000000000000000 0000000000006693
>> Call Trace:
>>  [<     inline     >] __dump_stack lib/dump_stack.c:15
>>  [<ffffffff82c6f2a8>] dump_stack+0xb2/0xfa lib/dump_stack.c:50
>>  [<ffffffff812ca446>] warn_slowpath_common+0xe6/0x170 kernel/panic.c:460
>>  [<ffffffff812ca699>] warn_slowpath_null+0x29/0x30 kernel/panic.c:493
>>  [<ffffffff8163302c>] task_ctx_sched_out+0x12c/0x1c0 kernel/events/core.c:2696
>>  [<     inline     >] perf_event_exit_task_context kernel/events/core.c:8815
>>  [<ffffffff8165669a>] perf_event_exit_task+0x27a/0xae0 kernel/events/core.c:8881
>>  [<ffffffff812d4a12>] do_exit+0x892/0x3050 kernel/exit.c:759
>>  [<ffffffff812d732c>] do_group_exit+0xec/0x390 kernel/exit.c:880
>>  [<ffffffff81302177>] get_signal+0x677/0x1bf0 kernel/signal.c:2307
>>  [<ffffffff8118645e>] do_signal+0x7e/0x2170 arch/x86/kernel/signal.c:709
>>  [<ffffffff81003a1e>] exit_to_usermode_loop+0xfe/0x1e0
>> arch/x86/entry/common.c:247
>>  [<     inline     >] prepare_exit_to_usermode arch/x86/entry/common.c:282
>>  [<ffffffff8100733b>] syscall_return_slowpath+0x16b/0x240
>> arch/x86/entry/common.c:344
>>  [<ffffffff868dafe2>] int_ret_from_sys_call+0x25/0x9f
>> arch/x86/entry/entry_64.S:281
>> ---[ end trace c5e9cee9f12b7d5f ]---
>>
>>
>>
>> static void task_ctx_sched_out(struct perf_event_context *ctx)
>> {
>>         struct perf_cpu_context *cpuctx = __get_cpu_context(ctx);
>>
>>         if (!cpuctx->task_ctx)
>>                 return;
>>
>>         if (WARN_ON_ONCE(ctx != cpuctx->task_ctx))
>>                 return;
>>
>>         ctx_sched_out(ctx, cpuctx, EVENT_ALL);
>>         cpuctx->task_ctx = NULL;
>> }
>
>
>
> Also this one. I saw them regularly, but I though that they are
> induced by the use-after-frees, but now I see them on a non-tainted
> kernel:
>
>
> ------------[ cut here ]------------
> WARNING: CPU: 1 PID: 25357 at arch/x86/kernel/hw_breakpoint.c:160
> arch_uninstall_hw_breakpoint+0x1e1/0x2a0()
> Can't find any breakpoint slot
> Modules linked in:
> CPU: 1 PID: 25357 Comm: syzkaller_execu Not tainted 4.4.0-rc3+ #150
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
>  0000000000000001 ffff8800333c74e8 ffffffff82c6f2a8 0000000041b58ab3
>  ffffffff8788bf8d ffffffff82c6f1f6 ffffffff8696a5e0 ffff8800333c7560
>  ffffffff8696a620 00000000000000a0 0000000000000009 ffff8800333c74c8
> Call Trace:
>  [<     inline     >] __dump_stack lib/dump_stack.c:15
>  [<ffffffff82c6f2a8>] dump_stack+0xb2/0xfa lib/dump_stack.c:50
>  [<ffffffff812ca446>] warn_slowpath_common+0xe6/0x170 kernel/panic.c:460
>  [<ffffffff812ca579>] warn_slowpath_fmt+0xa9/0xd0 kernel/panic.c:472
>  [<ffffffff811a1c31>] arch_uninstall_hw_breakpoint+0x1e1/0x2a0
> arch/x86/kernel/hw_breakpoint.c:160
>  [<ffffffff8165e1b5>] hw_breakpoint_del+0x15/0x20
> kernel/events/hw_breakpoint.c:595
>  [<ffffffff81631aa4>] event_sched_out+0x704/0x1270 kernel/events/core.c:1580
>  [<ffffffff81632681>] group_sched_out+0x71/0x1f0 kernel/events/core.c:1606
>  [<ffffffff81632d02>] ctx_sched_out+0x502/0x700 kernel/events/core.c:2414
>  [<     inline     >] perf_event_context_sched_out kernel/events/core.c:2593
>  [<ffffffff81645524>] __perf_event_task_sched_out+0x4d4/0x1800
> kernel/events/core.c:2678
>  [<     inline     >] perf_event_task_sched_out include/linux/perf_event.h:946
>  [<     inline     >] prepare_task_switch kernel/sched/core.c:2489
>  [<     inline     >] context_switch kernel/sched/core.c:2647
>  [<ffffffff868c986f>] __schedule+0xa0f/0x1f40 kernel/sched/core.c:3156
>  [<ffffffff868cae0d>] schedule+0x6d/0x210 kernel/sched/core.c:3185
>  [<     inline     >] freezable_schedule include/linux/freezer.h:171
>  [<ffffffff814c09c6>] futex_wait_queue_me+0x306/0x680 kernel/futex.c:2188
>  [<ffffffff814c238c>] futex_wait+0x22c/0x6b0 kernel/futex.c:2303
>  [<ffffffff814c6c3d>] do_futex+0x20d/0x19d0 kernel/futex.c:3067
>  [<     inline     >] SYSC_futex kernel/futex.c:3127
>  [<ffffffff814c8533>] SyS_futex+0x133/0x2b0 kernel/futex.c:3095
>  [<ffffffff868dafb8>] tracesys_phase2+0x88/0x8d arch/x86/entry/entry_64.S:269
> ---[ end trace 624ab9515f02dd2b ]---



Hit exactly the same use-after-free report without using bpf (just
perf_event_open and perf ioctl's).