On Tue, Dec 8, 2015 at 5:44 PM, Peter Zijlstra <pet...@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
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
