Re: [PATCH v4 1/2] x86/unwind: add ORC unwinder

[Josh Poimboeuf]

On Fri, Jul 28, 2017 at 04:48:47PM +0000, Levin, Alexander (Sasha Levin) wrote:
> Hey Josh,
> 
> Syzkaller seems to trigger the following:
> 
> ==================================================================
> BUG: KASAN: stack-out-of-bounds in __read_once_size include/linux/compiler.h:253 [inline]
> BUG: KASAN: stack-out-of-bounds in deref_stack_reg+0x123/0x140 arch/x86/kernel/unwind_orc.c:282
> Read of size 8 at addr ffff8800374a7b28 by task syz-executor4/6474
> 
> CPU: 2 PID: 6474 Comm: syz-executor4 Not tainted 4.13.0-rc2-next-20170727 #232
> Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.1-1ubuntu1 04/01/2014
> Call Trace:
>  <IRQ>
>  __dump_stack lib/dump_stack.c:16 [inline]
>  dump_stack+0xab/0x105 lib/dump_stack.c:52
>  print_address_description+0xc2/0x250 mm/kasan/report.c:252
>  kasan_report_error mm/kasan/report.c:351 [inline]
>  kasan_report+0x24f/0x360 mm/kasan/report.c:408
>  __read_once_size include/linux/compiler.h:253 [inline]
>  deref_stack_reg+0x123/0x140 arch/x86/kernel/unwind_orc.c:282
>  unwind_next_frame+0xd9b/0x1b80 arch/x86/kernel/unwind_orc.c:426
>  __save_stack_trace+0x7d/0xf0 arch/x86/kernel/stacktrace.c:44
>  save_stack+0x33/0xa0 mm/kasan/kasan.c:447
>  set_track mm/kasan/kasan.c:459 [inline]
>  kasan_slab_free+0x72/0xc0 mm/kasan/kasan.c:524
>  slab_free_hook mm/slub.c:1357 [inline]
>  slab_free_freelist_hook mm/slub.c:1379 [inline]
>  slab_free mm/slub.c:2955 [inline]
>  kmem_cache_free+0xae/0x310 mm/slub.c:2977
>  put_pid+0xe2/0x120 kernel/pid.c:246
>  __rcu_reclaim kernel/rcu/rcu.h:195 [inline]
>  rcu_do_batch kernel/rcu/tree.c:2666 [inline]
>  invoke_rcu_callbacks kernel/rcu/tree.c:2920 [inline]
>  __rcu_process_callbacks kernel/rcu/tree.c:2887 [inline]
>  rcu_process_callbacks+0x599/0x12b0 kernel/rcu/tree.c:2904
>  __do_softirq+0x234/0x934 kernel/softirq.c:284
>  invoke_softirq kernel/softirq.c:364 [inline]
>  irq_exit+0x164/0x190 kernel/softirq.c:405
>  exiting_irq arch/x86/include/asm/apic.h:638 [inline]
>  smp_apic_timer_interrupt+0x71/0x90 arch/x86/kernel/apic/apic.c:1044
>  apic_timer_interrupt+0xb9/0xc0 arch/x86/entry/entry_64.S:793
>  </IRQ>
> RIP: 0010:arch_local_irq_enable arch/x86/include/asm/paravirt.h:824 [inline]
> RIP: 0010:preempt_schedule_irq+0x71/0xd0 kernel/sched/core.c:3579
> RSP: 0018:ffff8800374a7958 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
> RAX: 0000000000000007 RBX: ffffed0006d95808 RCX: 1ffffffff534d022
> RDX: 0000000000000000 RSI: ffffffffa7065fe0 RDI: ffff880036cac9a4
> RBP: 0000000000000000 R08: ffff88007ffd709c R09: 0000000000000000
> R10: 0000000000000000 R11: 0000000000000000 R12: ffff880036cac040
> R13: 00000000000002eb R14: ffff880036cac040 R15: ffff88005fdc2728
>  retint_kernel+0x1b/0x2d
> RIP: 0010:arch_local_save_flags arch/x86/include/asm/paravirt.h:809 [inline]
> RIP: 0010:___might_sleep+0x159/0x480 kernel/sched/core.c:5968
> RSP: 0018:ffff8800374a7a28 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff02
> RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000001
> RDX: 1ffff10006d95882 RSI: 00000000ffffffff RDI: ffff880036cac410
> RBP: 0000000000000000 R08: ffffffffa3b1546e R09: dffffc0000000000
> R10: ffff8800374a7c08 R11: 0000000000000001 R12: ffffffffa7065320
> R13: 00000000000002eb R14: ffff880036cac040 R15: ffff88005fdc2728
>  ext4_orphan_add+0x34e/0xd70 fs/ext4/namei.c:2801

Thanks for reporting this.  I'm confused by the stack trace.  It seems
to end at ext4_orphan_add, which would normally make sense because the
unwinder would have stopped when it read the bad address on the stack.

But there aren't any of the '?' entries, which should still be there.
Any chance your post-processing script removes those?  Can you share the
raw dmesg before it was post-processed?

-- 
Josh