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

From: Levin, Alexander (Sasha Levin)
Date: Fri Jul 28 2017 - 16:00:09 EST


On Fri, Jul 28, 2017 at 01:57:20PM -0500, Josh Poimboeuf wrote:
>Thanks, that's much better. I'm relieved the unwinder didn't screw that
>up, at least.
>
>This looks like a tricky one. Is it easily recreatable?

Yeah, I just hit it again with slightly different initial calls:

[ 49.261152] ==================================================================
[ 49.262388] BUG: KASAN: stack-out-of-bounds in deref_stack_reg+0x123/0x140
[ 49.263455] Read of size 8 at addr ffff880037bdf9a8 by task udevd/2790
[ 49.264460]
[ 49.264859] CPU: 3 PID: 2790 Comm: udevd Not tainted 4.13.0-rc2-next-20170727 #232
[ 49.266469] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.1-1ubuntu1 04/01/2014
[ 49.268372] Call Trace:
[ 49.268993] <IRQ>
[ 49.269482] dump_stack+0xab/0x105
[ 49.270255] print_address_description+0xc2/0x250
[ 49.271295] kasan_report+0x24f/0x360
[ 49.272257] ? deref_stack_reg+0x123/0x140
[ 49.273179] deref_stack_reg+0x123/0x140
[ 49.274050] ? __read_once_size_nocheck.constprop.7+0x10/0x10
[ 49.275289] ? get_stack_info+0x32/0x150
[ 49.276161] ? stack_access_ok+0xd6/0x150
[ 49.277583] ? sched_clock_cpu+0x18/0x1d0
[ 49.278493] unwind_next_frame+0xd9b/0x1b80
[ 49.279422] ? __alloc_skb+0xac/0x550
[ 49.280240] ? __lock_acquire+0xc44/0x4870
[ 49.281181] ? deref_stack_reg+0x140/0x140
[ 49.282319] __save_stack_trace+0x7d/0xf0
[ 49.283377] ? __alloc_skb+0xac/0x550
[ 49.284204] ? rcu_process_callbacks+0x599/0x12b0
[ 49.285445] save_stack+0x33/0xa0
[ 49.286331] ? save_stack+0x33/0xa0
[ 49.287115] ? kasan_slab_free+0x72/0xc0
[ 49.287983] ? kmem_cache_free+0xae/0x310
[ 49.289100] ? rcu_process_callbacks+0x599/0x12b0
[ 49.290138] ? __do_softirq+0x234/0x934
[ 49.290998] ? irq_exit+0x164/0x190
[ 49.291776] ? smp_apic_timer_interrupt+0x71/0x90
[ 49.292816] ? apic_timer_interrupt+0xb9/0xc0
[ 49.293931] ? __slab_alloc.isra.64+0x17/0xa0
[ 49.294895] ? __alloc_skb+0xac/0x550
[ 49.295718] ? lock_acquire+0x3a0/0x3a0
[ 49.296586] ? check_preemption_disabled+0x34/0x1f0
[ 49.297668] ? trace_hardirqs_on_caller+0x284/0x590
[ 49.298740] ? _raw_spin_unlock_irqrestore+0x41/0x70
[ 49.299823] ? free_object+0xce/0x160
[ 49.300673] ? __debug_check_no_obj_freed+0x400/0x900
[ 49.301790] ? check_preemption_disabled+0x34/0x1f0
[ 49.302856] ? debug_object_free+0x10/0x10
[ 49.303939] ? check_preemption_disabled+0x34/0x1f0
[ 49.305173] ? check_preemption_disabled+0x34/0x1f0
[ 49.306249] kasan_slab_free+0x72/0xc0
[ 49.307116] kmem_cache_free+0xae/0x310
[ 49.307968] rcu_process_callbacks+0x599/0x12b0
[ 49.308989] ? rcu_exp_wait_wake+0x1100/0x1100
[ 49.309974] ? check_preemption_disabled+0x34/0x1f0
[ 49.311055] __do_softirq+0x234/0x934
[ 49.311926] ? __alloc_skb+0xac/0x550
[ 49.312739] irq_exit+0x164/0x190
[ 49.313512] smp_apic_timer_interrupt+0x71/0x90
[ 49.314515] apic_timer_interrupt+0xb9/0xc0
[ 49.315442] </IRQ>
[ 49.316085] RIP: 0010:__slab_alloc.isra.64+0x17/0xa0
[ 49.317298] RSP: 0018:ffff880037bdf8d8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
[ 49.318922] RAX: 0000000000000000 RBX: 00000000014000c0 RCX: ffffffffbacd0ecc
[ 49.320445] RDX: 00000000ffffffff RSI: 00000000014000c0 RDI: ffff88003dd36640
[ 49.321973] RBP: ffff88003dd36640 R08: 0000000000000000 R09: 0000000000000003
[ 49.323505] R10: ffff880037bdfa7f R11: 0000000000000001 R12: ffff88003dd36640
[ 49.325444] R13: 00000000014000c0 R14: 00000000ffffffff R15: ffffffffbacd0ecc
[ 49.327316] ? __alloc_skb+0xac/0x550
[ 49.328140] ? __alloc_skb+0xac/0x550
[ 49.328981] __alloc_skb+0xac/0x550
[ 49.329773] ? kmem_cache_alloc_node+0xc3/0x380
[ 49.330785] ? __alloc_skb+0xac/0x550
[ 49.331604] ? skb_to_sgvec_nomark+0x40/0x40
[ 49.332557] ? security_capable+0x88/0xb0
[ 49.333471] ? netlink_sendmsg+0x8da/0xbb0
[ 49.334391] ? netlink_unicast+0x7a0/0x7a0
[ 49.335311] ? netlink_unicast+0x7a0/0x7a0
[ 49.336425] ? sock_sendmsg+0xc0/0x100
[ 49.337676] ? ___sys_sendmsg+0x7b8/0x920
[ 49.338702] ? copy_msghdr_from_user+0x380/0x380
[ 49.339755] ? kvm_clock_read+0x1f/0x30
[ 49.340591] ? kvm_sched_clock_read+0x5/0x10
[ 49.341541] ? sched_clock+0x5/0x10
[ 49.342325] ? sched_clock_cpu+0x18/0x1d0
[ 49.343213] ? sched_clock+0x5/0x10
[ 49.343997] ? check_preemption_disabled+0x34/0x1f0
[ 49.345085] ? __lock_acquire+0xc44/0x4870
[ 49.346045] ? __fget_light+0x9a/0x1e0
[ 49.347347] ? __sys_sendmsg+0xc7/0x170
[ 49.348658] ? __sys_sendmsg+0xc7/0x170
[ 49.349652] ? SyS_shutdown+0x1a0/0x1a0
[ 49.350525] ? check_preemption_disabled+0x34/0x1f0
[ 49.351594] ? syscall_trace_enter+0x324/0xe30
[ 49.352571] ? lock_acquire+0x3a0/0x3a0
[ 49.353448] ? check_preemption_disabled+0x34/0x1f0
[ 49.354790] ? SyS_sendmsg+0x27/0x40
[ 49.355602] ? __sys_sendmsg+0x170/0x170
[ 49.356477] ? do_syscall_64+0x1b0/0x600
[ 49.357874] ? entry_SYSCALL64_slow_path+0x25/0x25
[ 49.358940]
[ 49.359891] The buggy address belongs to the page:
[ 49.360940] page:ffffea0000def7c0 count:0 mapcount:0 mapping: (null) index:0x0
[ 49.362788] flags: 0xfffe0000000000()
[ 49.363608] raw: 00fffe0000000000 0000000000000000 0000000000000000 00000000ffffffff
[ 49.365286] raw: dead000000000100 dead000000000200 0000000000000000 0000000000000000
[ 49.366955] page dumped because: kasan: bad access detected
[ 49.368162]
[ 49.368529] Memory state around the buggy address:
[ 49.370008] ffff880037bdf880: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[ 49.371916] ffff880037bdf900: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 f1
[ 49.373692] >ffff880037bdf980: f1 f1 f1 01 f4 f4 f4 00 00 00 00 00 00 00 00 00
[ 49.375240] ^
[ 49.376235] ffff880037bdfa00: 00 00 00 00 00 00 00 00 f1 f1 f1 f1 00 00 00 00
[ 49.377794] ffff880037bdfa80: f3 f3 f3 f3 00 00 00 00 00 00 00 00 00 00 00 00
[ 49.379539] ==================================================================
[ 49.381628] Disabling lock debugging due to kernel taint
[ 49.382908] Kernel panic - not syncing: panic_on_warn set ...
[ 49.382908]
[ 49.384486] CPU: 3 PID: 2790 Comm: udevd Tainted: G B 4.13.0-rc2-next-20170727 #232
[ 49.386541] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.1-1ubuntu1 04/01/2014
[ 49.388443] Call Trace:
[ 49.389006] <IRQ>
[ 49.389478] dump_stack+0xab/0x105
[ 49.390242] panic+0x1bc/0x3ba
[ 49.390929] ? __warn+0x1d6/0x1d6
[ 49.391687] kasan_end_report+0x4a/0x50
[ 49.392572] kasan_report+0x168/0x360
[ 49.393737] ? deref_stack_reg+0x123/0x140
[ 49.394644] deref_stack_reg+0x123/0x140
[ 49.395511] ? __read_once_size_nocheck.constprop.7+0x10/0x10
[ 49.396757] ? get_stack_info+0x32/0x150
[ 49.397622] ? stack_access_ok+0xd6/0x150
[ 49.398504] ? sched_clock_cpu+0x18/0x1d0
[ 49.399395] unwind_next_frame+0xd9b/0x1b80
[ 49.400313] ? __alloc_skb+0xac/0x550
[ 49.401133] ? __lock_acquire+0xc44/0x4870
[ 49.402029] ? deref_stack_reg+0x140/0x140
[ 49.402928] __save_stack_trace+0x7d/0xf0
[ 49.403954] ? __alloc_skb+0xac/0x550
[ 49.404984] ? rcu_process_callbacks+0x599/0x12b0
[ 49.406006] save_stack+0x33/0xa0
[ 49.406947] ? save_stack+0x33/0xa0
[ 49.407729] ? kasan_slab_free+0x72/0xc0
[ 49.408628] ? kmem_cache_free+0xae/0x310
[ 49.409497] ? rcu_process_callbacks+0x599/0x12b0
[ 49.410519] ? __do_softirq+0x234/0x934
[ 49.411353] ? irq_exit+0x164/0x190
[ 49.412110] ? smp_apic_timer_interrupt+0x71/0x90
[ 49.413121] ? apic_timer_interrupt+0xb9/0xc0
[ 49.414048] ? __slab_alloc.isra.64+0x17/0xa0
[ 49.415133] ? __alloc_skb+0xac/0x550
[ 49.415925] ? lock_acquire+0x3a0/0x3a0
[ 49.416768] ? check_preemption_disabled+0x34/0x1f0
[ 49.417809] ? trace_hardirqs_on_caller+0x284/0x590
[ 49.418847] ? _raw_spin_unlock_irqrestore+0x41/0x70
[ 49.419907] ? free_object+0xce/0x160
[ 49.420705] ? __debug_check_no_obj_freed+0x400/0x900
[ 49.421797] ? check_preemption_disabled+0x34/0x1f0
[ 49.422831] ? debug_object_free+0x10/0x10
[ 49.423708] ? check_preemption_disabled+0x34/0x1f0
[ 49.424751] ? check_preemption_disabled+0x34/0x1f0
[ 49.425932] kasan_slab_free+0x72/0xc0
[ 49.426740] kmem_cache_free+0xae/0x310
[ 49.427566] rcu_process_callbacks+0x599/0x12b0
[ 49.428538] ? rcu_exp_wait_wake+0x1100/0x1100
[ 49.429699] ? check_preemption_disabled+0x34/0x1f0
[ 49.430747] __do_softirq+0x234/0x934
[ 49.431551] ? __alloc_skb+0xac/0x550
[ 49.432352] irq_exit+0x164/0x190
[ 49.433078] smp_apic_timer_interrupt+0x71/0x90
[ 49.434048] apic_timer_interrupt+0xb9/0xc0
[ 49.434942] </IRQ>
[ 49.435417] RIP: 0010:__slab_alloc.isra.64+0x17/0xa0
[ 49.436473] RSP: 0018:ffff880037bdf8d8 EFLAGS: 00000246 ORIG_RAX: ffffffffffffff10
[ 49.438230] RAX: 0000000000000000 RBX: 00000000014000c0 RCX: ffffffffbacd0ecc
[ 49.439739] RDX: 00000000ffffffff RSI: 00000000014000c0 RDI: ffff88003dd36640
[ 49.441467] RBP: ffff88003dd36640 R08: 0000000000000000 R09: 0000000000000003
[ 49.442972] R10: ffff880037bdfa7f R11: 0000000000000001 R12: ffff88003dd36640
[ 49.444478] R13: 00000000014000c0 R14: 00000000ffffffff R15: ffffffffbacd0ecc
[ 49.445989] ? __alloc_skb+0xac/0x550
[ 49.446777] ? __alloc_skb+0xac/0x550
[ 49.447570] __alloc_skb+0xac/0x550
[ 49.448491] ? kmem_cache_alloc_node+0xc3/0x380
[ 49.449477] ? __alloc_skb+0xac/0x550
[ 49.450269] ? skb_to_sgvec_nomark+0x40/0x40
[ 49.451186] ? security_capable+0x88/0xb0
[ 49.452057] ? netlink_sendmsg+0x8da/0xbb0
[ 49.452948] ? netlink_unicast+0x7a0/0x7a0
[ 49.453831] ? netlink_unicast+0x7a0/0x7a0
[ 49.454719] ? sock_sendmsg+0xc0/0x100
[ 49.455525] ? ___sys_sendmsg+0x7b8/0x920
[ 49.456389] ? copy_msghdr_from_user+0x380/0x380
[ 49.457390] ? kvm_clock_read+0x1f/0x30
[ 49.458216] ? kvm_sched_clock_read+0x5/0x10
[ 49.459281] ? sched_clock+0x5/0x10
[ 49.460041] ? sched_clock_cpu+0x18/0x1d0
[ 49.460912] ? sched_clock+0x5/0x10
[ 49.461670] ? check_preemption_disabled+0x34/0x1f0
[ 49.462710] ? __lock_acquire+0xc44/0x4870
[ 49.463598] ? __fget_light+0x9a/0x1e0
[ 49.464406] ? __sys_sendmsg+0xc7/0x170
[ 49.465244] ? __sys_sendmsg+0xc7/0x170
[ 49.466060] ? SyS_shutdown+0x1a0/0x1a0
[ 49.466886] ? check_preemption_disabled+0x34/0x1f0
[ 49.467920] ? syscall_trace_enter+0x324/0xe30
[ 49.468877] ? lock_acquire+0x3a0/0x3a0
[ 49.469700] ? check_preemption_disabled+0x34/0x1f0
[ 49.470891] ? SyS_sendmsg+0x27/0x40
[ 49.471664] ? __sys_sendmsg+0x170/0x170
[ 49.472509] ? do_syscall_64+0x1b0/0x600
[ 49.473361] ? entry_SYSCALL64_slow_path+0x25/0x25
[ 49.474538] Dumping ftrace buffer:
[ 49.475276] (ftrace buffer empty)
[ 49.476055] Kernel Offset: 0x37400000 from 0xffffffff81000000 (relocation range: 0xffffffff80000000-0xffffffffbfffffff)
[ 49.478324] Rebooting in 86400 seconds..

>Any chance you'd be able to share the vmlinux file somehow? If not, at
>least the .config file, GCC version, and code level would be useful so I
>can try to build a similar image.

vmlinux is a bit big, ~180MB in my case. If you have somewhere to upload it to I'd be happy to push it.

Attached my config.

GCC is 7.1.0.

--

Thanks,
Sasha

Attachment: config-sasha.gz
Description: config-sasha.gz