lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
Open Source and information security mailing list archives
| ||
|
Message-ID: <20180429022606.267zucef42hm37m7@wfg-t540p.sh.intel.com> Date: Sun, 29 Apr 2018 10:26:06 +0800 From: Fengguang Wu <fengguang.wu@...el.com> To: linux-kernel@...r.kernel.org Cc: Arnd Bergmann <arnd@...db.de>, Greg Kroah-Hartman <gregkh@...uxfoundation.org>, Theodore Ts'o <tytso@....edu>, Linus Torvalds <torvalds@...ux-foundation.org>, "Jason A. Donenfeld" <Jason@...c4.com>, lkp@...org, "Kohli, Gaurav" <gkohli@...eaurora.org> Subject: [crng_reseed] WARNING: inconsistent lock state Hello, FYI this happens in mainline kernel 4.17.0-rc2. It looks like a new regression. It occurs in 3 out of 3 boots. There is another "[ 294.642506] BUG: sleeping function called from invalid context at mm/slab.h:421" at the bottom of this long dmesg: [ 123.885728] Writes: Total: 41708535 Max/Min: 0/0 Fail: 0 [ 185.312613] Writes: Total: 61148802 Max/Min: 0/0 Fail: 0 [ 246.752095] Writes: Total: 86067258 Max/Min: 0/0 Fail: 0 [ 294.560671] [ 294.560924] ================================ [ 294.561539] WARNING: inconsistent lock state [ 294.562165] 4.17.0-rc2 #145 Not tainted [ 294.562724] -------------------------------- [ 294.563338] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage. [ 294.564201] kworker/0:2/28 [HC1[1]:SC0[0]:HE0:SE1] takes: [ 294.564976] (ptrval) (fs_reclaim){?.+.}, at: fs_reclaim_acquire+0x0/0x30 [ 294.566157] {HARDIRQ-ON-W} state was registered at: [ 294.566863] lock_acquire+0x79/0xd0: lock_acquire at kernel/locking/lockdep.c:3922 [ 294.567379] fs_reclaim_acquire+0x24/0x30 [ 294.568069] fs_reclaim_acquire+0x14/0x20: fs_reclaim_acquire at mm/page_alloc.c:3740 [ 294.568660] kmem_cache_alloc_node+0x32/0x240: slab_pre_alloc_hook at mm/slab.h:419 (inlined by) slab_alloc_node at mm/slab.c:3299 (inlined by) kmem_cache_alloc_node at mm/slab.c:3642 [ 294.569294] __kmalloc_node+0x24/0x30: __kmalloc_node at mm/slab.c:3690 [ 294.569841] alloc_cpumask_var_node+0x1f/0x50 [ 294.570477] zalloc_cpumask_var+0x14/0x20 [ 294.571071] native_smp_prepare_cpus+0xf4/0x364 [ 294.571738] kvm_smp_prepare_cpus+0x21/0xff [ 294.572349] kernel_init_freeable+0x2b5/0x4db [ 294.572995] kernel_init+0x9/0x100 [ 294.573499] ret_from_fork+0x24/0x30 [ 294.574169] irq event stamp: 141042 [ 294.574681] hardirqs last enabled at (141041): [<ffffffff81d6dd81>] _raw_spin_unlock_irqrestore+0x31/0x60 [ 294.576050] hardirqs last disabled at (141042): [<ffffffff81e008d4>] interrupt_entry+0xd4/0x100 [ 294.577278] softirqs last enabled at (140644): [<ffffffff81aaec82>] update_defense_level+0x122/0x450 [ 294.578577] softirqs last disabled at (140642): [<ffffffff81aaeb60>] update_defense_level+0x0/0x450 [ 294.579855] [ 294.579855] other info that might help us debug this: [ 294.580867] Possible unsafe locking scenario: [ 294.580867] [ 294.581714] CPU0 [ 294.582073] ---- [ 294.582431] lock(fs_reclaim); [ 294.582892] <Interrupt> [ 294.583273] lock(fs_reclaim); [ 294.583757] [ 294.583757] *** DEADLOCK *** [ 294.583757] [ 294.584592] 2 locks held by kworker/0:2/28: [ 294.585196] #0: (ptrval) ((wq_completion)"events"){+.+.}, at: process_one_work+0x1d6/0x460 [ 294.586497] #1: (ptrval) ((work_completion)(&(&adapter->watchdog_task)->work)){+.+.}, at: process_one_work+0x1d6/0x460 [ 294.588125] [ 294.588125] stack backtrace: [ 294.588753] CPU: 0 PID: 28 Comm: kworker/0:2 Not tainted 4.17.0-rc2 #145 [ 294.589803] Workqueue: events e1000_watchdog [ 294.590410] Call Trace: [ 294.590776] <IRQ> [ 294.591078] dump_stack+0x8e/0xd5 [ 294.591557] print_usage_bug+0x247/0x262 [ 294.592221] mark_lock+0x5c5/0x660 [ 294.592719] ? check_usage_backwards+0x160/0x160 [ 294.593436] __lock_acquire+0xdcf/0x1b70 [ 294.594006] ? __lock_acquire+0x3f1/0x1b70 [ 294.594595] ? trace_hardirqs_off+0xd/0x10 [ 294.595190] lock_acquire+0x79/0xd0 [ 294.595706] ? lock_acquire+0x79/0xd0 [ 294.596259] ? find_suitable_fallback+0x80/0x80 [ 294.609933] ? crng_reseed+0x13e/0x2e0 [ 294.610479] fs_reclaim_acquire+0x24/0x30 [ 294.611163] ? find_suitable_fallback+0x80/0x80 [ 294.611915] fs_reclaim_acquire+0x14/0x20 [ 294.612490] __kmalloc+0x35/0x240 [ 294.612982] crng_reseed+0x13e/0x2e0 [ 294.613499] credit_entropy_bits+0x21c/0x230 [ 294.625342] add_interrupt_randomness+0x293/0x300 [ 294.626072] handle_irq_event_percpu+0x3b/0x70 [ 294.626718] handle_irq_event+0x34/0x60 [ 294.627272] handle_fasteoi_irq+0x70/0x120 [ 294.627867] handle_irq+0x15/0x20 [ 294.628349] do_IRQ+0x53/0x100 [ 294.628803] common_interrupt+0xf/0xf [ 294.629331] </IRQ> [ 294.629653] RIP: 0010:e1000_watchdog+0x126/0x530 [ 294.630335] RSP: 0000:ffff880016823e00 EFLAGS: 00000297 ORIG_RAX: ffffffffffffffda [ 294.631690] RAX: 0000000000000010 RBX: ffff880014f992c0 RCX: 0000000000000006 [ 294.632971] RDX: ffffc900008e0000 RSI: ffff88001681d3b8 RDI: ffff880014f98e70 [ 294.634237] RBP: ffff880016823e38 R08: 0000000097c673cd R09: 0000000000000000 [ 294.635549] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880014f98a80 [ 294.636838] R13: ffff880014f98000 R14: ffff880018994480 R15: ffff880014f98e70 [ 294.638276] process_one_work+0x236/0x460 [ 294.638993] ? process_one_work+0x1d6/0x460 [ 294.639652] worker_thread+0x35/0x3f0 [ 294.640175] kthread+0x122/0x140 [ 294.640646] ? process_one_work+0x460/0x460 [ 294.641242] ? __kthread_create_on_node+0x190/0x190 [ 294.641941] ret_from_fork+0x24/0x30 [ 294.642506] BUG: sleeping function called from invalid context at mm/slab.h:421 [ 294.644135] in_atomic(): 1, irqs_disabled(): 1, pid: 28, name: kworker/0:2 [ 294.646373] INFO: lockdep is turned off. [ 294.647940] irq event stamp: 141042 [ 294.648638] hardirqs last enabled at (141041): [<ffffffff81d6dd81>] _raw_spin_unlock_irqrestore+0x31/0x60 [ 294.655362] hardirqs last disabled at (141042): [<ffffffff81e008d4>] interrupt_entry+0xd4/0x100 [ 294.676115] softirqs last enabled at (140644): [<ffffffff81aaec82>] update_defense_level+0x122/0x450 [ 294.677737] softirqs last disabled at (140642): [<ffffffff81aaeb60>] update_defense_level+0x0/0x450 [ 294.682738] CPU: 0 PID: 28 Comm: kworker/0:2 Not tainted 4.17.0-rc2 #145 [ 294.683763] Workqueue: events e1000_watchdog [ 294.684414] Call Trace: [ 294.697850] <IRQ> [ 294.698174] dump_stack+0x8e/0xd5 [ 294.698697] ___might_sleep+0x15f/0x250 [ 294.699288] __might_sleep+0x45/0x80 [ 294.699853] __kmalloc+0x1a3/0x240 [ 294.700387] crng_reseed+0x13e/0x2e0 [ 294.700957] credit_entropy_bits+0x21c/0x230 [ 294.701642] add_interrupt_randomness+0x293/0x300 [ 294.702382] handle_irq_event_percpu+0x3b/0x70 [ 294.703080] handle_irq_event+0x34/0x60 [ 294.703689] handle_fasteoi_irq+0x70/0x120 [ 294.704325] handle_irq+0x15/0x20 [ 294.704863] do_IRQ+0x53/0x100 [ 294.705347] common_interrupt+0xf/0xf [ 294.705927] </IRQ> [ 294.706267] RIP: 0010:e1000_watchdog+0x126/0x530 [ 294.706983] RSP: 0000:ffff880016823e00 EFLAGS: 00000297 ORIG_RAX: ffffffffffffffda [ 294.708142] RAX: 0000000000000010 RBX: ffff880014f992c0 RCX: 0000000000000006 [ 294.709228] RDX: ffffc900008e0000 RSI: ffff88001681d3b8 RDI: ffff880014f98e70 [ 294.710314] RBP: ffff880016823e38 R08: 0000000097c673cd R09: 0000000000000000 [ 294.715815] R10: 0000000000000000 R11: 0000000000000000 R12: ffff880014f98a80 [ 294.716907] R13: ffff880014f98000 R14: ffff880018994480 R15: ffff880014f98e70 [ 294.718019] process_one_work+0x236/0x460 [ 294.718643] ? process_one_work+0x1d6/0x460 [ 294.719281] worker_thread+0x35/0x3f0 [ 294.719859] kthread+0x122/0x140 [ 294.720361] ? process_one_work+0x460/0x460 [ 294.721008] ? __kthread_create_on_node+0x190/0x190 [ 294.721766] ret_from_fork+0x24/0x30 [ 294.722324] random: crng init done Attached the full dmesg, kconfig and reproduce scripts. Thanks, Fengguang View attachment "dmesg-vm-ivb41-yocto-ia32-18:20180425110746:x86_64-randconfig-s4-04251005:4.17.0-rc2:145" of type "text/plain" (66429 bytes) View attachment ".config" of type "text/plain" (112499 bytes) View attachment "job-script" of type "text/plain" (3826 bytes) View attachment "reproduce-vm-ivb41-yocto-ia32-18:20180425110746:x86_64-randconfig-s4-04251005:4.17.0-rc2:145" of type "text/plain" (2144 bytes)
Powered by blists - more mailing lists