mm: slub: gpf in deactivate_slab
Hi all,
While fuzzing with trinity inside a KVM tools guest running latest -next kernel I've stumbled on the following spew:
[ 241.916559] BUG: unable to handle kernel paging request at ffff880029aa5e58 [ 241.917961] IP: [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.919439] PGD 88f9067 PUD 88fa067 PMD 102fd35067 PTE 8000000029aa5060 [ 241.920339] Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC [ 241.920339] Dumping ftrace buffer: [ 241.920339] (ftrace buffer empty) [ 241.920339] Modules linked in: [ 241.920339] CPU: 17 PID: 9910 Comm: trinity-c183 Tainted: G W 3.14.0-rc6-next-20140311-sasha-00009-g6c028cd-dirty #146 [ 241.920339] task: ffff88090eb68000 ti: ffff88090eb70000 task.ti: ffff88090eb70000 [ 241.920339] RIP: 0010:[<ffffffff812c5fa3>] [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.920339] RSP: 0018:ffff88090eb71c18 EFLAGS: 00010082 [ 241.920339] RAX: 0000000000000418 RBX: ffff880229ae2010 RCX: 0000000180170017 [ 241.920339] RDX: 0000000000000000 RSI: ffffffff812c5f52 RDI: ffffffff812c5e29 [ 241.920339] RBP: ffff88090eb71d28 R08: ffff880229ae2010 R09: 0000000000000080 [ 241.920339] R10: ffff880229ae2ed0 R11: 0000000000000000 R12: ffffea0008a6b800 [ 241.920339] R13: ffff88012b4da580 R14: ffff880029aa5a40 R15: ffff880229ae2010 [ 241.920339] FS: 00007fb615415700(0000) GS:ffff88022ba00000(0000) knlGS:0000000000000000 [ 241.920339] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [ 241.920339] CR2: ffff880029aa5e58 CR3: 000000090eb4a000 CR4: 00000000000006a0 [ 241.920339] DR0: 0000000000005bf2 DR1: 0000000000000000 DR2: 0000000000000000 [ 241.920339] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000070602 [ 241.920339] Stack: [ 241.920339] ffffffff856e37ab ffffffff84486272 0000000000000000 000000002b405600 [ 241.920339] ffff88090eb71c58 ffff88090eb70000 0000000000000011 ffff88022ba03fc0 [ 241.920339] ffff88090eb71cb8 000000000000000f ffff88022b405600 ffff880029aa5a40 [ 241.920339] Call Trace: [ 241.920339] [<ffffffff84486272>] ? preempt_count_sub+0xe2/0x120 [ 241.920339] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff812c36eb>] ? set_track+0xab/0x100 [ 241.954886] [<ffffffff812c731f>] __slab_alloc+0x42f/0x4d0 [ 241.954886] [<ffffffff81073e6d>] ? sched_clock+0x1d/0x30 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff812c870f>] kmem_cache_alloc+0x12f/0x2e0 [ 241.961624] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff8130f151>] alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff8130f1cb>] new_inode_pseudo+0x1b/0x70 [ 241.961624] [<ffffffff812f985c>] get_pipe_inode+0x1c/0xf0 [ 241.961624] [<ffffffff812f995c>] create_pipe_files+0x2c/0x170 [ 241.961624] [<ffffffff812f9ae1>] __do_pipe_flags+0x41/0xf0 [ 241.961624] [<ffffffff812f9bbb>] SyS_pipe2+0x2b/0xb0 [ 241.961624] [<ffffffff8448b3b1>] ? tracesys+0x7e/0xe2 [ 241.961624] [<ffffffff8448b410>] tracesys+0xdd/0xe2 [ 241.972975] Code: 4d 85 f6 75 8b eb 45 90 4d 85 f6 75 13 49 8b 5c 24 10 45 31 ff 0f 1f 00 eb 32 66 0f 1f 44 00 00 4c 89 b5 48 ff ff ff 49 63 45 20 <49> 8b 0c 06 48 85 c9 74 10 4d 89 f7 49 8b 54 24 10 49 89 ce e9 [ 241.972975] RIP [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.972975] RSP <ffff88090eb71c18> [ 241.972975] CR2: ffff880029aa5e58
Thanks,
Sasha
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 45 lines · Sasha Levin
Hi all,
While fuzzing with trinity inside a KVM tools guest running latest -next kernel I've stumbled on the following spew:
[ 241.916559] BUG: unable to handle kernel paging request at ffff880029aa5e58 [ 241.917961] IP: [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.919439] PGD 88f9067 PUD 88fa067 PMD 102fd35067 PTE 8000000029aa5060 [ 241.920339] Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC [ 241.920339] Dumping ftrace buffer: [ 241.920339] (ftrace buffer empty) [ 241.920339] Modules linked in: [ 241.920339] CPU: 17 PID: 9910 Comm: trinity-c183 Tainted: G W 3.14.0-rc6-next-20140311-sasha-00009-g6c028cd-dirty #146 [ 241.920339] task: ffff88090eb68000 ti: ffff88090eb70000 task.ti: ffff88090eb70000 [ 241.920339] RIP: 0010:[<ffffffff812c5fa3>] [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.920339] RSP: 0018:ffff88090eb71c18 EFLAGS: 00010082 [ 241.920339] RAX: 0000000000000418 RBX: ffff880229ae2010 RCX: 0000000180170017 [ 241.920339] RDX: 0000000000000000 RSI: ffffffff812c5f52 RDI: ffffffff812c5e29 [ 241.920339] RBP: ffff88090eb71d28 R08: ffff880229ae2010 R09: 0000000000000080 [ 241.920339] R10: ffff880229ae2ed0 R11: 0000000000000000 R12: ffffea0008a6b800 [ 241.920339] R13: ffff88012b4da580 R14: ffff880029aa5a40 R15: ffff880229ae2010 [ 241.920339] FS: 00007fb615415700(0000) GS:ffff88022ba00000(0000) knlGS:0000000000000000 [ 241.920339] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [ 241.920339] CR2: ffff880029aa5e58 CR3: 000000090eb4a000 CR4: 00000000000006a0 [ 241.920339] DR0: 0000000000005bf2 DR1: 0000000000000000 DR2: 0000000000000000 [ 241.920339] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000070602 [ 241.920339] Stack: [ 241.920339] ffffffff856e37ab ffffffff84486272 0000000000000000 000000002b405600 [ 241.920339] ffff88090eb71c58 ffff88090eb70000 0000000000000011 ffff88022ba03fc0 [ 241.920339] ffff88090eb71cb8 000000000000000f ffff88022b405600 ffff880029aa5a40 [ 241.920339] Call Trace: [ 241.920339] [<ffffffff84486272>] ? preempt_count_sub+0xe2/0x120 [ 241.920339] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff812c36eb>] ? set_track+0xab/0x100 [ 241.954886] [<ffffffff812c731f>] __slab_alloc+0x42f/0x4d0 [ 241.954886] [<ffffffff81073e6d>] ? sched_clock+0x1d/0x30 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff812c870f>] kmem_cache_alloc+0x12f/0x2e0 [ 241.961624] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff8130f151>] alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff8130f1cb>] new_inode_pseudo+0x1b/0x70 [ 241.961624] [<ffffffff812f985c>] get_pipe_inode+0x1c/0xf0 [ 241.961624] [<ffffffff812f995c>] create_pipe_files+0x2c/0x170
Quoted 8 lines
[ 241.961624] [<ffffffff812f9ae1>] __do_pipe_flags+0x41/0xf0 [ 241.961624] [<ffffffff812f9bbb>] SyS_pipe2+0x2b/0xb0 [ 241.961624] [<ffffffff8448b3b1>] ? tracesys+0x7e/0xe2 [ 241.961624] [<ffffffff8448b410>] tracesys+0xdd/0xe2 [ 241.972975] Code: 4d 85 f6 75 8b eb 45 90 4d 85 f6 75 13 49 8b 5c 24 10 45 31 ff 0f 1f 00 eb 32 66 0f 1f 44 00 00 4c 89 b5 48 ff ff ff 49 63 45 20 <49> 8b 0c 06 48 85 c9 74 10 4d 89 f7 49 8b 54 24 10 49 89 ce e9 [ 241.972975] RIP [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.972975] RSP <ffff88090eb71c18> [ 241.972975] CR2: ffff880029aa5e58
I have a lead on this. Consider the following:
kmem_cache_alloc
__slab_alloc
local_irq_save()
deactivate_slab
__cmpxchg_double_slab
slab_unlock
__bit_spin_unlock
preempt_enable
[ Page Fault ]
With this trace, it manifests as a "BUG: sleeping function called from invalid context at arch/x86/mm/fault.c" on a might_sleep() in the page fault handler (which is an issue on it's own), but I suspect it's also the cause of the trace above - preemption enabled and a race that removed the page.
Could someone confirm please?
Thanks,
Sasha
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 12 lines · Sasha Levin
I have a lead on this. Consider the following:
kmem_cache_alloc
__slab_alloc
local_irq_save()
deactivate_slab
__cmpxchg_double_slab
slab_unlock
__bit_spin_unlock
preempt_enable
[ Page Fault ]
Quoted 7 lines
With this trace, it manifests as a "BUG: sleeping function called from invalid context at
arch/x86/mm/fault.c" on amight_sleep()in the page fault handler (which is an issue on it's own), but I suspect it's also the cause of the trace
above - preemption enabled and a race that removed the page.Could someone confirm please?
The preempt count is incremented earlier in bit_spin_lock so the preempt_enable() should not do anything.
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 67 lines · Sasha Levin
Quoted 45 lines · Sasha Levin
Hi all,
While fuzzing with trinity inside a KVM tools guest running latest -next kernel I've stumbled on the following spew:
[ 241.916559] BUG: unable to handle kernel paging request at ffff880029aa5e58 [ 241.917961] IP: [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.919439] PGD 88f9067 PUD 88fa067 PMD 102fd35067 PTE 8000000029aa5060 [ 241.920339] Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC [ 241.920339] Dumping ftrace buffer: [ 241.920339] (ftrace buffer empty) [ 241.920339] Modules linked in: [ 241.920339] CPU: 17 PID: 9910 Comm: trinity-c183 Tainted: G W 3.14.0-rc6-next-20140311-sasha-00009-g6c028cd-dirty #146 [ 241.920339] task: ffff88090eb68000 ti: ffff88090eb70000 task.ti: ffff88090eb70000 [ 241.920339] RIP: 0010:[<ffffffff812c5fa3>] [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.920339] RSP: 0018:ffff88090eb71c18 EFLAGS: 00010082 [ 241.920339] RAX: 0000000000000418 RBX: ffff880229ae2010 RCX: 0000000180170017 [ 241.920339] RDX: 0000000000000000 RSI: ffffffff812c5f52 RDI: ffffffff812c5e29 [ 241.920339] RBP: ffff88090eb71d28 R08: ffff880229ae2010 R09: 0000000000000080 [ 241.920339] R10: ffff880229ae2ed0 R11: 0000000000000000 R12: ffffea0008a6b800 [ 241.920339] R13: ffff88012b4da580 R14: ffff880029aa5a40 R15: ffff880229ae2010 [ 241.920339] FS: 00007fb615415700(0000) GS:ffff88022ba00000(0000) knlGS:0000000000000000 [ 241.920339] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [ 241.920339] CR2: ffff880029aa5e58 CR3: 000000090eb4a000 CR4: 00000000000006a0 [ 241.920339] DR0: 0000000000005bf2 DR1: 0000000000000000 DR2: 0000000000000000 [ 241.920339] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000070602 [ 241.920339] Stack: [ 241.920339] ffffffff856e37ab ffffffff84486272 0000000000000000 000000002b405600 [ 241.920339] ffff88090eb71c58 ffff88090eb70000 0000000000000011 ffff88022ba03fc0 [ 241.920339] ffff88090eb71cb8 000000000000000f ffff88022b405600 ffff880029aa5a40 [ 241.920339] Call Trace: [ 241.920339] [<ffffffff84486272>] ? preempt_count_sub+0xe2/0x120 [ 241.920339] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.954886] [<ffffffff812c36eb>] ? set_track+0xab/0x100 [ 241.954886] [<ffffffff812c731f>] __slab_alloc+0x42f/0x4d0 [ 241.954886] [<ffffffff81073e6d>] ? sched_clock+0x1d/0x30 [ 241.954886] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff812c870f>] kmem_cache_alloc+0x12f/0x2e0 [ 241.961624] [<ffffffff8130f151>] ? alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff8130f151>] alloc_inode+0x41/0xa0 [ 241.961624] [<ffffffff8130f1cb>] new_inode_pseudo+0x1b/0x70 [ 241.961624] [<ffffffff812f985c>] get_pipe_inode+0x1c/0xf0 [ 241.961624] [<ffffffff812f995c>] create_pipe_files+0x2c/0x170Quoted 8 lines
[ 241.961624] [<ffffffff812f9ae1>] __do_pipe_flags+0x41/0xf0 [ 241.961624] [<ffffffff812f9bbb>] SyS_pipe2+0x2b/0xb0 [ 241.961624] [<ffffffff8448b3b1>] ? tracesys+0x7e/0xe2 [ 241.961624] [<ffffffff8448b410>] tracesys+0xdd/0xe2 [ 241.972975] Code: 4d 85 f6 75 8b eb 45 90 4d 85 f6 75 13 49 8b 5c 24 10 45 31 ff 0f 1f 00 eb 32 66 0f 1f 44 00 00 4c 89 b5 48 ff ff ff 49 63 45 20 <49> 8b 0c 06 48 85 c9 74 10 4d 89 f7 49 8b 54 24 10 49 89 ce e9 [ 241.972975] RIP [<ffffffff812c5fa3>] deactivate_slab+0x103/0x560 [ 241.972975] RSP <ffff88090eb71c18> [ 241.972975] CR2: ffff880029aa5e58I have a lead on this. Consider the following:
kmem_cache_alloc
__slab_alloc
local_irq_save()
deactivate_slab
__cmpxchg_double_slab
slab_unlock
__bit_spin_unlock
preempt_enable
[ Page Fault ]
Quoted 6 lines
With this trace, it manifests as a "BUG: sleeping function called from invalid context at
arch/x86/mm/fault.c" on amight_sleep()in the page fault handler (which is an issue on it's own), but I suspect it's also the cause of the trace above - preemption enabled and a race that removed the page.Could someone confirm please?
You are right. The function even does VM_BUG_ON(!irqs_disabled())... Unfortunatelly we do not seem to have an _irq alternative of the bit spinlock.
Not sure what to do about it. Christoph?
Btw. it seems to go way back to 3.1 (1d07171c5e58e).
Signature · 8 lines
Michal Hocko SUSE Labs -- To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM, see: http://www.linux-mm.org/ . Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 6 lines · Michal Hocko
You are right. The function even does VM_BUG_ON(!irqs_disabled())... Unfortunatelly we do not seem to have an
_irqalternative of the bit spinlock.
Not sure what to do about it. Christoph?Btw. it seems to go way back to 3.1 (
1d07171c5e58e).
Well there is a preempt_enable() (bit_spin_lock) and a preempt_disable() bit_spin_unlock() within a piece of code where irqs are disabled.
Is that a problem? Has been there for a long time.
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 7 lines · Christoph Lameter
Quoted 5 lines · Michal Hocko
You are right. The function even does VM_BUG_ON(!irqs_disabled())... Unfortunatelly we do not seem to have an
_irqalternative of the bit spinlock.
Not sure what to do about it. Christoph?
Quoted 6 lines
Quoted 1 line
Btw. it seems to go way back to 3.1 (
1d07171c5e58e).Well there is a
preempt_enable()(bit_spin_lock) and apreempt_disable()bit_spin_unlock()within a piece of code where irqs are disabled.Is that a problem? Has been there for a long time.
So here's the full trace. There's obviously something wrong here since we pagefault inside the section that was supposed to be running with irqs disabled and I don't see another cause besides this.
The unreliable entries in the stack trace also somewhat suggest that the fault is with the code I've pointed out.
[ 584.145271] BUG: sleeping function called from invalid context at arch/x86/mm/fault.c:1167
[ 584.148787] in_atomic(): 0, irqs_disabled(): 1, pid: 10089, name: trinity-c42
[ 584.150413] 1 lock held by trinity-c42/10089:
[ 584.151834] #0: (&mm->mmap_sem){++++++}, at: [<ffffffff8450aec3>] __do_page_fault+0x2e3/0x630
[ 584.151834] irq event stamp: 33318
[ 584.151834] hardirqs last enabled at (33317): [<ffffffff81282f15>] context_tracking_user_exit+0x1b5/0x260
[ 584.151834] hardirqs last disabled at (33318): [<ffffffff844b10d6>] __slab_alloc+0x41/0x637
[ 584.151834] softirqs last enabled at (33070): [<ffffffff81161a3e>] __do_softirq+0x3fe/0x560
[ 584.151834] softirqs last disabled at (33065): [<ffffffff81161f7c>] irq_exit+0x6c/0x170
[ 584.151834] CPU: 42 PID: 10089 Comm: trinity-c42 Tainted: G W 3.14.0-rc7-next-20140324-sasha-00015-g2fee858-dirty #271
[ 584.151834] ffff8800bc043000 ffff8800bc06f9c8 ffffffff844baf42 0000000000000001
[ 584.151834] 0000000000000000 ffff8800bc06f9f8 ffffffff81197ee1 ffffffff8450aec3
[ 584.151834] 0000000000000028 ffff8800bc06fb68 0000000000000a94 ffff8800bc06fb08
[ 584.151834] Call Trace:
[ 584.151834] [<ffffffff844baf42>] dump_stack+0x4f/0x7c
[ 584.151834] [<ffffffff81197ee1>] __might_sleep+0x221/0x240
[ 584.151834] [<ffffffff8450aec3>] ? __do_page_fault+0x2e3/0x630
[ 584.151834] [<ffffffff8450af0b>] __do_page_fault+0x32b/0x630
[ 584.151834] [<ffffffff8107aab5>] ? sched_clock+0x15/0x20
[ 584.151834] [<ffffffff811a2295>] ? sched_clock_local+0x25/0xa0
[ 584.151834] [<ffffffff811a2578>] ? sched_clock_cpu+0xa8/0xf0
[ 584.151834] [<ffffffff81282f07>] ? context_tracking_user_exit+0x1a7/0x260
[ 584.151834] [<ffffffff81b37063>] ? __this_cpu_preempt_check+0x13/0x20
[ 584.151834] [<ffffffff811c0664>] ? trace_hardirqs_off_caller+0x174/0x1a0
[ 584.151834] [<ffffffff8450b25e>] do_page_fault+0x4e/0xa0
[ 584.151834] [<ffffffff8450a775>] do_async_page_fault+0x35/0x100
[ 584.151834] [<ffffffff845073d8>] async_page_fault+0x28/0x30
[ 584.151834] [<ffffffff812e60e8>] ? deactivate_slab+0xc8/0x620
[ 584.151834] [<ffffffff812e5f70>] ? __cmpxchg_double_slab.isra.26+0x120/0x1d0
[ 584.151834] [<ffffffff812e611b>] ? deactivate_slab+0xfb/0x620
[ 584.151834] [<ffffffff812e60e8>] ? deactivate_slab+0xc8/0x620
[ 584.151834] [<ffffffff84506345>] ? _raw_spin_unlock+0x35/0x60
[ 584.151834] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0
[ 584.151834] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0
[ 584.151834] [<ffffffff81b37087>] ? debug_smp_processor_id+0x17/0x20
[ 584.151834] [<ffffffff812e3676>] ? set_track+0x96/0x180
[ 584.151834] [<ffffffff812e35ce>] ? init_object+0x6e/0x80
[ 584.151834] [<ffffffff844b15f9>] __slab_alloc+0x564/0x637
[ 584.151834] [<ffffffff810b9b24>] ? kvm_clock_read+0x24/0x40
[ 584.151834] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0
[ 584.151834] [<ffffffff8119b041>] ? get_parent_ip+0x11/0x50
[ 584.151834] [<ffffffff812e7ddc>] kmem_cache_alloc+0x12c/0x3b0
[ 584.151834] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0
[ 584.151834] [<ffffffff811a3288>] ? vtime_account_user+0x98/0xb0
[ 584.151834] [<ffffffff8132c5e1>] alloc_inode+0x41/0xa0
[ 584.151834] [<ffffffff8132e4fa>] new_inode_pseudo+0x1a/0x70
[ 584.151834] [<ffffffff8131837a>] create_pipe_files+0x2a/0x220
[ 584.151834] [<ffffffff811c28f4>] ? trace_hardirqs_on_caller+0x1f4/0x290
[ 584.151834] [<ffffffff813185b5>] __do_pipe_flags+0x45/0xe0
[ 584.151834] [<ffffffff81318770>] SyS_pipe+0x20/0xb0
[ 584.151834] [<ffffffff84510975>] ? tracesys+0x7e/0xe6
[ 584.151834] [<ffffffff845109d8>] tracesys+0xe1/0xe6It was also followed by a straightforward NULL ptr deref in deactivate_slab():
[ 584.151834] BUG: unable to handle kernel NULL pointer dereference at 0000000000000a94 [ 584.151834] IP: [<ffffffff812e611b>] deactivate_slab+0xfb/0x620 [ 584.223982] PGD bc06c067 PUD bc06d067 PMD 0 [ 584.223982] Oops: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC [ 584.223982] Dumping ftrace buffer: [ 584.223982] (ftrace buffer empty) [ 584.223982] Modules linked in: [ 584.223982] CPU: 42 PID: 10089 Comm: trinity-c42 Tainted: G W 3.14.0-rc7-next-20140324-sasha-00015-g2fee858-dirty #271 [ 584.223982] task: ffff8800bc043000 ti: ffff8800bc06e000 task.ti: ffff8800bc06e000 [ 584.223982] RIP: 0010:[<ffffffff812e611b>] [<ffffffff812e611b>] deactivate_slab+0xfb/0x620 [ 584.223982] RSP: 0018:ffff8800bc06fc18 EFLAGS: 00010006 [ 584.223982] RAX: 0000000000000410 RBX: ffffea002bb04200 RCX: 0000000180180016 [ 584.223982] RDX: 0000000000000001 RSI: ffffffff812e60e8 RDI: ffffffff812e5f70 [ 584.223982] RBP: ffff8800bc06fd08 R08: ffffea0023ac6000 R09: 0000000000000080 [ 584.223982] R10: ffff880aec108408 R11: 0000000000000001 R12: ffffea0023ac6000 [ 584.223982] R13: ffff880a6c520000 R14: 0000000000000684 R15: 0000000000000684 [ 584.223982] FS: 00007feaa0845700(0000) GS:ffff880aecc00000(0000) knlGS:0000000000000000 [ 584.223982] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b [ 584.223982] CR2: 0000000000000a94 CR3: 00000000bc06b000 CR4: 00000000000006a0 [ 584.223982] DR0: 0000000000698000 DR1: 0000000000698000 DR2: 0000000000000000 [ 584.223982] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000d9060a [ 584.223982] Stack: [ 584.223982] ffff8800bc043000 0000002a8450b958 ffff8800bc06e000 ffff8800bc06fc78 [ 584.223982] 00000000bc06fc58 ffffffff84506345 ffff88000000000f ffff880aec805600 [ 584.223982] ffffffff8132c5e1 0000000000000082 ffff880aec108418 0000000180180015 [ 584.223982] Call Trace: [ 584.223982] [<ffffffff84506345>] ? _raw_spin_unlock+0x35/0x60 [ 584.223982] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0 [ 584.223982] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0 [ 584.223982] [<ffffffff81b37087>] ? debug_smp_processor_id+0x17/0x20 [ 584.223982] [<ffffffff812e3676>] ? set_track+0x96/0x180 [ 584.223982] [<ffffffff812e35ce>] ? init_object+0x6e/0x80 [ 584.223982] [<ffffffff844b15f9>] __slab_alloc+0x564/0x637 [ 584.223982] [<ffffffff810b9b24>] ? kvm_clock_read+0x24/0x40 [ 584.223982] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0 [ 584.223982] [<ffffffff8119b041>] ? get_parent_ip+0x11/0x50 [ 584.223982] [<ffffffff812e7ddc>] kmem_cache_alloc+0x12c/0x3b0 [ 584.223982] [<ffffffff8132c5e1>] ? alloc_inode+0x41/0xa0 [ 584.223982] [<ffffffff811a3288>] ? vtime_account_user+0x98/0xb0 [ 584.223982] [<ffffffff8132c5e1>] alloc_inode+0x41/0xa0 [ 584.223982] [<ffffffff8132e4fa>] new_inode_pseudo+0x1a/0x70 [ 584.223982] [<ffffffff8131837a>] create_pipe_files+0x2a/0x220 [ 584.223982] [<ffffffff811c28f4>] ? trace_hardirqs_on_caller+0x1f4/0x290 [ 584.223982] [<ffffffff813185b5>] __do_pipe_flags+0x45/0xe0 [ 584.223982] [<ffffffff81318770>] SyS_pipe+0x20/0xb0 [ 584.223982] [<ffffffff84510975>] ? tracesys+0x7e/0xe6 [ 584.223982] [<ffffffff845109d8>] tracesys+0xe1/0xe6 [ 584.223982] Code: 49 63 45 20 eb b2 66 2e 0f 1f 84 00 00 00 00 00 4d 85 f6 75 0b 4c 8b 63 10 45 31 ff eb 22 66 90 49 63 45 20 4d 89 f7 4c 8b 63 10 <49> 8b 14 06 48 85 d2 74 0c 49 89 d6 e9 7c ff ff ff 0f 1f 40 00 [ 584.223982] RIP [<ffffffff812e611b>] deactivate_slab+0xfb/0x620 [ 584.223982] RSP <ffff8800bc06fc18> [ 584.223982] CR2: 0000000000000a94
Thanks,
Sasha
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 7 lines · Sasha Levin
So here's the full trace. There's obviously something wrong here since we pagefault inside the section that was supposed to be running with irqs disabled
and I don't see another cause besides this.The unreliable entries in the stack trace also somewhat suggest that the fault is with the code I've pointed out.
Looks like there was some invalid data fed to the function and the page fault with interrupts disabled is the result of following and invalid pointer.
Is there more context information available? What are the options set for the cache that the operation was performed on?
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 10 lines · Christoph Lameter
Quoted 7 lines · Sasha Levin
So here's the full trace. There's obviously something wrong here since we pagefault inside the section that was supposed to be running with irqs disabled
and I don't see another cause besides this.The unreliable entries in the stack trace also somewhat suggest that the fault is with the code I've pointed out.
Quoted 6 lines
Looks like there was some invalid data fed to the function and the page fault with interrupts disabled is the result of following and invalid pointer.
Is there more context information available? What are the options set for the cache that the operation was performed on?
It seems like it's a regular allocation from the inode_cachep kmem_cache:
inode = kmem_cache_alloc(inode_cachep, GFP_KERNEL);
I'm not sure if there's anything special about this cache, codewise it's created as follows:
inode_cachep = kmem_cache_create("inode_cache",
sizeof(struct inode),
0,
(SLAB_RECLAIM_ACCOUNT|SLAB_PANIC|
SLAB_MEM_SPREAD),
init_once);I'd be happy to dig up any other info required, I'm just not too sure what you mean by options for the cache?
Thanks,
Sasha
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 12 lines · Sasha Levin
I'm not sure if there's anything special about this cache, codewise it's created as follows:
inode_cachep = kmem_cache_create("inode_cache", sizeof(struct inode), 0, (SLAB_RECLAIM_ACCOUNT|SLAB_PANIC| SLAB_MEM_SPREAD), init_once);
Quoted 2 lines
I'd be happy to dig up any other info required, I'm just not too sure what you mean by options for the cache?
Slab parameters can be change in /sys/kernel/slab/inode. Any debug parameters active? More information about what was actually going on when the gpf occured?
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 14 lines · Christoph Lameter
Quoted 12 lines · Sasha Levin
I'm not sure if there's anything special about this cache, codewise it's created as follows:
inode_cachep = kmem_cache_create("inode_cache", sizeof(struct inode), 0, (SLAB_RECLAIM_ACCOUNT|SLAB_PANIC| SLAB_MEM_SPREAD), init_once);
Quoted 6 lines
Quoted 2 lines
I'd be happy to dig up any other info required, I'm just not too sure what you mean by options for the cache?
Slab parameters can be change in
/sys/kernel/slab/inode. Any debug parameters active? More information about what was actually going on when the gpf occured?
Unfortunately I've been unable to reproduce the issue to get more debug info out of it. However, I've hit something that seems to be somewhat similar to that:
[ 1035.176692] BUG: unable to handle kernel paging request at ffff8801377e4000 [ 1035.177893] IP: memset (arch/x86/lib/memset_64.S:105) [ 1035.178651] PGD 3d91c067 PUD 102f7ff067 PMD 102f643067 PTE 80000001377e4060 [ 1035.179740] Oops: 0002 [#1] PREEMPT SMP DEBUG_PAGEALLOC [ 1035.180063] Dumping ftrace buffer: [ 1035.180063] (ftrace buffer empty) [ 1035.180063] Modules linked in: [ 1035.180063] CPU: 2 PID: 27857 Comm: modprobe Not tainted 3.14.0-next-20140403-sasha-00019-g7474aa9-dirty #376 [ 1035.180063] task: ffff8800a1918000 ti: ffff8800a4650000 task.ti: ffff8800a4650000 [ 1035.180063] RIP: memset (arch/x86/lib/memset_64.S:105) [ 1035.180063] RSP: 0018:ffff8800a4651b60 EFLAGS: 00010046 [ 1035.180063] RAX: bbbbbbbbbbbbbbbb RBX: ffff88007d852ec0 RCX: 0000000000000000 [ 1035.180063] RDX: 0000000000000008 RSI: 00000000000000bb RDI: ffff8801377e4000 [ 1035.180063] RBP: ffff8800a4651b88 R08: 0000000000000001 R09: 0000000000000000 [ 1035.180063] R10: ffff8801377e4000 R11: ffffffffffffffce R12: ffff8801377e3000 [ 1035.180063] R13: 00000000000000bb R14: ffff8801377e3000 R15: ffffffffffffffff [ 1035.180063] FS: 00007f2e098d6700(0000) GS:ffff8801abc00000(0000) knlGS:0000000000000000 [ 1035.180063] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1035.180063] CR2: ffff8801377e4000 CR3: 000000061feec000 CR4: 00000000000006a0 [ 1035.193166] DR0: 0000000000696000 DR1: 0000000000000000 DR2: 0000000000000000 [ 1035.193166] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000600 [ 1035.193166] Stack: [ 1035.193166] ffffffffb62dabee ffff8800a4651b78 ffff88007d852ec0 ffff8801377e3000 [ 1035.193166] ffffea0004ddf8c0 ffff8800a4651ba8 ffffffffb62db1c0 ffff88007d852ec0 [ 1035.193166] ffff8801377e3000 ffff8800a4651be8 ffffffffb62dd1a6 ffff8800a4651bd8 [ 1035.193166] Call Trace: [ 1035.193166] ? init_object (mm/slub.c:679) [ 1035.193166] setup_object.isra.34 (mm/slub.c:1071 mm/slub.c:1399) [ 1035.193166] new_slab (mm/slub.c:286 mm/slub.c:1439) [ 1035.193166] __slab_alloc (mm/slub.c:2203 mm/slub.c:2363) [ 1035.193166] ? kmem_cache_alloc (mm/slub.c:2469 mm/slub.c:2480 mm/slub.c:2485) [ 1035.193166] ? getname_flags (fs/namei.c:145) [ 1035.193166] ? get_parent_ip (kernel/sched/core.c:2472) [ 1035.193166] kmem_cache_alloc (mm/slub.c:2469 mm/slub.c:2480 mm/slub.c:2485) [ 1035.193166] ? getname_flags (fs/namei.c:145) [ 1035.193166] getname_flags (fs/namei.c:145) [ 1035.193166] user_path_at_empty (fs/namei.c:2121) [ 1035.193166] ? kvm_clock_read (arch/x86/include/asm/preempt.h:90 arch/x86/kernel/kvmclock.c:86) [ 1035.193166] ? sched_clock (arch/x86/include/asm/paravirt.h:192 arch/x86/kernel/tsc.c:305) [ 1035.193166] ? sched_clock_local (kernel/sched/clock.c:214) [ 1035.193166] ? vtime_account_user (kernel/sched/cputime.c:687) [ 1035.193166] ? debug_smp_processor_id (lib/smp_processor_id.c:57) [ 1035.193166] ? put_lock_stats.isra.12 (arch/x86/include/asm/preempt.h:98 kernel/locking/lockdep.c:254) [ 1035.193166] user_path_at (fs/namei.c:2137) [ 1035.193166] vfs_fstatat (fs/stat.c:107) [ 1035.193166] ? context_tracking_user_exit (arch/x86/include/asm/paravirt.h:809 (discriminator 2) kernel/context_tracking.c:182 (discriminator 2)) [ 1035.193166] vfs_stat (fs/stat.c:124) [ 1035.193166] SYSC_newstat (fs/stat.c:272) [ 1035.193166] ? trace_hardirqs_on (kernel/locking/lockdep.c:2607) [ 1035.193166] ? syscall_trace_enter (include/linux/context_tracking.h:27 arch/x86/kernel/ptrace.c:1461) [ 1035.193166] ? tracesys (arch/x86/kernel/entry_64.S:738) [ 1035.193166] SyS_newstat (fs/stat.c:267) [ 1035.193166] tracesys (arch/x86/kernel/entry_64.S:749) [ 1035.193166] Code: 89 47 28 48 89 47 30 48 89 47 38 48 8d 7f 40 75 d8 0f 1f 84 00 00 00 00 00 89 d1 83 e1 38 74 14 c1 e9 03 66 0f 1f 44 00 00 ff c9 <48> 89 07 48 8d 7f 08 75 f5 83 e2 07 74 0a ff ca 88 07 48 8d 7f [ 1035.193166] RIP memset (arch/x86/lib/memset_64.S:105) [ 1035.193166] RSP <ffff8800a4651b60> [ 1035.193166] CR2: ffff8801377e4000
Thanks,
Sasha
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 3 lines · Sasha Levin
Unfortunately I've been unable to reproduce the issue to get more debug info out of it. However, I've hit something that seems to be somewhat similar to that:
Could you jsut run with "slub_debug" on the kernel command line to get us more diagnostics? Could be memory corruption.
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 8 lines · Christoph Lameter
Quoted 3 lines · Sasha Levin
Unfortunately I've been unable to reproduce the issue to get more debug info out of it. However, I've hit something that seems to be somewhat similar to that:
Could you jsut run with "
slub_debug" on the kernel command line to get us more diagnostics? Could be memory corruption.
I was running it with "slub_debug=FZPU" when I reported both errors, there was no other information beyond the traces in the log.
Thanks,
Sasha
--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 6 lines · Sasha Levin
[ 1035.193166] Call Trace: [ 1035.193166] ? init_object (mm/slub.c:679) [ 1035.193166] setup_object.isra.34 (mm/slub.c:1071 mm/slub.c:1399) [ 1035.193166] new_slab (mm/slub.c:286 mm/slub.c:1439) [ 1035.193166] __slab_alloc (mm/slub.c:2203 mm/slub.c:2363) [ 1035.193166] ? kmem_cache_alloc (mm/slub.c:2469 mm/slub.c:2480 mm/slub.c:2485)
Ok so the story here is that slub decided it needed a new slab and requested memory from the page allocator.
setup_object() tries to write to the page which fails.
Could the page allocator have delivered a reference to a page struct that creates an invalid address?
The code that fails is:
page = allocate_slab(s,
flags & (GFP_RECLAIM_MASK | GFP_CONSTRAINT_MASK), node);
if (!page)
goto out;--- So we got a page from teh page allocator
order = compound_order(page);
inc_slabs_node(s, page_to_nid(page), page->objects);
memcg_bind_pages(s, order);
page->slab_cache = s;
__SetPageSlab(page);-- Writing to the page struct works.
if (page->pfmemalloc)
SetPageSlabPfmemalloc(page);
start = page_address(page);
if (unlikely(s->flags & SLAB_POISON))
memset(start, POISON_INUSE, PAGE_SIZE << order);--- This should have triggered since we write to the page but maybe this
slab has a ctor set and therefore no poisining is possible.
last = start;
for_each_object(p, s, start, page->objects) {
setup_object(s, page, last);*** This is where the write access to the page fails.
set_freepointer(s, last, p);
last = p;
}
setup_object(s, page, last);--
To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 7 lines · Christoph Lameter
Quoted 5 lines · Michal Hocko
You are right. The function even does VM_BUG_ON(!irqs_disabled())... Unfortunatelly we do not seem to have an
_irqalternative of the bit spinlock.
Not sure what to do about it. Christoph?
Quoted 6 lines
Quoted 1 line
Btw. it seems to go way back to 3.1 (
1d07171c5e58e).Well there is a
preempt_enable()(bit_spin_lock) and apreempt_disable()bit_spin_unlock()within a piece of code where irqs are disabled.Is that a problem? Has been there for a long time.
It is because preempt_enable calls __preempt_schedule when the preempt count drops down to 0. You would need to call preempt_disable before you disable interrupts or use an irq safe bit spin unlock which doesn't enabled preemption unconditionally.
Signature · 8 lines
Michal Hocko SUSE Labs -- To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM, see: http://www.linux-mm.org/ . Don't email: <a href=mailto:"[email protected]"> [email protected] </a>
Quoted 13 lines · Michal Hocko
Quoted 12 lines · Christoph Lameter
Quoted 6 lines · Michal Hocko
You are right. The function even does VM_BUG_ON(!irqs_disabled())... Unfortunatelly we do not seem to have an
_irqalternative of the bit spinlock.
Not sure what to do about it. Christoph?Btw. it seems to go way back to 3.1 (
1d07171c5e58e).Well there is a
preempt_enable()(bit_spin_lock) and apreempt_disable()bit_spin_unlock()within a piece of code where irqs are disabled.
Quoted 6 lines
Quoted 1 line
Is that a problem? Has been there for a long time.
It is because
preempt_enablecalls__preempt_schedulewhen the preempt count drops down to 0. You would need to callpreempt_disablebefore you disable interrupts or use an irq safe bit spin unlock which doesn't enabled preemption unconditionally.
Hmm, now that I am looking into the code more closely it seems that preempt_schedule bails out when interrupts are disabled.
Signature · 8 lines
Michal Hocko SUSE Labs -- To unsubscribe, send a message with 'unsubscribe linux-mm' in the body to [email protected]. For more info on Linux MM, see: http://www.linux-mm.org/ . Don't email: <a href=mailto:"[email protected]"> [email protected] </a>