[ 9.813881][ T182] netdevsim netdevsim9955 eni9955np1: renamed from eth0 [ 9.813941][ T182] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 9.813943][ T182] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 182, name: (udev-worker) [ 9.813945][ T182] preempt_count: 1, expected: 0 [ 9.813946][ T182] RCU nest depth: 0, expected: 0 [ 9.813947][ T182] locks held by (udev-worker)/182: 6, last CPU#3: [ 9.813949][ T182] #0: ffffffffbaf05fc0 (rtnl_mutex){+.+.}-{4:4}, at: rtnl_setlink+0x29d/0x920 [ 9.813962][ T182] #1: ff1100000e93ade8 (&dev_instance_lock_key#2){+.+.}-{4:4}, at: do_setlink.isra.0+0x27a/0x2a60 [ 9.813967][ T182] #2: ffffffffba799cc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 9.813972][ T182] #3: ffffffffba799d38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 9.813976][ T182] #4: ffffffffba689660 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 9.813980][ T182] #5: ffffffffba689560 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x202/0x4f0 [ 9.813984][ T182] irq event stamp: 38516 [ 9.813985][ T182] hardirqs last enabled at (38515): [] __down_trylock_console_sem+0x86/0xa0 [ 9.813988][ T182] hardirqs last disabled at (38516): [] console_emit_next_record+0x3f8/0x4f0 [ 9.813990][ T182] softirqs last enabled at (38510): [] netif_change_name+0x216/0x8c0 [ 9.813994][ T182] softirqs last disabled at (38508): [] netif_change_name+0x1ad/0x8c0 [ 9.813996][ T182] Preemption disabled at: [ 9.813997][ T182] [] vprintk_emit+0x31b/0x3e0 [ 9.814001][ T182] CPU: 3 UID: 0 PID: 182 Comm: (udev-worker) Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 9.814005][ T182] Tainted: [W]=WARN [ 9.814006][ T182] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 9.814008][ T182] Call Trace: [ 9.814009][ T182] [ 9.814011][ T182] dump_stack_lvl+0x6f/0xa0 [ 9.814017][ T182] ? vprintk_emit+0x31b/0x3e0 [ 9.814019][ T182] __might_resched.cold+0x1fe/0x2c1 [ 9.814023][ T182] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 9.814028][ T182] ? __kmalloc_noprof+0xdb/0x760 [ 9.814034][ T182] __kmalloc_noprof+0x443/0x760 [ 9.814036][ T182] ? alloc_buf.isra.0+0x4b/0x260 [ 9.814043][ T182] ? do_raw_spin_unlock+0x59/0x250 [ 9.814046][ T182] alloc_buf.isra.0+0x4b/0x260 [ 9.814049][ T182] put_chars+0x1e1/0x2f0 [ 9.814052][ T182] ? __send_to_port+0x420/0x420 [ 9.814056][ T182] ? validate_chain+0x34a/0xc20 [ 9.814062][ T182] hvc_console_print+0x292/0x780 [ 9.814065][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814071][ T182] ? hvc_write+0x3a0/0x3a0 [ 9.814074][ T182] ? rcu_is_watching+0x16/0xd0 [ 9.814080][ T182] console_emit_next_record+0x252/0x4f0 [ 9.814084][ T182] ? devkmsg_read+0x4e0/0x4e0 [ 9.814089][ T182] ? rcu_is_watching+0x16/0xd0 [ 9.814091][ T182] ? lock_acquire+0x13c/0x160 [ 9.814095][ T182] console_flush_one_record+0x46f/0x710 [ 9.814099][ T182] ? console_emit_next_record+0x4f0/0x4f0 [ 9.814101][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814107][ T182] console_unlock+0xee/0x1f0 [ 9.814110][ T182] ? console_flush_one_record+0x710/0x710 [ 9.814112][ T182] ? rcu_is_watching+0x16/0xd0 [ 9.814114][ T182] ? lock_acquire+0x60/0x160 [ 9.814118][ T182] ? __down_trylock_console_sem+0x5e/0xa0 [ 9.814120][ T182] ? vprintk_emit+0x320/0x3e0 [ 9.814123][ T182] vprintk_emit+0x37c/0x3e0 [ 9.814126][ T182] ? wake_up_klogd_work_func+0x90/0x90 [ 9.814128][ T182] ? write_profile+0xf0/0xf0 [ 9.814131][ T182] ? unwind_get_return_address+0x67/0xd0 [ 9.814137][ T182] dev_vprintk_emit+0x27f/0x2c0 [ 9.814142][ T182] ? device_rename.cold+0xa/0xa [ 9.814146][ T182] ? filter_irq_stacks+0xd0/0xd0 [ 9.814153][ T182] dev_printk_emit+0xb9/0xee [ 9.814155][ T182] ? dev_vprintk_emit+0x2c0/0x2c0 [ 9.814159][ T182] ? check_prev_add+0x316/0xe90 [ 9.814165][ T182] __netdev_printk+0x160/0x1d0 [ 9.814171][ T182] netdev_info+0xe2/0x116 [ 9.814173][ T182] ? netdev_notice+0x120/0x120 [ 9.814176][ T182] ? find_held_lock+0x2b/0x80 [ 9.814179][ T182] ? __lock_release.isra.0+0x69/0x1a0 [ 9.814182][ T182] ? mark_held_locks+0x40/0x70 [ 9.814186][ T182] ? do_setlink.isra.0+0x1f7d/0x2a60 [ 9.814188][ T182] netif_change_name.cold+0x4f/0x89 [ 9.814191][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814193][ T182] ? mark_lock_irq+0x747/0x9c0 [ 9.814195][ T182] ? find_held_lock+0x2/0x80 [ 9.814198][ T182] ? netdev_adjacent_rename_links+0x470/0x470 [ 9.814201][ T182] ? find_held_lock+0x2b/0x80 [ 9.814204][ T182] ? __asan_memset+0x27/0x50 [ 9.814209][ T182] do_setlink.isra.0+0x1f7d/0x2a60 [ 9.814212][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814216][ T182] ? rtnl_link_get_size+0x350/0x350 [ 9.814217][ T182] ? mark_usage+0x61/0x170 [ 9.814219][ T182] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 9.814222][ T182] ? rcu_read_lock_any_held+0x3c/0x90 [ 9.814225][ T182] ? validate_chain+0x38b/0xc20 [ 9.814230][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814234][ T182] ? lock_acquire.part.0+0xd4/0x280 [ 9.814237][ T182] ? rtnl_setlink+0x29d/0x920 [ 9.814240][ T182] ? rcu_is_watching+0x16/0xd0 [ 9.814242][ T182] ? lock_acquire+0x13c/0x160 [ 9.814243][ T182] ? rcu_is_watching+0x16/0xd0 [ 9.814245][ T182] ? rcu_is_watching+0x16/0xd0 [ 9.814246][ T182] ? trace_contention_end+0xb3/0x180 [ 9.814249][ T182] ? __mutex_lock+0x1db/0x1ea0 [ 9.814253][ T182] ? __mutex_lock+0x9a3/0x1ea0 [ 9.814255][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814257][ T182] ? rtnl_setlink+0x29d/0x920 [ 9.814259][ T182] ? mark_usage+0x61/0x170 [ 9.814262][ T182] ? ww_mutex_lock+0x160/0x160 [ 9.814265][ T182] ? nla_get_range_signed+0x3d0/0x3d0 [ 9.814271][ T182] ? mark_usage+0x61/0x170 [ 9.814274][ T182] ? cap_capable+0x1d7/0x3d0 [ 9.814282][ T182] rtnl_setlink+0x527/0x920 [ 9.814286][ T182] ? __rtnl_newlink+0xa50/0xa50 [ 9.814287][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814318][ T182] ? lock_acquire.part.0+0xd4/0x280 [ 9.814320][ T182] ? find_held_lock+0x2b/0x80 [ 9.814323][ T182] ? __lock_release.isra.0+0x69/0x1a0 [ 9.814325][ T182] ? mark_usage+0x61/0x170 [ 9.814327][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814332][ T182] ? lock_acquire.part.0+0xd4/0x280 [ 9.814334][ T182] ? find_held_lock+0x2b/0x80 [ 9.814336][ T182] ? __rtnl_newlink+0xa50/0xa50 [ 9.814338][ T182] ? __lock_release.isra.0+0x69/0x1a0 [ 9.814342][ T182] ? __rtnl_newlink+0xa50/0xa50 [ 9.814345][ T182] rtnetlink_rcv_msg+0x6fd/0xbd0 [ 9.814349][ T182] ? rtnl_link_fill+0x900/0x900 [ 9.814350][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814355][ T182] ? lock_acquire.part.0+0xd4/0x280 [ 9.814357][ T182] ? find_held_lock+0x2b/0x80 [ 9.814361][ T182] netlink_rcv_skb+0x14e/0x3a0 [ 9.814365][ T182] ? rtnl_link_fill+0x900/0x900 [ 9.814368][ T182] ? netlink_ack+0xcd0/0xcd0 [ 9.814375][ T182] ? netlink_deliver_tap+0xc5/0x330 [ 9.814377][ T182] ? netlink_deliver_tap+0x13c/0x330 [ 9.814382][ T182] netlink_unicast+0x486/0x750 [ 9.814386][ T182] ? netlink_attachskb+0x810/0x810 [ 9.814389][ T182] ? __lock_acquire+0x518/0xc20 [ 9.814394][ T182] netlink_sendmsg+0x735/0xc60 [ 9.814398][ T182] ? netlink_unicast+0x750/0x750 [ 9.814402][ T182] ? __might_fault+0x97/0x140 [ 9.814406][ T182] ? __might_fault+0x97/0x140 [ 9.814410][ T182] __sys_sendto+0x2aa/0x400 [ 9.814414][ T182] ? __ia32_sys_getpeername+0xd0/0xd0 [ 9.814430][ T182] ? exc_page_fault+0x87/0x100 [ 9.814436][ T182] __x64_sys_sendto+0xe4/0x1f0 [ 9.814438][ T182] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 9.814441][ T182] ? lockdep_hardirqs_on+0x91/0x130 [ 9.814443][ T182] ? do_syscall_64+0xa6/0x530 [ 9.814445][ T182] do_syscall_64+0xff/0x530 [ 9.814447][ T182] ? exc_page_fault+0xee/0x100 [ 9.814450][ T182] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 9.814452][ T182] RIP: 0033:0x7f435299854e [ 9.814456][ T182] Code: 4d 89 d8 e8 b4 bd 00 00 4c 8b 5d f8 41 8b 93 08 03 00 00 59 5e 48 83 f8 fc 74 11 c9 c3 0f 1f 80 00 00 00 00 48 8b 45 10 0f 05 c3 83 e2 39 83 fa 08 75 e7 e8 03 ff ff ff 0f 1f 00 f3 0f 1e fa [ 9.814458][ T182] RSP: 002b:00007fff3185a0c0 EFLAGS: 00000202 ORIG_RAX: 000000000000002c [ 9.814461][ T182] RAX: ffffffffffffffda RBX: 000055dc4d365b70 RCX: 00007f435299854e [ 9.814462][ T182] RDX: 0000000000000030 RSI: 000055dc4d216a80 RDI: 0000000000000016 [ 9.814463][ T182] RBP: 00007fff3185a0d0 R08: 00007fff3185a120 R09: 0000000000000080 [ 9.814464][ T182] R10: 0000000000000000 R11: 0000000000000202 R12: 000055dc4d3b4680 [ 9.814465][ T182] R13: 00007fff3185a204 R14: 0000000000000000 R15: 0000000000000000 [ 9.814472][ T182] [ 10.025411][ T182] netdevsim netdevsim12201 eni12201np1: renamed from eth0 [ 12.375781][ T217] iperf3 (217) used greatest stack depth: 24536 bytes left [ 12.375800][ T217] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 12.375802][ T217] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 217, name: iperf3 [ 12.375804][ T217] preempt_count: 2, expected: 0 [ 12.375805][ T217] RCU nest depth: 0, expected: 0 [ 12.375806][ T217] locks held by iperf3/217: 5, last CPU#0: [ 12.375808][ T217] #0: ffffffffba6027b8 (low_water_lock){+.+.}-{3:3}, at: do_exit+0x887/0xdc0 [ 12.375819][ T217] #1: ffffffffba799cc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 12.375824][ T217] #2: ffffffffba799d38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 12.375829][ T217] #3: ffffffffba689660 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 12.375832][ T217] #4: ffffffffba689560 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x202/0x4f0 [ 12.375836][ T217] irq event stamp: 14622 [ 12.375838][ T217] hardirqs last enabled at (14621): [] __down_trylock_console_sem+0x86/0xa0 [ 12.375841][ T217] hardirqs last disabled at (14622): [] console_emit_next_record+0x3f8/0x4f0 [ 12.375843][ T217] softirqs last enabled at (14552): [] tcp_sendmsg+0x39/0x50 [ 12.375847][ T217] softirqs last disabled at (14550): [] release_sock+0x21/0x240 [ 12.375852][ T217] Preemption disabled at: [ 12.375853][ T217] [<0000000000000000>] 0x0 [ 12.375859][ T217] CPU: 0 UID: 0 PID: 217 Comm: iperf3 Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 12.375863][ T217] Tainted: [W]=WARN [ 12.375864][ T217] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 12.375866][ T217] Call Trace: [ 12.375868][ T217] [ 12.375869][ T217] dump_stack_lvl+0x6f/0xa0 [ 12.375876][ T217] __might_resched.cold+0x1fe/0x2c1 [ 12.375881][ T217] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 12.375885][ T217] ? __kmalloc_noprof+0xdb/0x760 [ 12.375891][ T217] __kmalloc_noprof+0x443/0x760 [ 12.375893][ T217] ? alloc_buf.isra.0+0x4b/0x260 [ 12.375900][ T217] ? do_raw_spin_unlock+0x59/0x250 [ 12.375902][ T217] alloc_buf.isra.0+0x4b/0x260 [ 12.375906][ T217] put_chars+0x1e1/0x2f0 [ 12.375909][ T217] ? __send_to_port+0x420/0x420 [ 12.375912][ T217] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 12.375916][ T217] ? rcu_read_lock_any_held+0x3c/0x90 [ 12.375919][ T217] ? validate_chain+0x38b/0xc20 [ 12.375923][ T217] hvc_console_print+0x292/0x780 [ 12.375926][ T217] ? mark_usage+0x61/0x170 [ 12.375928][ T217] ? __lock_acquire+0x518/0xc20 [ 12.375930][ T217] ? __lock_acquire+0x518/0xc20 [ 12.375934][ T217] ? hvc_write+0x3a0/0x3a0 [ 12.375936][ T217] ? lock_acquire.part.0+0xd4/0x280 [ 12.375940][ T217] ? lock_acquire+0x13c/0x160 [ 12.375945][ T217] console_emit_next_record+0x252/0x4f0 [ 12.375949][ T217] ? devkmsg_read+0x4e0/0x4e0 [ 12.375954][ T217] ? rcu_is_watching+0x16/0xd0 [ 12.375956][ T217] ? lock_acquire+0x13c/0x160 [ 12.375960][ T217] console_flush_one_record+0x46f/0x710 [ 12.375965][ T217] ? console_emit_next_record+0x4f0/0x4f0 [ 12.375967][ T217] ? __lock_acquire+0x518/0xc20 [ 12.375972][ T217] console_unlock+0xee/0x1f0 [ 12.375975][ T217] ? console_flush_one_record+0x710/0x710 [ 12.375977][ T217] ? rcu_is_watching+0x16/0xd0 [ 12.375979][ T217] ? lock_acquire+0x60/0x160 [ 12.375982][ T217] ? __down_trylock_console_sem+0x5e/0xa0 [ 12.375984][ T217] ? vprintk_emit+0x320/0x3e0 [ 12.375987][ T217] vprintk_emit+0x37c/0x3e0 [ 12.375990][ T217] ? wake_up_klogd_work_func+0x90/0x90 [ 12.375993][ T217] ? __lock_acquire+0x518/0xc20 [ 12.375997][ T217] _printk+0xc7/0x100 [ 12.376000][ T217] ? snapshot_read.cold+0x21/0x21 [ 12.376003][ T217] ? do_raw_spin_lock+0x131/0x280 [ 12.376006][ T217] ? __rwlock_init+0x150/0x150 [ 12.376010][ T217] ? do_raw_spin_lock+0x131/0x280 [ 12.376013][ T217] do_exit.cold+0x82/0x9c [ 12.376017][ T217] ? exit_notify+0x890/0x890 [ 12.376022][ T217] do_group_exit+0xb8/0x370 [ 12.376025][ T217] ? _raw_spin_unlock_irq+0x33/0x50 [ 12.376028][ T217] get_signal+0x1886/0x1980 [ 12.376032][ T217] ? ____sys_recvmsg+0x710/0x710 [ 12.376037][ T217] ? new_sync_read+0x750/0x750 [ 12.376041][ T217] ? ptrace_signal+0x600/0x600 [ 12.376044][ T217] ? __lock_release.isra.0+0x69/0x1a0 [ 12.376048][ T217] arch_do_signal_or_restart+0xc2/0x3a0 [ 12.376052][ T217] ? __fget_files+0x1e3/0x460 [ 12.376055][ T217] ? get_sigframe_size+0x20/0x20 [ 12.376061][ T217] ? rcu_is_watching+0x16/0xd0 [ 12.376063][ T217] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 12.376067][ T217] exit_to_user_mode_loop+0xd5/0x5a0 [ 12.376070][ T217] ? rcu_is_watching+0x16/0xd0 [ 12.376073][ T217] do_syscall_64+0x3e3/0x530 [ 12.376075][ T217] ? exc_page_fault+0xee/0x100 [ 12.376078][ T217] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 12.376081][ T217] RIP: 0033:0x7fd6f5e30312 [ 12.376083][ T217] Code: Unable to access opcode bytes at 0x7fd6f5e302e8. [ 12.376084][ T217] RSP: 002b:00007fd6f5406c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000001 [ 12.376087][ T217] RAX: 0000000000003db8 RBX: 0000000000020000 RCX: 00007fd6f5e30312 [ 12.376088][ T217] RDX: 0000000000020000 RSI: 00007fd6f55e8000 RDI: 0000000000000005 [ 12.376089][ T217] RBP: 00007fd6f5406ca0 R08: 0000000000000000 R09: 0000000000000000 [ 12.376090][ T217] R10: 0000000000000000 R11: 0000000000000246 R12: 00007fd6f55e8000 [ 12.376091][ T217] R13: 0000000000000005 R14: 0000000000020000 R15: 0000559b520eeaa0 [ 12.376097][ T217] [ 12.407140][ T225] iperf3 (225) used greatest stack depth: 24016 bytes left [ 14.412055][ T281] iperf3 (281) used greatest stack depth: 23384 bytes left [ 14.412076][ T281] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 14.412078][ T281] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 281, name: iperf3 [ 14.412080][ T281] preempt_count: 2, expected: 0 [ 14.412081][ T281] RCU nest depth: 0, expected: 0 [ 14.412082][ T281] locks held by iperf3/281: 5, last CPU#3: [ 14.412084][ T281] #0: ffffffffba6027b8 (low_water_lock){+.+.}-{3:3}, at: do_exit+0x887/0xdc0 [ 14.412096][ T281] #1: ffffffffba799cc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 14.412101][ T281] #2: ffffffffba799d38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 14.412105][ T281] #3: ffffffffba689660 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 14.412109][ T281] #4: ffffffffba689560 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x202/0x4f0 [ 14.412113][ T281] irq event stamp: 24884 [ 14.412114][ T281] hardirqs last enabled at (24883): [] __down_trylock_console_sem+0x86/0xa0 [ 14.412117][ T281] hardirqs last disabled at (24884): [] console_emit_next_record+0x3f8/0x4f0 [ 14.412119][ T281] softirqs last enabled at (24834): [] tcp_recvmsg+0x114/0x4f0 [ 14.412123][ T281] softirqs last disabled at (24832): [] release_sock+0x21/0x240 [ 14.412127][ T281] Preemption disabled at: [ 14.412128][ T281] [<0000000000000000>] 0x0 [ 14.412135][ T281] CPU: 3 UID: 0 PID: 281 Comm: iperf3 Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 14.412139][ T281] Tainted: [W]=WARN [ 14.412140][ T281] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 14.412142][ T281] Call Trace: [ 14.412143][ T281] [ 14.412145][ T281] dump_stack_lvl+0x6f/0xa0 [ 14.412151][ T281] __might_resched.cold+0x1fe/0x2c1 [ 14.412156][ T281] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 14.412160][ T281] ? __kmalloc_noprof+0xdb/0x760 [ 14.412166][ T281] __kmalloc_noprof+0x443/0x760 [ 14.412169][ T281] ? alloc_buf.isra.0+0x4b/0x260 [ 14.412175][ T281] ? do_raw_spin_unlock+0x59/0x250 [ 14.412178][ T281] alloc_buf.isra.0+0x4b/0x260 [ 14.412182][ T281] put_chars+0x1e1/0x2f0 [ 14.412185][ T281] ? __send_to_port+0x420/0x420 [ 14.412188][ T281] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 14.412191][ T281] ? rcu_read_lock_any_held+0x3c/0x90 [ 14.412194][ T281] ? validate_chain+0x38b/0xc20 [ 14.412199][ T281] hvc_console_print+0x292/0x780 [ 14.412202][ T281] ? mark_usage+0x61/0x170 [ 14.412204][ T281] ? __lock_acquire+0x518/0xc20 [ 14.412206][ T281] ? __lock_acquire+0x518/0xc20 [ 14.412210][ T281] ? hvc_write+0x3a0/0x3a0 [ 14.412212][ T281] ? lock_acquire.part.0+0xd4/0x280 [ 14.412216][ T281] ? lock_acquire+0x13c/0x160 [ 14.412220][ T281] console_emit_next_record+0x252/0x4f0 [ 14.412224][ T281] ? devkmsg_read+0x4e0/0x4e0 [ 14.412229][ T281] ? rcu_is_watching+0x16/0xd0 [ 14.412231][ T281] ? lock_acquire+0x13c/0x160 [ 14.412235][ T281] console_flush_one_record+0x46f/0x710 [ 14.412239][ T281] ? console_emit_next_record+0x4f0/0x4f0 [ 14.412241][ T281] ? __lock_acquire+0x518/0xc20 [ 14.412247][ T281] console_unlock+0xee/0x1f0 [ 14.412250][ T281] ? console_flush_one_record+0x710/0x710 [ 14.412252][ T281] ? rcu_is_watching+0x16/0xd0 [ 14.412253][ T281] ? lock_acquire+0x60/0x160 [ 14.412257][ T281] ? __down_trylock_console_sem+0x5e/0xa0 [ 14.412259][ T281] ? vprintk_emit+0x320/0x3e0 [ 14.412262][ T281] vprintk_emit+0x37c/0x3e0 [ 14.412265][ T281] ? wake_up_klogd_work_func+0x90/0x90 [ 14.412268][ T281] ? __lock_acquire+0x518/0xc20 [ 14.412272][ T281] _printk+0xc7/0x100 [ 14.412276][ T281] ? snapshot_read.cold+0x21/0x21 [ 14.412278][ T281] ? do_raw_spin_lock+0x131/0x280 [ 14.412281][ T281] ? __rwlock_init+0x150/0x150 [ 14.412285][ T281] ? do_raw_spin_lock+0x131/0x280 [ 14.412288][ T281] do_exit.cold+0x82/0x9c [ 14.412292][ T281] ? exit_notify+0x890/0x890 [ 14.412293][ T281] ? find_held_lock+0x2b/0x80 [ 14.412296][ T281] ? __lock_release.isra.0+0x69/0x1a0 [ 14.412298][ T281] ? __rwlock_init+0x150/0x150 [ 14.412305][ T281] do_group_exit+0xb8/0x370 [ 14.412307][ T281] ? lockdep_hardirqs_on_prepare.part.0+0x9a/0x160 [ 14.412310][ T281] ? lockdep_hardirqs_on+0x91/0x130 [ 14.412313][ T281] ? _raw_spin_unlock_irq+0x28/0x50 [ 14.412316][ T281] ? _raw_spin_unlock_irq+0x33/0x50 [ 14.412317][ T281] get_signal+0x1886/0x1980 [ 14.412322][ T281] ? new_sync_read+0x3fb/0x750 [ 14.412328][ T281] ? ptrace_signal+0x600/0x600 [ 14.412331][ T281] ? __lock_release.isra.0+0x69/0x1a0 [ 14.412336][ T281] arch_do_signal_or_restart+0xc2/0x3a0 [ 14.412340][ T281] ? __fget_files+0x1e3/0x460 [ 14.412343][ T281] ? get_sigframe_size+0x20/0x20 [ 14.412349][ T281] ? rcu_is_watching+0x16/0xd0 [ 14.412350][ T281] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 14.412354][ T281] exit_to_user_mode_loop+0xd5/0x5a0 [ 14.412357][ T281] ? rcu_is_watching+0x16/0xd0 [ 14.412360][ T281] do_syscall_64+0x3e3/0x530 [ 14.412363][ T281] ? irq_exit_rcu+0x1a/0x30 [ 14.412366][ T281] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 14.412368][ T281] RIP: 0033:0x7f3ea8af2312 [ 14.412371][ T281] Code: Unable to access opcode bytes at 0x7f3ea8af22e8. [ 14.412372][ T281] RSP: 002b:00007f3ea38bfc98 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 14.412374][ T281] RAX: fffffffffffffe00 RBX: 00000000000137a8 RCX: 00007f3ea8af2312 [ 14.412376][ T281] RDX: 00000000000137a8 RSI: 00007f3ea8196858 RDI: 0000000000000018 [ 14.412377][ T281] RBP: 00007f3ea38bfcc0 R08: 0000000000000000 R09: 0000000000000000 [ 14.412377][ T281] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000020000 [ 14.412378][ T281] R13: 0000000000000018 R14: 0000000000000000 R15: 00007f3ea8196858 [ 14.412385][ T281] [ 14.426043][ C0] clocksource: Watchdog remote CPU 3 read timed out [ 14.426068][ C0] [ 14.426069][ C0] ======================================================== [ 14.426070][ C0] WARNING: possible irq lock inversion dependency detected [ 14.426072][ C0] 7.2.0-virtme #1 Tainted: G W [ 14.426074][ C0] -------------------------------------------------------- [ 14.426074][ C0] ksoftirqd/0/14 just changed the state of lock: [ 14.426075][ C0] ffffffffba689660 (console_owner){..-.}-{0:0}, at: console_trylock_spinning+0xa4/0x1e0 [ 14.426087][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 14.426088][ C0] (fs_reclaim){+.+.}-{0:0} [ 14.426090][ C0] [ 14.426090][ C0] [ 14.426090][ C0] and interrupts could create inverse lock ordering between them. [ 14.426090][ C0] [ 14.426090][ C0] [ 14.426090][ C0] other info that might help us debug this: [ 14.426091][ C0] Possible interrupt unsafe locking scenario: [ 14.426091][ C0] [ 14.426092][ C0] CPU0 CPU1 [ 14.426092][ C0] ---- ---- [ 14.426092][ C0] lock(fs_reclaim); [ 14.426094][ C0] local_irq_disable(); [ 14.426094][ C0] lock(console_owner); [ 14.426095][ C0] lock(fs_reclaim); [ 14.426096][ C0] [ 14.426097][ C0] lock(console_owner); [ 14.426097][ C0] [ 14.426097][ C0] *** DEADLOCK *** [ 14.426097][ C0] [ 14.426098][ C0] locks held by ksoftirqd/0/14: 2, last CPU#0: [ 14.426099][ C0] #0: ffa00000000e7ab8 ((&watchdog_timer)){+.-.}-{0:0}, at: call_timer_fn+0x110/0x4d0 [ 14.426105][ C0] #1: ffffffffba7fe8b8 (watchdog_lock){+.-.}-{3:3}, at: clocksource_watchdog+0x15/0x30 [ 14.426110][ C0] [ 14.426110][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 14.426113][ C0] -> (fs_reclaim){+.+.}-{0:0} { [ 14.426115][ C0] HARDIRQ-ON-W at: [ 14.426117][ C0] __lock_acquire+0x388/0xc20 [ 14.426120][ C0] lock_acquire.part.0+0xd4/0x280 [ 14.426122][ C0] fs_reclaim_acquire+0xd5/0x120 [ 14.426125][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 14.426129][ C0] kthread_create_worker_on_node+0xea/0x210 [ 14.426132][ C0] workqueue_init+0x2a/0x680 [ 14.426136][ C0] kernel_init_freeable+0x2fe/0x630 [ 14.426138][ C0] kernel_init+0x21/0x150 [ 14.426142][ C0] ret_from_fork+0x474/0x6b0 [ 14.426145][ C0] ret_from_fork_asm+0x11/0x20 [ 14.426148][ C0] SOFTIRQ-ON-W at: [ 14.426148][ C0] __lock_acquire+0x388/0xc20 [ 14.426150][ C0] lock_acquire.part.0+0xd4/0x280 [ 14.426151][ C0] fs_reclaim_acquire+0xd5/0x120 [ 14.426153][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 14.426154][ C0] kthread_create_worker_on_node+0xea/0x210 [ 14.426156][ C0] workqueue_init+0x2a/0x680 [ 14.426157][ C0] kernel_init_freeable+0x2fe/0x630 [ 14.426158][ C0] kernel_init+0x21/0x150 [ 14.426160][ C0] ret_from_fork+0x474/0x6b0 [ 14.426161][ C0] ret_from_fork_asm+0x11/0x20 [ 14.426162][ C0] INITIAL USE at: [ 14.426163][ C0] __lock_acquire+0x388/0xc20 [ 14.426165][ C0] lock_acquire.part.0+0xd4/0x280 [ 14.426166][ C0] fs_reclaim_acquire+0xd5/0x120 [ 14.426168][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 14.426169][ C0] kthread_create_worker_on_node+0xea/0x210 [ 14.426171][ C0] workqueue_init+0x2a/0x680 [ 14.426172][ C0] kernel_init_freeable+0x2fe/0x630 [ 14.426173][ C0] kernel_init+0x21/0x150 [ 14.426174][ C0] ret_from_fork+0x474/0x6b0 [ 14.426176][ C0] ret_from_fork_asm+0x11/0x20 [ 14.426177][ C0] } [ 14.426177][ C0] ... key at: [] __fs_reclaim_map+0x0/0xbe0 [ 14.426181][ C0] ... acquired at: [ 14.426182][ C0] __lock_acquire+0x518/0xc20 [ 14.426183][ C0] lock_acquire.part.0+0xd4/0x280 [ 14.426185][ C0] fs_reclaim_acquire+0xd5/0x120 [ 14.426186][ C0] __kmalloc_noprof+0xd3/0x760 [ 14.426188][ C0] alloc_buf.isra.0+0x4b/0x260 [ 14.426191][ C0] put_chars+0x1e1/0x2f0 [ 14.426193][ C0] hvc_console_print+0x292/0x780 [ 14.426195][ C0] console_emit_next_record+0x252/0x4f0 [ 14.426197][ C0] console_flush_one_record+0x46f/0x710 [ 14.426198][ C0] console_unlock+0xee/0x1f0 [ 14.426200][ C0] vprintk_emit+0x37c/0x3e0 [ 14.426201][ C0] dev_vprintk_emit+0x27f/0x2c0 [ 14.426205][ C0] dev_printk_emit+0xb9/0xee [ 14.426207][ C0] _dev_info+0xe2/0x116 [ 14.426208][ C0] __devm_rtc_register_device.cold+0xc3/0x3a8 [ 14.426211][ C0] cmos_do_probe+0x73b/0x98a [ 14.426212][ C0] platform_probe+0xfe/0x1f0 [ 14.426216][ C0] call_driver_probe+0x61/0x1c0 [ 14.426217][ C0] really_probe+0x199/0x760 [ 14.426218][ C0] __driver_probe_device+0x24f/0x440 [ 14.426219][ C0] driver_probe_device+0x4a/0xf0 [ 14.426220][ C0] __driver_attach+0x1b8/0x540 [ 14.426222][ C0] bus_for_each_dev+0x130/0x1e0 [ 14.426224][ C0] bus_add_driver+0x2c8/0x530 [ 14.426225][ C0] driver_register+0x1a3/0x390 [ 14.426226][ C0] __platform_driver_probe+0x13f/0x270 [ 14.426227][ C0] cmos_init+0x31/0x40 [ 14.426230][ C0] do_one_initcall+0x124/0x4f0 [ 14.426231][ C0] kernel_init_freeable+0x596/0x630 [ 14.426232][ C0] kernel_init+0x21/0x150 [ 14.426234][ C0] ret_from_fork+0x474/0x6b0 [ 14.426235][ C0] ret_from_fork_asm+0x11/0x20 [ 14.426236][ C0] [ 14.426237][ C0] -> (console_owner){..-.}-{0:0} { [ 14.426238][ C0] IN-SOFTIRQ-W at: [ 14.426239][ C0] __lock_acquire+0x388/0xc20 [ 14.426241][ C0] lock_acquire.part.0+0xd4/0x280 [ 14.426242][ C0] console_trylock_spinning+0xb5/0x1e0 [ 14.426244][ C0] vprintk_emit+0x320/0x3e0 [ 14.426245][ C0] _printk+0xc7/0x100 [ 14.426248][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 14.426250][ C0] call_timer_fn+0x160/0x4d0 [ 14.426252][ C0] __run_timers+0x68f/0xaa0 [ 14.426254][ C0] run_timer_softirq+0xf0/0x160 [ 14.426255][ C0] handle_softirqs+0x1d3/0x900 [ 14.426257][ C0] run_ksoftirqd+0x39/0x60 [ 14.426259][ C0] smpboot_thread_fn+0x2fb/0x9b0 [ 14.426261][ C0] kthread+0x367/0x460 [ 14.426263][ C0] ret_from_fork+0x474/0x6b0 [ 14.426265][ C0] ret_from_fork_asm+0x11/0x20 [ 14.426266][ C0] INITIAL USE at: [ 14.426267][ C0] } [ 14.426267][ C0] ... key at: [] console_owner_dep_map+0x0/0x60 [ 14.426272][ C0] ... acquired at: [ 14.426272][ C0] mark_lock+0x1d7/0xa00 [ 14.426274][ C0] mark_usage+0x42/0x170 [ 14.426275][ C0] __lock_acquire+0x388/0xc20 [ 14.426277][ C0] lock_acquire.part.0+0xd4/0x280 [ 14.426278][ C0] console_trylock_spinning+0xb5/0x1e0 [ 14.426280][ C0] vprintk_emit+0x320/0x3e0 [ 14.426281][ C0] _printk+0xc7/0x100 [ 14.426282][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 14.426283][ C0] call_timer_fn+0x160/0x4d0 [ 14.426285][ C0] __run_timers+0x68f/0xaa0 [ 14.426287][ C0] run_timer_softirq+0xf0/0x160 [ 14.426288][ C0] handle_softirqs+0x1d3/0x900 [ 14.426290][ C0] run_ksoftirqd+0x39/0x60 [ 14.426291][ C0] smpboot_thread_fn+0x2fb/0x9b0 [ 14.426293][ C0] kthread+0x367/0x460 [ 14.426294][ C0] ret_from_fork+0x474/0x6b0 [ 14.426295][ C0] ret_from_fork_asm+0x11/0x20 [ 14.426297][ C0] [ 14.426297][ C0] [ 14.426297][ C0] stack backtrace: [ 14.426301][ C0] CPU: 0 UID: 0 PID: 14 Comm: ksoftirqd/0 Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 14.426306][ C0] Tainted: [W]=WARN [ 14.426307][ C0] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 14.426309][ C0] Call Trace: [ 14.426310][ C0] [ 14.426312][ C0] dump_stack_lvl+0x6f/0xa0 [ 14.426316][ C0] print_irq_inversion_bug.part.0.cold+0xe6/0x143 [ 14.426318][ C0] mark_lock_irq+0x989/0x9c0 [ 14.426322][ C0] mark_lock+0x1d7/0xa00 [ 14.426324][ C0] mark_usage+0x42/0x170 [ 14.426325][ C0] __lock_acquire+0x388/0xc20 [ 14.426328][ C0] lock_acquire.part.0+0xd4/0x280 [ 14.426330][ C0] ? console_trylock_spinning+0xa4/0x1e0 [ 14.426332][ C0] ? rcu_is_watching+0x16/0xd0 [ 14.426334][ C0] ? lock_acquire+0x13c/0x160 [ 14.426336][ C0] console_trylock_spinning+0xb5/0x1e0 [ 14.426338][ C0] ? console_trylock_spinning+0xa4/0x1e0 [ 14.426340][ C0] vprintk_emit+0x320/0x3e0 [ 14.426341][ C0] ? wake_up_klogd_work_func+0x90/0x90 [ 14.426343][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 14.426345][ C0] _printk+0xc7/0x100 [ 14.426347][ C0] ? snapshot_read.cold+0x21/0x21 [ 14.426349][ C0] ? clocksource_watchdog.part.0+0x4d0/0x540 [ 14.426351][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 14.426353][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 14.426355][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 14.426357][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 14.426359][ C0] call_timer_fn+0x160/0x4d0 [ 14.426361][ C0] ? detach_if_pending+0x1d0/0x1d0 [ 14.426363][ C0] ? find_held_lock+0x2b/0x80 [ 14.426365][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 14.426366][ C0] ? rcu_is_watching+0x16/0xd0 [ 14.426368][ C0] __run_timers+0x68f/0xaa0 [ 14.426370][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 14.426372][ C0] ? __rwlock_init+0x150/0x150 [ 14.426374][ C0] ? __bpf_trace_itimer_expire+0x10/0x10 [ 14.426376][ C0] ? __lock_acquire+0x518/0xc20 [ 14.426379][ C0] ? __rwlock_init+0x150/0x150 [ 14.426382][ C0] run_timer_softirq+0xf0/0x160 [ 14.426383][ C0] ? tasklet_action_common+0x7a/0x410 [ 14.426385][ C0] ? __run_timers+0xaa0/0xaa0 [ 14.426387][ C0] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 14.426390][ C0] ? rcu_is_watching+0x16/0xd0 [ 14.426391][ C0] handle_softirqs+0x1d3/0x900 [ 14.426393][ C0] ? _local_bh_enable+0xc0/0xc0 [ 14.426395][ C0] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 14.426398][ C0] ? rcu_is_watching+0x16/0xd0 [ 14.426399][ C0] ? rcu_is_watching+0x16/0xd0 [ 14.426400][ C0] run_ksoftirqd+0x39/0x60 [ 14.426402][ C0] smpboot_thread_fn+0x2fb/0x9b0 [ 14.426404][ C0] ? sort_range+0x20/0x20 [ 14.426406][ C0] kthread+0x367/0x460 [ 14.426407][ C0] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 14.426408][ C0] ? kthread_affine_preferred+0x4c0/0x4c0 [ 14.426410][ C0] ret_from_fork+0x474/0x6b0 [ 14.426412][ C0] ? arch_exit_to_user_mode_prepare.isra.0+0x120/0x120 [ 14.426414][ C0] ? __switch_to+0x5a3/0xe00 [ 14.426417][ C0] ? kthread_affine_preferred+0x4c0/0x4c0 [ 14.426419][ C0] ret_from_fork_asm+0x11/0x20 [ 14.426422][ C0] [ 14.428188][ T265] iperf3 (265) used greatest stack depth: 23032 bytes left [ 14.536316][ T182] (udev-worker) (182) used greatest stack depth: 22696 bytes left