kernel/rcu/tree.c:1031 rcu_irq_enter() invoked with irqs enabled!!!!
Subsystems (3)
I hit this RCU warning while running mkfs.ext4 on a PMEM namespace with an unmodified v4.11-rc8 (passed through kasan_symbolize.py):
===============================
[ ERR: suspicious RCU usage. ]
4.11.0-rc8 #1 Not tainted
-------------------------------kernel/rcu/tree.c:1031 rcu_irq_enter() invoked with irqs enabled!!!!
other info that might help us debug this:
rcu_scheduler_active = 2, debug_locks = 0
no locks held by mkfs.ext4/18493.
stack backtrace: CPU: 10 PID: 18493 Comm: mkfs.ext4 Not tainted 4.11.0-rc8 #1 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-1.fc25 04/01/2014 Call Trace: [< inline >] __dump_stack project/linux/lib/dump_stack.c:16 [< none >] dump_stack+0x86/0xc3 project/linux/lib/dump_stack.c:52 [< none >] lockdep_rcu_suspicious+0xd7/0x110 project/linux/kernel/locking/lockdep.c:4461 [< none >] rcu_irq_enter+0x74/0x80 project/linux/kernel/rcu/tree.c:1031 [< none >] kvm_async_pf_task_wait+0x1af/0x240 project/linux/arch/x86/kernel/kvm.c:164 [< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 ?[< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 [< none >] async_page_fault+0x28/0x30 project/linux_2/arch/x86/entry/entry_64.S:1014 RIP: 0010:copy_user_enhanced_fast_string+0x5/0x10 RSP: 0018:ffffc90008777c90 EFLAGS: 00010202 RAX: 0000000000000001 RBX: 0000000000001000 RCX: 0000000000001000 RDX: 0000000000001000 RSI: 00007f42a5d88010 RDI: ffff88007e82d000 RBP: ffffc90008777ce0 R08: ffff88007e82d000 R09: 0000000000000000 R10: 0000000000000000 R11: ffffea0001fa0b40 R12: 0000000000001000 R13: ffffc90008777e50 R14: ffff88007e82e000 R15: 0000000000001000 ?[< inline >] copy_user_generic project/linux/./arch/x86/include/asm/uaccess_64.h:37 ?[< inline >] __copy_from_user_nocheck project/linux/./arch/x86/include/asm/uaccess_64.h:59 ?[< inline >] __copy_from_user_inatomic project/linux/./arch/x86/include/asm/uaccess_64.h:251 ?[< none >] iov_iter_copy_from_user_atomic+0xbb/0x350 project/linux/lib/iov_iter.c:721 [< none >] generic_perform_write+0xf2/0x1d0 project/linux/mm/filemap.c:2843 [< none >] __generic_file_write_iter+0x185/0x1c0 project/linux/mm/filemap.c:2960 [< none >] blkdev_write_iter+0x96/0x110 project/linux/fs/block_dev.c:2008 [< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 [< inline >] new_sync_write project/linux/fs/read_write.c:497 [< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 ?[< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 ?[< inline >] new_sync_write project/linux/fs/read_write.c:497 ?[< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 [< none >] vfs_write+0xcb/0x1f0 project/linux/fs/read_write.c:558 [< inline >] SYSC_pwrite64 project/linux/fs/read_write.c:647 [< none >] SyS_pwrite64+0x98/0xc0 project/linux/fs/read_write.c:634 [< none >] entry_SYSCALL_64_fastpath+0x1f/0xc2 project/linux_2/arch/x86/entry/entry_64.S:204 RIP: 0033:0x7f42acd4d213 RSP: 002b:00007ffc846e4e38 EFLAGS: 00000246 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f42acd4d213 RDX: 00000000001e0000 RSI: 00007f42a5c9f010 RDI: 0000000000000003 RBP: 0000559bd6c46380 R08: 00007f42a5c9f010 R09: 0000000000000200 R10: 0000000680820000 R11: 0000000000000246 R12: 00007ffc846e4f9c R13: 0000000000000425 R14: 0000000000000200 R15: 0000559bd6c46380
Quoted 8 lines · Ross Zwisler
I hit this RCU warning while running mkfs.ext4 on a PMEM namespace with an unmodified v4.11-rc8 (passed through
kasan_symbolize.py):===============================
[ ERR: suspicious RCU usage. ]
4.11.0-rc8 #1 Not tainted
-------------------------------kernel/rcu/tree.c:1031rcu_irq_enter()invoked with irqs enabled!!!!
Just in case there is any doubt, invoking rcu_irq_enter() with irqs enabled voids your kernel's RCU warranty. ;-)
So please don't do that.
Thanx, Paul
Quoted 50 lines
other info that might help us debug this:
rcu_scheduler_active= 2,debug_locks= 0
no locks held by mkfs.ext4/18493.stack backtrace: CPU: 10 PID: 18493 Comm: mkfs.ext4 Not tainted 4.11.0-rc8 #1 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-1.fc25 04/01/2014 Call Trace: [< inline >] __dump_stack project/linux/lib/dump_stack.c:16 [< none >] dump_stack+0x86/0xc3 project/linux/lib/dump_stack.c:52 [< none >] lockdep_rcu_suspicious+0xd7/0x110 project/linux/kernel/locking/lockdep.c:4461 [< none >] rcu_irq_enter+0x74/0x80 project/linux/kernel/rcu/tree.c:1031 [< none >] kvm_async_pf_task_wait+0x1af/0x240 project/linux/arch/x86/kernel/kvm.c:164 [< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 ?[< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 [< none >] async_page_fault+0x28/0x30 project/linux_2/arch/x86/entry/entry_64.S:1014 RIP: 0010:copy_user_enhanced_fast_string+0x5/0x10 RSP: 0018:ffffc90008777c90 EFLAGS: 00010202 RAX: 0000000000000001 RBX: 0000000000001000 RCX: 0000000000001000 RDX: 0000000000001000 RSI: 00007f42a5d88010 RDI: ffff88007e82d000 RBP: ffffc90008777ce0 R08: ffff88007e82d000 R09: 0000000000000000 R10: 0000000000000000 R11: ffffea0001fa0b40 R12: 0000000000001000 R13: ffffc90008777e50 R14: ffff88007e82e000 R15: 0000000000001000 ?[< inline >] copy_user_generic project/linux/./arch/x86/include/asm/uaccess_64.h:37 ?[< inline >] __copy_from_user_nocheck project/linux/./arch/x86/include/asm/uaccess_64.h:59 ?[< inline >] __copy_from_user_inatomic project/linux/./arch/x86/include/asm/uaccess_64.h:251 ?[< none >] iov_iter_copy_from_user_atomic+0xbb/0x350 project/linux/lib/iov_iter.c:721 [< none >] generic_perform_write+0xf2/0x1d0 project/linux/mm/filemap.c:2843 [< none >] __generic_file_write_iter+0x185/0x1c0 project/linux/mm/filemap.c:2960 [< none >] blkdev_write_iter+0x96/0x110 project/linux/fs/block_dev.c:2008 [< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 [< inline >] new_sync_write project/linux/fs/read_write.c:497 [< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 ?[< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 ?[< inline >] new_sync_write project/linux/fs/read_write.c:497 ?[< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 [< none >] vfs_write+0xcb/0x1f0 project/linux/fs/read_write.c:558 [< inline >] SYSC_pwrite64 project/linux/fs/read_write.c:647 [< none >] SyS_pwrite64+0x98/0xc0 project/linux/fs/read_write.c:634 [< none >] entry_SYSCALL_64_fastpath+0x1f/0xc2 project/linux_2/arch/x86/entry/entry_64.S:204 RIP: 0033:0x7f42acd4d213 RSP: 002b:00007ffc846e4e38 EFLAGS: 00000246 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f42acd4d213 RDX: 00000000001e0000 RSI: 00007f42a5c9f010 RDI: 0000000000000003 RBP: 0000559bd6c46380 R08: 00007f42a5c9f010 R09: 0000000000000200 R10: 0000000680820000 R11: 0000000000000246 R12: 00007ffc846e4f9c R13: 0000000000000425 R14: 0000000000000200 R15: 0000559bd6c46380
Quoted 10 lines · Paul E. McKenney
Quoted 8 lines · Ross Zwisler
I hit this RCU warning while running mkfs.ext4 on a PMEM namespace with an unmodified v4.11-rc8 (passed through
kasan_symbolize.py):===============================
[ ERR: suspicious RCU usage. ]
4.11.0-rc8 #1 Not tainted
-------------------------------kernel/rcu/tree.c:1031rcu_irq_enter()invoked with irqs enabled!!!!
Quoted 4 lines
Just in case there is any doubt, invoking
rcu_irq_enter()with irqs enabled voids your kernel's RCU warranty. ;-)So please don't do that.
OK, but looking at the stack trace, this has nothing to do with ext4. The problem seems to be in KVM - relevant CCs added.
Honza
Quoted 52 lines
Quoted 51 lines
other info that might help us debug this:
rcu_scheduler_active= 2,debug_locks= 0
no locks held by mkfs.ext4/18493.stack backtrace: CPU: 10 PID: 18493 Comm: mkfs.ext4 Not tainted 4.11.0-rc8 #1 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-1.fc25 04/01/2014 Call Trace: [< inline >] __dump_stack project/linux/lib/dump_stack.c:16 [< none >] dump_stack+0x86/0xc3 project/linux/lib/dump_stack.c:52 [< none >] lockdep_rcu_suspicious+0xd7/0x110 project/linux/kernel/locking/lockdep.c:4461 [< none >] rcu_irq_enter+0x74/0x80 project/linux/kernel/rcu/tree.c:1031 [< none >] kvm_async_pf_task_wait+0x1af/0x240 project/linux/arch/x86/kernel/kvm.c:164 [< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 ?[< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 [< none >] async_page_fault+0x28/0x30 project/linux_2/arch/x86/entry/entry_64.S:1014 RIP: 0010:copy_user_enhanced_fast_string+0x5/0x10 RSP: 0018:ffffc90008777c90 EFLAGS: 00010202 RAX: 0000000000000001 RBX: 0000000000001000 RCX: 0000000000001000 RDX: 0000000000001000 RSI: 00007f42a5d88010 RDI: ffff88007e82d000 RBP: ffffc90008777ce0 R08: ffff88007e82d000 R09: 0000000000000000 R10: 0000000000000000 R11: ffffea0001fa0b40 R12: 0000000000001000 R13: ffffc90008777e50 R14: ffff88007e82e000 R15: 0000000000001000 ?[< inline >] copy_user_generic project/linux/./arch/x86/include/asm/uaccess_64.h:37 ?[< inline >] __copy_from_user_nocheck project/linux/./arch/x86/include/asm/uaccess_64.h:59 ?[< inline >] __copy_from_user_inatomic project/linux/./arch/x86/include/asm/uaccess_64.h:251 ?[< none >] iov_iter_copy_from_user_atomic+0xbb/0x350 project/linux/lib/iov_iter.c:721 [< none >] generic_perform_write+0xf2/0x1d0 project/linux/mm/filemap.c:2843 [< none >] __generic_file_write_iter+0x185/0x1c0 project/linux/mm/filemap.c:2960 [< none >] blkdev_write_iter+0x96/0x110 project/linux/fs/block_dev.c:2008 [< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 [< inline >] new_sync_write project/linux/fs/read_write.c:497 [< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 ?[< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 ?[< inline >] new_sync_write project/linux/fs/read_write.c:497 ?[< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 [< none >] vfs_write+0xcb/0x1f0 project/linux/fs/read_write.c:558 [< inline >] SYSC_pwrite64 project/linux/fs/read_write.c:647 [< none >] SyS_pwrite64+0x98/0xc0 project/linux/fs/read_write.c:634 [< none >] entry_SYSCALL_64_fastpath+0x1f/0xc2 project/linux_2/arch/x86/entry/entry_64.S:204 RIP: 0033:0x7f42acd4d213 RSP: 002b:00007ffc846e4e38 EFLAGS: 00000246 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f42acd4d213 RDX: 00000000001e0000 RSI: 00007f42a5c9f010 RDI: 0000000000000003 RBP: 0000559bd6c46380 R08: 00007f42a5c9f010 R09: 0000000000000200 R10: 0000000680820000 R11: 0000000000000246 R12: 00007ffc846e4f9c R13: 0000000000000425 R14: 0000000000000200 R15: 0000559bd6c46380
Signature · 2 lines
Jan Kara <[email protected]> SUSE Labs, CR
2017-04-26 09:16+0200, Jan Kara:
Quoted 11 lines · Paul E. McKenney
Quoted 10 lines · Ross Zwisler
Quoted 8 lines
I hit this RCU warning while running mkfs.ext4 on a PMEM namespace with an unmodified v4.11-rc8 (passed through
kasan_symbolize.py):===============================
[ ERR: suspicious RCU usage. ]
4.11.0-rc8 #1 Not tainted
-------------------------------kernel/rcu/tree.c:1031rcu_irq_enter()invoked with irqs enabled!!!!
Quoted 7 lines
Quoted 4 lines
Just in case there is any doubt, invoking
rcu_irq_enter()with irqs enabled voids your kernel's RCU warranty. ;-)So please don't do that.
OK, but looking at the stack trace, this has nothing to do with ext4. The problem seems to be in KVM - relevant CCs added.
The path begins with async_page_fault interrupt gate and the hardware should clear the interrupt flag before executing it. I don't see a change that would break the assumption that interrupts are disabled ...
Paul, is it a regression since v4.10?
It might be a fault of the host KVM that interrupts are enabled -- what is the host cpu and kernel version?
Thanks.
Quoted 58 lines
Honza
Quoted 52 lines
Quoted 51 lines
other info that might help us debug this:
rcu_scheduler_active= 2,debug_locks= 0
no locks held by mkfs.ext4/18493.stack backtrace: CPU: 10 PID: 18493 Comm: mkfs.ext4 Not tainted 4.11.0-rc8 #1 Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-1.fc25 04/01/2014 Call Trace: [< inline >] __dump_stack project/linux/lib/dump_stack.c:16 [< none >] dump_stack+0x86/0xc3 project/linux/lib/dump_stack.c:52 [< none >] lockdep_rcu_suspicious+0xd7/0x110 project/linux/kernel/locking/lockdep.c:4461 [< none >] rcu_irq_enter+0x74/0x80 project/linux/kernel/rcu/tree.c:1031 [< none >] kvm_async_pf_task_wait+0x1af/0x240 project/linux/arch/x86/kernel/kvm.c:164 [< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 ?[< none >] do_async_page_fault+0x63/0x90 project/linux/arch/x86/kernel/kvm.c:269 [< none >] async_page_fault+0x28/0x30 project/linux_2/arch/x86/entry/entry_64.S:1014 RIP: 0010:copy_user_enhanced_fast_string+0x5/0x10 RSP: 0018:ffffc90008777c90 EFLAGS: 00010202 RAX: 0000000000000001 RBX: 0000000000001000 RCX: 0000000000001000 RDX: 0000000000001000 RSI: 00007f42a5d88010 RDI: ffff88007e82d000 RBP: ffffc90008777ce0 R08: ffff88007e82d000 R09: 0000000000000000 R10: 0000000000000000 R11: ffffea0001fa0b40 R12: 0000000000001000 R13: ffffc90008777e50 R14: ffff88007e82e000 R15: 0000000000001000 ?[< inline >] copy_user_generic project/linux/./arch/x86/include/asm/uaccess_64.h:37 ?[< inline >] __copy_from_user_nocheck project/linux/./arch/x86/include/asm/uaccess_64.h:59 ?[< inline >] __copy_from_user_inatomic project/linux/./arch/x86/include/asm/uaccess_64.h:251 ?[< none >] iov_iter_copy_from_user_atomic+0xbb/0x350 project/linux/lib/iov_iter.c:721 [< none >] generic_perform_write+0xf2/0x1d0 project/linux/mm/filemap.c:2843 [< none >] __generic_file_write_iter+0x185/0x1c0 project/linux/mm/filemap.c:2960 [< none >] blkdev_write_iter+0x96/0x110 project/linux/fs/block_dev.c:2008 [< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 [< inline >] new_sync_write project/linux/fs/read_write.c:497 [< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 ?[< inline >] call_write_iter project/linux/./include/linux/fs.h:1733 ?[< inline >] new_sync_write project/linux/fs/read_write.c:497 ?[< none >] __vfs_write+0xe8/0x160 project/linux/fs/read_write.c:510 [< none >] vfs_write+0xcb/0x1f0 project/linux/fs/read_write.c:558 [< inline >] SYSC_pwrite64 project/linux/fs/read_write.c:647 [< none >] SyS_pwrite64+0x98/0xc0 project/linux/fs/read_write.c:634 [< none >] entry_SYSCALL_64_fastpath+0x1f/0xc2 project/linux_2/arch/x86/entry/entry_64.S:204 RIP: 0033:0x7f42acd4d213 RSP: 002b:00007ffc846e4e38 EFLAGS: 00000246 ORIG_RAX: 0000000000000012 RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00007f42acd4d213 RDX: 00000000001e0000 RSI: 00007f42a5c9f010 RDI: 0000000000000003 RBP: 0000559bd6c46380 R08: 00007f42a5c9f010 R09: 0000000000000200 R10: 0000000680820000 R11: 0000000000000246 R12: 00007ffc846e4f9c R13: 0000000000000425 R14: 0000000000000200 R15: 0000559bd6c46380Signature · 2 lines
Jan Kara <[email protected]> SUSE Labs, CR
Paolo Bonzini
maintainerQuoted 5 lines · Radim Krčmář
Quoted 2 lines
OK, but looking at the stack trace, this has nothing to do with ext4. The problem seems to be in KVM - relevant CCs added.
The path begins with
async_page_faultinterrupt gate and the hardware should clear the interrupt flag before executing it. I don't see a change that would break the assumption that interrupts are disabled ...
native_safe_halt enables interrupts. I think this is it:
arch/x86/kernel/kvm.c +1 -1
@@ -161,8 +161,8 @@ void kvm_async_pf_task_wait(u32 token)*/ rcu_irq_exit ();native_safe_halt (); -rcu_irq_enter ();local_irq_disable (); +rcu_irq_enter (); } }if (!n.halted)
Paolo
2017-04-26 16:29+0200, Paolo Bonzini:
Quoted 14 lines · Radim Krčmář
Quoted 5 lines
Quoted 2 lines
OK, but looking at the stack trace, this has nothing to do with ext4. The problem seems to be in KVM - relevant CCs added.
The path begins with
async_page_faultinterrupt gate and the hardware should clear the interrupt flag before executing it. I don't see a change that would break the assumption that interrupts are disabled ...
native_safe_haltenables interrupts. I think this is it:arch/x86/kernel/kvm.c +0
-0
arch/x86/kernel/kvm.c void kvm_async_pf_task_wait(u32 token) · line 168
Quoted 9 lines
arch/x86/kernel/kvm.c +1
-1@@ -161,8 +161,8 @@ void kvm_async_pf_task_wait(u32 token)*/ rcu_irq_exit ();native_safe_halt (); -rcu_irq_enter ();local_irq_disable (); +rcu_irq_enter (); } }if (!n.halted)
We called rcu_irq_enter() there twice, *facepalm*. Yes, that patch should fix it.