Re: use-after-free in __perf_install_in_context

[Dmitry Vyukov <dvyukov@google.com>]

On Tue, Dec 8, 2015 at 5:44 PM, Peter Zijlstra <peterz@infradead.org> wrote:
> On Mon, Dec 07, 2015 at 05:09:21PM +0100, Dmitry Vyukov wrote:
>> If your audit does not give any results, can you give me a patch that
>> prints rcu callback submission stacks in KASAN reports?
>
> Just because my brain is fried for today, I figured I'd give it a go.
>
> Completely untested..
>
> ---
>  include/linux/slub_def.h |  2 ++
>  kernel/rcu/tree_plugin.h |  1 +
>  mm/slub.c                | 34 ++++++++++++++++++++++++++++++++--
>  3 files changed, 35 insertions(+), 2 deletions(-)
>
> diff --git a/include/linux/slub_def.h b/include/linux/slub_def.h
> index 33885118523c..445b586c0bfa 100644
> --- a/include/linux/slub_def.h
> +++ b/include/linux/slub_def.h
> @@ -129,4 +129,6 @@ static inline void *virt_to_obj(struct kmem_cache *s,
>  void object_err(struct kmem_cache *s, struct page *page,
>                 u8 *object, char *reason);
>
> +void object_set_indirect(const void *addr);
> +
>  #endif /* _LINUX_SLUB_DEF_H */
> diff --git a/kernel/rcu/tree_plugin.h b/kernel/rcu/tree_plugin.h
> index 630c19772630..4e1e79e01e34 100644
> --- a/kernel/rcu/tree_plugin.h
> +++ b/kernel/rcu/tree_plugin.h
> @@ -659,6 +659,7 @@ static void rcu_preempt_do_callbacks(void)
>   */
>  void call_rcu(struct rcu_head *head, rcu_callback_t func)
>  {
> +       object_set_indirect(head);
>         __call_rcu(head, func, rcu_state_p, -1, 0);
>  }
>  EXPORT_SYMBOL_GPL(call_rcu);
> diff --git a/mm/slub.c b/mm/slub.c
> index 46997517406e..6977dc7cffcd 100644
> --- a/mm/slub.c
> +++ b/mm/slub.c
> @@ -196,7 +196,12 @@ struct track {
>         unsigned long when;     /* When did the operation occur */
>  };
>
> -enum track_item { TRACK_ALLOC, TRACK_FREE };
> +enum track_item {
> +       TRACK_ALLOC = 0,
> +       TRACK_FREE,
> +       TRACK_INDIRECT,
> +       TRACK_NR,
> +};
>
>  #ifdef CONFIG_SYSFS
>  static int sysfs_slab_add(struct kmem_cache *);
> @@ -551,6 +556,7 @@ static void init_tracking(struct kmem_cache *s, void *object)
>
>         set_track(s, object, TRACK_FREE, 0UL);
>         set_track(s, object, TRACK_ALLOC, 0UL);
> +       set_track(s, object, TRACK_INDIRECT, 0UL);
>  }
>
>  static void print_track(const char *s, struct track *t)
> @@ -579,6 +585,7 @@ static void print_tracking(struct kmem_cache *s, void *object)
>
>         print_track("Allocated", get_track(s, object, TRACK_ALLOC));
>         print_track("Freed", get_track(s, object, TRACK_FREE));
> +       print_track("Indirect", get_track(s, object, TRACK_INDIRECT));
>  }
>
>  static void print_page_info(struct page *page)
> @@ -652,6 +659,29 @@ static void print_trailer(struct kmem_cache *s, struct page *page, u8 *p)
>         dump_stack();
>  }
>
> +void object_set_indirect(const void *addr)
> +{
> +       if ((addr >= (void *)PAGE_OFFSET) &&
> +               (addr < high_memory)) {
> +               struct page *page = virt_to_head_page(addr);
> +
> +               if (PageSlab(page)) {
> +                       void *object;
> +                       struct kmem_cache *cache = page->slab_cache;
> +                       void *last_object;
> +
> +                       object = virt_to_obj(cache, page_address(page), addr);
> +                       last_object = page_address(page) +
> +                               page->objects * cache->size;
> +
> +                       if (unlikely(object > last_object))
> +                               object = last_object; /* we hit into padding */
> +
> +                       set_track(cache, object, TRACK_INDIRECT, (unsigned long)addr);
> +               }
> +       }
> +}
> +
>  void object_err(struct kmem_cache *s, struct page *page,
>                         u8 *object, char *reason)
>  {
> @@ -767,7 +797,7 @@ static int check_pad_bytes(struct kmem_cache *s, struct page *page, u8 *p)
>
>         if (s->flags & SLAB_STORE_USER)
>                 /* We also have user information there */
> -               off += 2 * sizeof(struct track);
> +               off += TRACK_NR * sizeof(struct track);
>
>         if (s->size == off)
>                 return 1;


Peter,

Tested with your patches.
The additional WARNING does not fire.
For the rcu stacks, I had to change two more 2's to TRACK_NR and also
moved memorization from call_rcu to __call_rcu, but now it is working.
Two reports with indirect stack:


BUG: KASAN: use-after-free in __lock_acquire+0x4e99/0x5100 at addr
ffff88003096c640
BUG kmalloc-1024 (Not tainted): kasan: bad access detected
-----------------------------------------------------------------------------

irq event stamp: 136
hardirqs last  enabled at (135): [<ffffffff814c12e4>]
__raw_spin_lock_init+0x24/0x120 kernel/locking/spinlock_debug.c:23
hardirqs last disabled at (136): [<ffffffff8183c967>]
__slab_alloc+0x37/0x90 mm/slub.c:2487
softirqs last  enabled at (38): [<ffffffff8138417d>]
__do_softirq+0x5ed/0xb40 kernel/softirq.c:299
softirqs last disabled at (31): [<     inline     >] invoke_softirq
kernel/softirq.c:350
softirqs last disabled at (31): [<ffffffff813849d5>]
irq_exit+0x165/0x1e0 kernel/softirq.c:391

INFO: Allocated in alloc_perf_context+0x4c/0x100 age=220 cpu=1 pid=15649
[<      none      >] ___slab_alloc+0x648/0x8c0 mm/slub.c:2468
[<      none      >] __slab_alloc+0x4c/0x90 mm/slub.c:2497
[<     inline     >] slab_alloc_node mm/slub.c:2560
[<     inline     >] slab_alloc mm/slub.c:2602
[<      none      >] kmem_cache_alloc_trace+0x23c/0x3f0 mm/slub.c:2619
[<     inline     >] kmalloc include/linux/slab.h:458
[<     inline     >] kzalloc include/linux/slab.h:602
[<      none      >] alloc_perf_context+0x4c/0x100 kernel/events/core.c:3405
[<      none      >] find_get_context+0x187/0x830 kernel/events/core.c:3512
[<      none      >] SYSC_perf_event_open+0xe50/0x21a0 kernel/events/core.c:8381
[<      none      >] SyS_perf_event_open+0x39/0x50 kernel/events/core.c:8242
[<      none      >] tracesys_phase2+0x88/0x8d arch/x86/entry/entry_64.S:269

INFO: Freed in free_ctx+0x4b/0x70 age=89 cpu=3 pid=21
[<      none      >] __slab_free+0x21e/0x3e0 mm/slub.c:2678
[<     inline     >] slab_free mm/slub.c:2833
[<      none      >] kfree+0x26f/0x3e0 mm/slub.c:3662
[<      none      >] free_ctx+0x4b/0x70 kernel/events/core.c:872
[<     inline     >] __rcu_reclaim kernel/rcu/rcu.h:118
[<     inline     >] rcu_do_batch kernel/rcu/tree.c:2693
[<     inline     >] invoke_rcu_callbacks kernel/rcu/tree.c:2961
[<     inline     >] __rcu_process_callbacks kernel/rcu/tree.c:2928
[<      none      >] rcu_process_callbacks+0x631/0x19e0 kernel/rcu/tree.c:2945
[<      none      >] __do_softirq+0x2e5/0xb40 kernel/softirq.c:273
[<      none      >] run_ksoftirqd+0x20/0x50 kernel/softirq.c:662
[<      none      >] smpboot_thread_fn+0x41d/0x850 kernel/smpboot.c:163
[<      none      >] kthread+0x21d/0x2e0 drivers/block/aoe/aoecmd.c:1314
[<      none      >] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:468

INFO: Indirect in __call_rcu.constprop.63+0x7e/0xe30 age=126 cpu=3 pid=15645
[<      none      >] __call_rcu.constprop.63+0x7e/0xe30 kernel/rcu/tree.c:3048
[<      none      >] call_rcu_sched+0x26/0x30 kernel/rcu/tree.c:3117
[<      none      >] put_ctx+0x150/0x250 kernel/events/core.c:891
[<     inline     >] __free_event kernel/events/core.c:3707
[<      none      >] _free_event+0x2c7/0xaa0 kernel/events/core.c:3738
[<      none      >] put_event+0x294/0x4d0 kernel/events/core.c:3834
[<      none      >] perf_release+0x3c/0x60 kernel/events/core.c:3849
[<      none      >] __fput+0x244/0x860 fs/file_table.c:208
[<      none      >] ____fput+0x15/0x20 fs/file_table.c:244
[<      none      >] task_work_run+0x130/0x240 kernel/task_work.c:115
[<     inline     >] exit_task_work include/linux/task_work.h:21
[<      none      >] do_exit+0x885/0x3050 kernel/exit.c:750
[<      none      >] do_group_exit+0xec/0x390 kernel/exit.c:880
[<      none      >] get_signal+0x677/0x1bf0 kernel/signal.c:2307
[<      none      >] do_signal+0x7e/0x2170 arch/x86/kernel/signal.c:709
[<      none      >] exit_to_usermode_loop+0xfe/0x1e0
arch/x86/entry/common.c:247
[<     inline     >] prepare_exit_to_usermode arch/x86/entry/common.c:282
[<      none      >] syscall_return_slowpath+0x16b/0x240
arch/x86/entry/common.c:344
[<      none      >] int_ret_from_sys_call+0x25/0x9f
arch/x86/entry/entry_64.S:281

INFO: Slab 0xffffea0000c25a00 objects=21 used=1 fp=0xffff88003096d7a8
flags=0x1fffc0000004080
INFO: Object 0xffff88003096c620 @offset=17952 fp=0x          (null)
CPU: 1 PID: 15687 Comm: syzkaller_execu Tainted: G    B
4.4.0-rc3+ #155
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
 0000000000000001 ffff88003794f680 ffffffff82e0f8b8 0000000041b58ab3
 ffffffff87a9a27d ffffffff82e0f806 ffff880033c62e80 ffffffff87abb3d1
 ffff88003e806d00 0000000000000008 ffff88003096c620 ffff88003794f680

Call Trace:
 [<     inline     >] __dump_stack lib/dump_stack.c:15
 [<ffffffff82e0f8b8>] dump_stack+0xb2/0xfa lib/dump_stack.c:50
 [<ffffffff818369dc>] print_trailer+0x12c/0x210 mm/slub.c:659
 [<ffffffff81841a3f>] object_err+0x2f/0x40 mm/slub.c:689
 [<     inline     >] print_address_description mm/kasan/report.c:138
 [<ffffffff818457a9>] kasan_report_error+0x5d9/0x860 mm/kasan/report.c:251
 [<     inline     >] kasan_report mm/kasan/report.c:274
 [<ffffffff81845bd4>] __asan_report_load8_noabort+0x54/0x70
mm/kasan/report.c:295
 [<ffffffff814b25f9>] __lock_acquire+0x4e99/0x5100 kernel/locking/lockdep.c:3092
 [<ffffffff814b517d>] lock_acquire+0x19d/0x3f0 kernel/locking/lockdep.c:3585
 [<     inline     >] __raw_spin_lock include/linux/spinlock_api_smp.h:144
 [<ffffffff86a89591>] _raw_spin_lock+0x31/0x40 kernel/locking/spinlock.c:151
 [<     inline     >] perf_ctx_lock kernel/events/core.c:351
 [<ffffffff816e15d9>] __perf_install_in_context+0x109/0xa00
kernel/events/core.c:2083
 [<ffffffff816cb7ba>] remote_function+0x14a/0x200 kernel/events/core.c:74
 [<ffffffff81572787>] generic_exec_single+0x2a7/0x490 kernel/smp.c:156
 [<ffffffff81573350>] smp_call_function_single+0x200/0x310 kernel/smp.c:300
 [<ffffffff816c9bd3>] task_function_call+0x123/0x160 kernel/events/core.c:101
 [<ffffffff816d1bf1>] perf_install_in_context+0x201/0x340
kernel/events/core.c:2164
 [<ffffffff816f62e5>] SYSC_perf_event_open+0x1465/0x21a0
kernel/events/core.c:8546
 [<ffffffff816ff449>] SyS_perf_event_open+0x39/0x50 kernel/events/core.c:8242
 [<ffffffff86a8a3b6>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185







BUG: KASAN: use-after-free in __lock_acquire+0x4e99/0x5100 at addr
ffff88005f77aee0
Read of size 8 by task syzkaller_execu/30337
=============================================================================
BUG kmalloc-1024 (Not tainted): kasan: bad access detected
-----------------------------------------------------------------------------

Disabling lock debugging due to kernel taint
INFO: Allocated in alloc_perf_context+0x4c/0x100 age=124 cpu=3 pid=30312
[<      none      >] ___slab_alloc+0x648/0x8c0 mm/slub.c:2468
[<      none      >] __slab_alloc+0x4c/0x90 mm/slub.c:2497
[<     inline     >] slab_alloc_node mm/slub.c:2560
[<     inline     >] slab_alloc mm/slub.c:2602
[<      none      >] kmem_cache_alloc_trace+0x23c/0x3f0 mm/slub.c:2619
[<     inline     >] kmalloc include/linux/slab.h:458
[<     inline     >] kzalloc include/linux/slab.h:602
[<      none      >] alloc_perf_context+0x4c/0x100 kernel/events/core.c:3405
[<      none      >] find_get_context+0x187/0x830 kernel/events/core.c:3512
[<      none      >] SYSC_perf_event_open+0xe50/0x21a0 kernel/events/core.c:8381
[<      none      >] SyS_perf_event_open+0x39/0x50 kernel/events/core.c:8242
[<      none      >] tracesys_phase2+0x88/0x8d arch/x86/entry/entry_64.S:269

INFO: Freed in free_ctx+0x4b/0x70 age=74 cpu=2 pid=16
[<      none      >] __slab_free+0x21e/0x3e0 mm/slub.c:2678
[<     inline     >] slab_free mm/slub.c:2833
[<      none      >] kfree+0x26f/0x3e0 mm/slub.c:3662
[<      none      >] free_ctx+0x4b/0x70 kernel/events/core.c:872
[<     inline     >] __rcu_reclaim kernel/rcu/rcu.h:118
[<     inline     >] rcu_do_batch kernel/rcu/tree.c:2693
[<     inline     >] invoke_rcu_callbacks kernel/rcu/tree.c:2961
[<     inline     >] __rcu_process_callbacks kernel/rcu/tree.c:2928
[<      none      >] rcu_process_callbacks+0x631/0x19e0 kernel/rcu/tree.c:2945
[<      none      >] __do_softirq+0x2e5/0xb40 kernel/softirq.c:273
[<      none      >] run_ksoftirqd+0x20/0x50 kernel/softirq.c:662
[<      none      >] smpboot_thread_fn+0x41d/0x850 kernel/smpboot.c:163
[<      none      >] kthread+0x21d/0x2e0 drivers/block/aoe/aoecmd.c:1314
[<      none      >] ret_from_fork+0x3f/0x70 arch/x86/entry/entry_64.S:468

INFO: Indirect in __call_rcu.constprop.63+0x7e/0xe30 age=88 cpu=2 pid=30312
[<      none      >] __call_rcu.constprop.63+0x7e/0xe30 kernel/rcu/tree.c:3048
[<      none      >] call_rcu_sched+0x26/0x30 kernel/rcu/tree.c:3117
[<      none      >] put_ctx+0x150/0x250 kernel/events/core.c:891
[<     inline     >] perf_event_exit_task_context kernel/events/core.c:8860
[<      none      >] perf_event_exit_task+0x706/0xae0 kernel/events/core.c:8887
[<      none      >] do_exit+0x892/0x3050 kernel/exit.c:759
[<      none      >] do_group_exit+0xec/0x390 kernel/exit.c:880
[<      none      >] get_signal+0x677/0x1bf0 kernel/signal.c:2307
[<      none      >] do_signal+0x7e/0x2170 arch/x86/kernel/signal.c:709
[<      none      >] exit_to_usermode_loop+0xfe/0x1e0
arch/x86/entry/common.c:247
[<     inline     >] prepare_exit_to_usermode arch/x86/entry/common.c:282
[<      none      >] syscall_return_slowpath+0x16b/0x240
arch/x86/entry/common.c:344
[<      none      >] int_ret_from_sys_call+0x25/0x9f
arch/x86/entry/entry_64.S:281

INFO: Slab 0xffffea00017dde00 objects=21 used=8 fp=0xffff88005f77aec0
flags=0x5fffc0000004080
INFO: Object 0xffff88005f77aec0 @offset=11968 fp=0xffff88005f77b498
CPU: 3 PID: 30337 Comm: syzkaller_execu Tainted: G    B
4.4.0-rc3+ #155
Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Bochs 01/01/2011
 0000000000000003 ffff880065547680 ffffffff82e0f8b8 0000000041b58ab3
 ffffffff87a9a27d ffffffff82e0f806 ffff880064972e80 ffffffff87abb3d1
 ffff88003e806d00 0000000000000008 ffff88005f77aec0 ffff880065547680

Call Trace:
 [<     inline     >] __dump_stack lib/dump_stack.c:15
 [<ffffffff82e0f8b8>] dump_stack+0xb2/0xfa lib/dump_stack.c:50
 [<ffffffff818369dc>] print_trailer+0x12c/0x210 mm/slub.c:659
 [<ffffffff81841a3f>] object_err+0x2f/0x40 mm/slub.c:689
 [<     inline     >] print_address_description mm/kasan/report.c:138
 [<ffffffff818457a9>] kasan_report_error+0x5d9/0x860 mm/kasan/report.c:251
 [<     inline     >] kasan_report mm/kasan/report.c:274
 [<ffffffff81845bd4>] __asan_report_load8_noabort+0x54/0x70
mm/kasan/report.c:295
 [<ffffffff814b25f9>] __lock_acquire+0x4e99/0x5100 kernel/locking/lockdep.c:3092
 [<ffffffff814b517d>] lock_acquire+0x19d/0x3f0 kernel/locking/lockdep.c:3585
 [<     inline     >] __raw_spin_lock include/linux/spinlock_api_smp.h:144
 [<ffffffff86a89591>] _raw_spin_lock+0x31/0x40 kernel/locking/spinlock.c:151
 [<     inline     >] perf_ctx_lock kernel/events/core.c:351
 [<ffffffff816e15d9>] __perf_install_in_context+0x109/0xa00
kernel/events/core.c:2083
 [<ffffffff816cb7ba>] remote_function+0x14a/0x200 kernel/events/core.c:74
 [<ffffffff81572787>] generic_exec_single+0x2a7/0x490 kernel/smp.c:156
 [<ffffffff81573350>] smp_call_function_single+0x200/0x310 kernel/smp.c:300
 [<ffffffff816c9bd3>] task_function_call+0x123/0x160 kernel/events/core.c:101
 [<ffffffff816d1bf1>] perf_install_in_context+0x201/0x340
kernel/events/core.c:2164
 [<ffffffff816f62e5>] SYSC_perf_event_open+0x1465/0x21a0
kernel/events/core.c:8546
 [<ffffffff816ff449>] SyS_perf_event_open+0x39/0x50 kernel/events/core.c:8242
 [<ffffffff86a8a3b6>] entry_SYSCALL_64_fastpath+0x16/0x7a
arch/x86/entry/entry_64.S:185