[ 10.311994][ T195] ip (195) used greatest stack depth: 24152 bytes left [ 10.312012][ T195] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 10.312014][ T195] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 195, name: ip [ 10.312015][ T195] preempt_count: 2, expected: 0 [ 10.312016][ T195] RCU nest depth: 0, expected: 0 [ 10.312017][ T195] locks held by ip/195: 5, last CPU#3: [ 10.312019][ T195] #0: ffffffffa56167b8 (low_water_lock){+.+.}-{3:3}, at: do_exit+0x887/0xdc0 [ 10.312031][ T195] #1: ffffffffa577ddc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 10.312035][ T195] #2: ffffffffa577de38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 10.312040][ T195] #3: ffffffffa569d760 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 10.312043][ T195] #4: ffffffffa569d660 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x1df/0x4c0 [ 10.312047][ T195] irq event stamp: 31888 [ 10.312048][ T195] hardirqs last enabled at (31887): [] __down_trylock_console_sem+0x86/0xa0 [ 10.312051][ T195] hardirqs last disabled at (31888): [] console_emit_next_record+0x3d4/0x4c0 [ 10.312053][ T195] softirqs last enabled at (30616): [] handle_softirqs+0x67c/0x900 [ 10.312055][ T195] softirqs last disabled at (30611): [] __irq_exit_rcu+0x145/0x1c0 [ 10.312058][ T195] Preemption disabled at: [ 10.312058][ T195] [<0000000000000000>] 0x0 [ 10.312065][ T195] CPU: 3 UID: 0 PID: 195 Comm: ip Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 10.312068][ T195] Tainted: [W]=WARN [ 10.312069][ T195] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 10.312071][ T195] Call Trace: [ 10.312072][ T195] [ 10.312074][ T195] dump_stack_lvl+0x6f/0xa0 [ 10.312080][ T195] __might_resched.cold+0x1fe/0x2c1 [ 10.312084][ T195] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 10.312088][ T195] ? __kmalloc_noprof+0xdb/0x760 [ 10.312092][ T195] __kmalloc_noprof+0x443/0x760 [ 10.312094][ T195] ? alloc_buf.isra.0+0x4b/0x260 [ 10.312101][ T195] ? do_raw_spin_unlock+0x59/0x250 [ 10.312104][ T195] alloc_buf.isra.0+0x4b/0x260 [ 10.312107][ T195] put_chars+0x1e1/0x2f0 [ 10.312110][ T195] ? __send_to_port+0x420/0x420 [ 10.312111][ T195] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 10.312114][ T195] ? validate_chain+0x38b/0xc20 [ 10.312120][ T195] hvc_console_print+0x292/0x780 [ 10.312127][ T195] ? hvc_write+0x3a0/0x3a0 [ 10.312130][ T195] ? rcu_is_watching+0x16/0xd0 [ 10.312132][ T195] ? lock_acquire+0x13c/0x160 [ 10.312136][ T195] console_emit_next_record+0x22f/0x4c0 [ 10.312139][ T195] ? devkmsg_read+0x4b0/0x4b0 [ 10.312141][ T195] ? console_flush_one_record+0x106/0x710 [ 10.312144][ T195] ? rcu_is_watching+0x16/0xd0 [ 10.312146][ T195] ? lock_acquire+0x13c/0x160 [ 10.312150][ T195] console_flush_one_record+0x46f/0x710 [ 10.312154][ T195] ? console_emit_next_record+0x4c0/0x4c0 [ 10.312156][ T195] ? __lock_acquire+0x518/0xc20 [ 10.312161][ T195] console_unlock+0xee/0x1f0 [ 10.312164][ T195] ? console_flush_one_record+0x710/0x710 [ 10.312165][ T195] ? rcu_is_watching+0x16/0xd0 [ 10.312167][ T195] ? lock_acquire+0xe0/0x160 [ 10.312171][ T195] ? __down_trylock_console_sem+0x5e/0xa0 [ 10.312172][ T195] ? vprintk_emit+0x320/0x3e0 [ 10.312175][ T195] vprintk_emit+0x37c/0x3e0 [ 10.312178][ T195] ? wake_up_klogd_work_func+0x90/0x90 [ 10.312181][ T195] ? __lock_acquire+0x518/0xc20 [ 10.312184][ T195] _printk+0xc7/0x100 [ 10.312188][ T195] ? snapshot_read.cold+0x21/0x21 [ 10.312190][ T195] ? do_raw_spin_lock+0x131/0x280 [ 10.312193][ T195] ? __rwlock_init+0x150/0x150 [ 10.312197][ T195] ? do_raw_spin_lock+0x131/0x280 [ 10.312199][ T195] do_exit.cold+0x82/0x9c [ 10.312203][ T195] ? exit_notify+0x890/0x890 [ 10.312204][ T195] ? __lock_release.isra.0+0x69/0x1a0 [ 10.312207][ T195] ? rcu_is_watching+0x16/0xd0 [ 10.312210][ T195] do_group_exit+0xb8/0x370 [ 10.312213][ T195] __x64_sys_exit_group+0x3c/0x50 [ 10.312215][ T195] x64_sys_call+0x1567/0x1570 [ 10.312218][ T195] do_syscall_64+0xff/0x530 [ 10.312221][ T195] ? exc_page_fault+0xee/0x100 [ 10.312224][ T195] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 10.312227][ T195] RIP: 0033:0x7f4002fc61b8 [ 10.312229][ T195] Code: Unable to access opcode bytes at 0x7f4002fc618e. [ 10.312230][ T195] RSP: 002b:00007ffc950f36a8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7 [ 10.312232][ T195] RAX: ffffffffffffffda RBX: 00007f40030f6f88 RCX: 00007f4002fc61b8 [ 10.312233][ T195] RDX: 00007f4002d10fc8 RSI: fffffffffffffeb8 RDI: 0000000000000000 [ 10.312234][ T195] RBP: 00007ffc950f3700 R08: 0000000000000000 R09: 0000000000000050 [ 10.312235][ T195] R10: 00007ffc950f34c0 R11: 0000000000000246 R12: 0000000000000001 [ 10.312236][ T195] R13: 0000000000000000 R14: 00007f40030f5680 R15: 00007f40030f6fa0 [ 10.312242][ T195] [ 13.863990][ T214] ip (214) used greatest stack depth: 23936 bytes left [ 13.864008][ T214] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 13.864010][ T214] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 214, name: ip [ 13.864012][ T214] preempt_count: 2, expected: 0 [ 13.864014][ T214] RCU nest depth: 0, expected: 0 [ 13.864015][ T214] locks held by ip/214: 5, last CPU#1: [ 13.864017][ T214] #0: ffffffffa56167b8 (low_water_lock){+.+.}-{3:3}, at: do_exit+0x887/0xdc0 [ 13.864030][ T214] #1: ffffffffa577ddc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 13.864037][ T214] #2: ffffffffa577de38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 13.864043][ T214] #3: ffffffffa569d760 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 13.864048][ T214] #4: ffffffffa569d660 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x1df/0x4c0 [ 13.864053][ T214] irq event stamp: 19958 [ 13.864054][ T214] hardirqs last enabled at (19957): [] __down_trylock_console_sem+0x86/0xa0 [ 13.864058][ T214] hardirqs last disabled at (19958): [] console_emit_next_record+0x3d4/0x4c0 [ 13.864061][ T214] softirqs last enabled at (19782): [] handle_softirqs+0x67c/0x900 [ 13.864064][ T214] softirqs last disabled at (19777): [] __irq_exit_rcu+0x145/0x1c0 [ 13.864067][ T214] Preemption disabled at: [ 13.864068][ T214] [<0000000000000000>] 0x0 [ 13.864076][ T214] CPU: 1 UID: 0 PID: 214 Comm: ip Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 13.864080][ T214] Tainted: [W]=WARN [ 13.864081][ T214] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 13.864083][ T214] Call Trace: [ 13.864085][ T214] [ 13.864087][ T214] dump_stack_lvl+0x6f/0xa0 [ 13.864095][ T214] __might_resched.cold+0x1fe/0x2c1 [ 13.864100][ T214] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 13.864106][ T214] ? __kmalloc_noprof+0xdb/0x760 [ 13.864112][ T214] __kmalloc_noprof+0x443/0x760 [ 13.864114][ T214] ? alloc_buf.isra.0+0x4b/0x260 [ 13.864123][ T214] ? do_raw_spin_unlock+0x59/0x250 [ 13.864127][ T214] alloc_buf.isra.0+0x4b/0x260 [ 13.864132][ T214] put_chars+0x1e1/0x2f0 [ 13.864135][ T214] ? __send_to_port+0x420/0x420 [ 13.864137][ T214] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 13.864142][ T214] ? validate_chain+0x38b/0xc20 [ 13.864150][ T214] hvc_console_print+0x292/0x780 [ 13.864161][ T214] ? hvc_write+0x3a0/0x3a0 [ 13.864165][ T214] ? rcu_is_watching+0x16/0xd0 [ 13.864168][ T214] ? lock_acquire+0x13c/0x160 [ 13.864174][ T214] console_emit_next_record+0x22f/0x4c0 [ 13.864179][ T214] ? devkmsg_read+0x4b0/0x4b0 [ 13.864182][ T214] ? console_flush_one_record+0x106/0x710 [ 13.864186][ T214] ? rcu_is_watching+0x16/0xd0 [ 13.864189][ T214] ? lock_acquire+0x13c/0x160 [ 13.864195][ T214] console_flush_one_record+0x46f/0x710 [ 13.864201][ T214] ? console_emit_next_record+0x4c0/0x4c0 [ 13.864204][ T214] ? __lock_acquire+0x518/0xc20 [ 13.864212][ T214] console_unlock+0xee/0x1f0 [ 13.864216][ T214] ? console_flush_one_record+0x710/0x710 [ 13.864218][ T214] ? rcu_is_watching+0x16/0xd0 [ 13.864221][ T214] ? lock_acquire+0xe0/0x160 [ 13.864226][ T214] ? __down_trylock_console_sem+0x5e/0xa0 [ 13.864229][ T214] ? vprintk_emit+0x320/0x3e0 [ 13.864233][ T214] vprintk_emit+0x37c/0x3e0 [ 13.864238][ T214] ? wake_up_klogd_work_func+0x90/0x90 [ 13.864242][ T214] ? __lock_acquire+0x518/0xc20 [ 13.864248][ T214] _printk+0xc7/0x100 [ 13.864252][ T214] ? snapshot_read.cold+0x21/0x21 [ 13.864256][ T214] ? do_raw_spin_lock+0x131/0x280 [ 13.864260][ T214] ? __rwlock_init+0x150/0x150 [ 13.864266][ T214] ? do_raw_spin_lock+0x131/0x280 [ 13.864270][ T214] do_exit.cold+0x82/0x9c [ 13.864275][ T214] ? exit_notify+0x890/0x890 [ 13.864277][ T214] ? __lock_release.isra.0+0x69/0x1a0 [ 13.864281][ T214] ? rcu_is_watching+0x16/0xd0 [ 13.864286][ T214] do_group_exit+0xb8/0x370 [ 13.864291][ T214] __x64_sys_exit_group+0x3c/0x50 [ 13.864293][ T214] x64_sys_call+0x1567/0x1570 [ 13.864296][ T214] do_syscall_64+0xff/0x530 [ 13.864301][ T214] ? exc_page_fault+0xee/0x100 [ 13.864305][ T214] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 13.864308][ T214] RIP: 0033:0x7efcc62381b8 [ 13.864311][ T214] Code: Unable to access opcode bytes at 0x7efcc623818e. [ 13.864312][ T214] RSP: 002b:00007ffdb7dbbaa8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7 [ 13.864315][ T214] RAX: ffffffffffffffda RBX: 00007efcc6368f88 RCX: 00007efcc62381b8 [ 13.864317][ T214] RDX: 00007efcc5f82fc8 RSI: fffffffffffffeb8 RDI: 0000000000000000 [ 13.864318][ T214] RBP: 00007ffdb7dbbb00 R08: 0000000000000000 R09: 0000000000000050 [ 13.864319][ T214] R10: 00007ffdb7dbb8c0 R11: 0000000000000246 R12: 0000000000000001 [ 13.864320][ T214] R13: 0000000000000000 R14: 00007efcc6367680 R15: 00007efcc6368fa0 [ 13.864331][ T214] [ 64.017576][ C0] clocksource: Watchdog remote CPU 2 read timed out [ 64.019257][ C0] [ 64.019259][ C0] ======================================================== [ 64.019260][ C0] WARNING: possible irq lock inversion dependency detected [ 64.019263][ C0] 7.2.0-virtme #1 Tainted: G W [ 64.019264][ C0] -------------------------------------------------------- [ 64.019265][ C0] udpgso_bench_tx/414 just changed the state of lock: [ 64.019266][ C0] ffffffffa569d760 (console_owner){..-.}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 64.019279][ C0] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 64.019280][ C0] (fs_reclaim){+.+.}-{0:0} [ 64.019281][ C0] [ 64.019281][ C0] [ 64.019281][ C0] and interrupts could create inverse lock ordering between them. [ 64.019281][ C0] [ 64.019282][ C0] [ 64.019282][ C0] other info that might help us debug this: [ 64.019283][ C0] Possible interrupt unsafe locking scenario: [ 64.019283][ C0] [ 64.019284][ C0] CPU0 CPU1 [ 64.019284][ C0] ---- ---- [ 64.019284][ C0] lock(fs_reclaim); [ 64.019285][ C0] local_irq_disable(); [ 64.019286][ C0] lock(console_owner); [ 64.019287][ C0] lock(fs_reclaim); [ 64.019287][ C0] [ 64.019288][ C0] lock(console_owner); [ 64.019289][ C0] [ 64.019289][ C0] *** DEADLOCK *** [ 64.019289][ C0] [ 64.019289][ C0] locks held by udpgso_bench_tx/414: 6, last CPU#0: [ 64.019290][ C0] #0: ffffffffa5794c00 (rcu_read_lock){....}-{1:3}, at: ip6_send_skb+0xa2/0x350 [ 64.019297][ C0] #1: ffffffffa5794c00 (rcu_read_lock){....}-{1:3}, at: ip6_output+0x11d/0x7f0 [ 64.019300][ C0] #2: ffa0000000007ca8 ((&watchdog_timer)){+.-.}-{0:0}, at: call_timer_fn+0x110/0x4d0 [ 64.019305][ C0] #3: ffffffffa57e29f8 (watchdog_lock){+.-.}-{3:3}, at: clocksource_watchdog+0x15/0x30 [ 64.019308][ C0] #4: ffffffffa577ddc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 64.019311][ C0] #5: ffffffffa577de38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 64.019314][ C0] [ 64.019314][ C0] the shortest dependencies between 2nd lock and 1st lock: [ 64.019318][ C0] -> (fs_reclaim){+.+.}-{0:0} { [ 64.019321][ C0] HARDIRQ-ON-W at: [ 64.019322][ C0] __lock_acquire+0x388/0xc20 [ 64.019326][ C0] lock_acquire.part.0+0xd4/0x280 [ 64.019327][ C0] fs_reclaim_acquire+0xd5/0x120 [ 64.019331][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 64.019333][ C0] kthread_create_worker_on_node+0xea/0x210 [ 64.019336][ C0] workqueue_init+0x2a/0x680 [ 64.019340][ C0] kernel_init_freeable+0x2fe/0x630 [ 64.019343][ C0] kernel_init+0x21/0x150 [ 64.019346][ C0] ret_from_fork+0x474/0x6b0 [ 64.019349][ C0] ret_from_fork_asm+0x11/0x20 [ 64.019352][ C0] SOFTIRQ-ON-W at: [ 64.019353][ C0] __lock_acquire+0x388/0xc20 [ 64.019355][ C0] lock_acquire.part.0+0xd4/0x280 [ 64.019356][ C0] fs_reclaim_acquire+0xd5/0x120 [ 64.019357][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 64.019358][ C0] kthread_create_worker_on_node+0xea/0x210 [ 64.019360][ C0] workqueue_init+0x2a/0x680 [ 64.019361][ C0] kernel_init_freeable+0x2fe/0x630 [ 64.019363][ C0] kernel_init+0x21/0x150 [ 64.019364][ C0] ret_from_fork+0x474/0x6b0 [ 64.019365][ C0] ret_from_fork_asm+0x11/0x20 [ 64.019366][ C0] INITIAL USE at: [ 64.019367][ C0] __lock_acquire+0x388/0xc20 [ 64.019369][ C0] lock_acquire.part.0+0xd4/0x280 [ 64.019370][ C0] fs_reclaim_acquire+0xd5/0x120 [ 64.019371][ C0] __kmalloc_cache_noprof+0x6e/0x620 [ 64.019372][ C0] kthread_create_worker_on_node+0xea/0x210 [ 64.019374][ C0] workqueue_init+0x2a/0x680 [ 64.019375][ C0] kernel_init_freeable+0x2fe/0x630 [ 64.019377][ C0] kernel_init+0x21/0x150 [ 64.019378][ C0] ret_from_fork+0x474/0x6b0 [ 64.019379][ C0] ret_from_fork_asm+0x11/0x20 [ 64.019380][ C0] } [ 64.019381][ C0] ... key at: [] __fs_reclaim_map+0x0/0xbe0 [ 64.019385][ C0] ... acquired at: [ 64.019386][ C0] __lock_acquire+0x518/0xc20 [ 64.019387][ C0] lock_acquire.part.0+0xd4/0x280 [ 64.019388][ C0] fs_reclaim_acquire+0xd5/0x120 [ 64.019390][ C0] __kmalloc_noprof+0xd3/0x760 [ 64.019391][ C0] alloc_buf.isra.0+0x4b/0x260 [ 64.019394][ C0] put_chars+0x1e1/0x2f0 [ 64.019395][ C0] hvc_console_print+0x292/0x780 [ 64.019399][ C0] console_emit_next_record+0x22f/0x4c0 [ 64.019401][ C0] console_flush_one_record+0x46f/0x710 [ 64.019402][ C0] console_unlock+0xee/0x1f0 [ 64.019404][ C0] vprintk_emit+0x37c/0x3e0 [ 64.019405][ C0] _printk+0xc7/0x100 [ 64.019408][ C0] i8042_pnp_init+0xf7/0x3c0 [ 64.019410][ C0] i8042_platform_init+0x3f9/0x460 [ 64.019412][ C0] i8042_init+0x45/0x130 [ 64.019413][ C0] do_one_initcall+0x124/0x4f0 [ 64.019414][ C0] kernel_init_freeable+0x596/0x630 [ 64.019416][ C0] kernel_init+0x21/0x150 [ 64.019417][ C0] ret_from_fork+0x474/0x6b0 [ 64.019418][ C0] ret_from_fork_asm+0x11/0x20 [ 64.019420][ C0] [ 64.019420][ C0] -> (console_owner){..-.}-{0:0} { [ 64.019422][ C0] IN-SOFTIRQ-W at: [ 64.019422][ C0] __lock_acquire+0x388/0xc20 [ 64.019424][ C0] lock_acquire.part.0+0xd4/0x280 [ 64.019425][ C0] console_lock_spinning_enable+0x5c/0x60 [ 64.019427][ C0] console_emit_next_record+0x1d1/0x4c0 [ 64.019428][ C0] console_flush_one_record+0x46f/0x710 [ 64.019430][ C0] console_unlock+0xee/0x1f0 [ 64.019432][ C0] vprintk_emit+0x37c/0x3e0 [ 64.019432][ C0] _printk+0xc7/0x100 [ 64.019434][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 64.019436][ C0] call_timer_fn+0x160/0x4d0 [ 64.019438][ C0] __run_timers+0x68f/0xaa0 [ 64.019439][ C0] run_timer_softirq+0xf0/0x160 [ 64.019441][ C0] handle_softirqs+0x1d3/0x900 [ 64.019444][ C0] do_softirq+0xac/0xe0 [ 64.019445][ C0] __local_bh_enable_ip+0x118/0x150 [ 64.019446][ C0] __dev_queue_xmit+0x989/0x1b90 [ 64.019450][ C0] ip6_finish_output2+0x9e0/0x13f0 [ 64.019451][ C0] ip6_finish_output+0x701/0xe80 [ 64.019453][ C0] ip6_output+0x23f/0x7f0 [ 64.019454][ C0] ip6_send_skb+0xee/0x350 [ 64.019456][ C0] udp_v6_send_skb+0x6ee/0x1630 [ 64.019458][ C0] udpv6_sendmsg+0x1d13/0x2860 [ 64.019460][ C0] __sock_sendmsg+0xce/0x190 [ 64.019462][ C0] __sys_sendto+0x260/0x320 [ 64.019464][ C0] __x64_sys_sendto+0xe4/0x1f0 [ 64.019465][ C0] do_syscall_64+0xff/0x530 [ 64.019468][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 64.019469][ C0] INITIAL USE at: [ 64.019470][ C0] } [ 64.019471][ C0] ... key at: [] console_owner_dep_map+0x0/0x60 [ 64.019473][ C0] ... acquired at: [ 64.019474][ C0] mark_lock+0x1d7/0xa00 [ 64.019475][ C0] mark_usage+0x42/0x170 [ 64.019476][ C0] __lock_acquire+0x388/0xc20 [ 64.019478][ C0] lock_acquire.part.0+0xd4/0x280 [ 64.019479][ C0] console_lock_spinning_enable+0x5c/0x60 [ 64.019480][ C0] console_emit_next_record+0x1d1/0x4c0 [ 64.019482][ C0] console_flush_one_record+0x46f/0x710 [ 64.019484][ C0] console_unlock+0xee/0x1f0 [ 64.019485][ C0] vprintk_emit+0x37c/0x3e0 [ 64.019486][ C0] _printk+0xc7/0x100 [ 64.019487][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 64.019488][ C0] call_timer_fn+0x160/0x4d0 [ 64.019490][ C0] __run_timers+0x68f/0xaa0 [ 64.019491][ C0] run_timer_softirq+0xf0/0x160 [ 64.019493][ C0] handle_softirqs+0x1d3/0x900 [ 64.019494][ C0] do_softirq+0xac/0xe0 [ 64.019495][ C0] __local_bh_enable_ip+0x118/0x150 [ 64.019496][ C0] __dev_queue_xmit+0x989/0x1b90 [ 64.019498][ C0] ip6_finish_output2+0x9e0/0x13f0 [ 64.019499][ C0] ip6_finish_output+0x701/0xe80 [ 64.019501][ C0] ip6_output+0x23f/0x7f0 [ 64.019502][ C0] ip6_send_skb+0xee/0x350 [ 64.019504][ C0] udp_v6_send_skb+0x6ee/0x1630 [ 64.019505][ C0] udpv6_sendmsg+0x1d13/0x2860 [ 64.019507][ C0] __sock_sendmsg+0xce/0x190 [ 64.019508][ C0] __sys_sendto+0x260/0x320 [ 64.019509][ C0] __x64_sys_sendto+0xe4/0x1f0 [ 64.019511][ C0] do_syscall_64+0xff/0x530 [ 64.019512][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 64.019513][ C0] [ 64.019513][ C0] [ 64.019513][ C0] stack backtrace: [ 64.019517][ C0] CPU: 0 UID: 0 PID: 414 Comm: udpgso_bench_tx Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 64.019520][ C0] Tainted: [W]=WARN [ 64.019520][ C0] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 64.019523][ C0] Call Trace: [ 64.019524][ C0] [ 64.019525][ C0] dump_stack_lvl+0x6f/0xa0 [ 64.019529][ C0] print_irq_inversion_bug.part.0.cold+0xe6/0x143 [ 64.019532][ C0] mark_lock_irq+0x989/0x9c0 [ 64.019535][ C0] mark_lock+0x1d7/0xa00 [ 64.019537][ C0] mark_usage+0x42/0x170 [ 64.019538][ C0] __lock_acquire+0x388/0xc20 [ 64.019541][ C0] lock_acquire.part.0+0xd4/0x280 [ 64.019542][ C0] ? console_lock_spinning_enable+0x40/0x60 [ 64.019544][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019547][ C0] ? lock_acquire+0x13c/0x160 [ 64.019549][ C0] console_lock_spinning_enable+0x5c/0x60 [ 64.019550][ C0] ? console_lock_spinning_enable+0x40/0x60 [ 64.019552][ C0] console_emit_next_record+0x1d1/0x4c0 [ 64.019554][ C0] ? devkmsg_read+0x4b0/0x4b0 [ 64.019556][ C0] ? console_flush_one_record+0x106/0x710 [ 64.019558][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019559][ C0] ? lock_acquire+0x13c/0x160 [ 64.019561][ C0] console_flush_one_record+0x46f/0x710 [ 64.019563][ C0] ? console_emit_next_record+0x4c0/0x4c0 [ 64.019565][ C0] ? __lock_acquire+0x518/0xc20 [ 64.019567][ C0] console_unlock+0xee/0x1f0 [ 64.019569][ C0] ? console_flush_one_record+0x710/0x710 [ 64.019571][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019572][ C0] ? lock_acquire+0xe0/0x160 [ 64.019574][ C0] ? __down_trylock_console_sem+0x5e/0xa0 [ 64.019576][ C0] ? vprintk_emit+0x320/0x3e0 [ 64.019577][ C0] vprintk_emit+0x37c/0x3e0 [ 64.019579][ C0] ? wake_up_klogd_work_func+0x90/0x90 [ 64.019581][ C0] ? clocksource_watchdog.part.0+0x450/0x540 [ 64.019582][ C0] _printk+0xc7/0x100 [ 64.019584][ C0] ? snapshot_read.cold+0x21/0x21 [ 64.019586][ C0] ? clocksource_watchdog.part.0+0x450/0x540 [ 64.019587][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019590][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 64.019591][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 64.019593][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 64.019595][ C0] call_timer_fn+0x160/0x4d0 [ 64.019596][ C0] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 64.019598][ C0] ? detach_if_pending+0x1d0/0x1d0 [ 64.019600][ C0] ? find_held_lock+0x2b/0x80 [ 64.019601][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019603][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019605][ C0] __run_timers+0x68f/0xaa0 [ 64.019606][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 64.019609][ C0] ? __bpf_trace_itimer_expire+0x10/0x10 [ 64.019610][ C0] ? __lock_acquire+0x518/0xc20 [ 64.019612][ C0] ? static_obj+0x90/0x90 [ 64.019614][ C0] ? __rwlock_init+0x150/0x150 [ 64.019617][ C0] run_timer_softirq+0xf0/0x160 [ 64.019619][ C0] ? __run_timers+0xaa0/0xaa0 [ 64.019621][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019622][ C0] handle_softirqs+0x1d3/0x900 [ 64.019624][ C0] ? _local_bh_enable+0xc0/0xc0 [ 64.019625][ C0] ? do_raw_spin_unlock+0x59/0x250 [ 64.019627][ C0] ? _raw_spin_unlock+0x2d/0x50 [ 64.019629][ C0] ? __dev_queue_xmit+0x974/0x1b90 [ 64.019631][ C0] do_softirq+0xac/0xe0 [ 64.019632][ C0] [ 64.019633][ C0] [ 64.019634][ C0] __local_bh_enable_ip+0x118/0x150 [ 64.019635][ C0] __dev_queue_xmit+0x989/0x1b90 [ 64.019637][ C0] ? __asan_memset+0x27/0x50 [ 64.019641][ C0] ? iov_iter_zero+0x379/0x1a40 [ 64.019644][ C0] ? netdev_core_pick_tx+0x2c0/0x2c0 [ 64.019646][ C0] ? lock_acquire.part.0+0x60/0x280 [ 64.019647][ C0] ? find_held_lock+0x2b/0x80 [ 64.019649][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019650][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019651][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019653][ C0] ? __asan_memcpy+0x3c/0x60 [ 64.019654][ C0] ? neigh_hh_output+0x152/0x4c0 [ 64.019657][ C0] ip6_finish_output2+0x9e0/0x13f0 [ 64.019659][ C0] ? ip6_dst_lookup+0x80/0x80 [ 64.019661][ C0] ? find_held_lock+0x2b/0x80 [ 64.019662][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019664][ C0] ? ip6_mtu+0x174/0x410 [ 64.019667][ C0] ip6_finish_output+0x701/0xe80 [ 64.019669][ C0] ip6_output+0x23f/0x7f0 [ 64.019671][ C0] ? ip6_finish_output+0xe80/0xe80 [ 64.019673][ C0] ? l3mdev_l3_out.constprop.0+0xe5/0x340 [ 64.019677][ C0] ip6_send_skb+0xee/0x350 [ 64.019679][ C0] udp_v6_send_skb+0x6ee/0x1630 [ 64.019681][ C0] udpv6_sendmsg+0x1d13/0x2860 [ 64.019683][ C0] ? __might_fault+0x97/0x140 [ 64.019686][ C0] ? udpv6_splice_eof+0x1a0/0x1a0 [ 64.019688][ C0] ? find_held_lock+0x2b/0x80 [ 64.019690][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019691][ C0] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 64.019694][ C0] ? lockdep_hardirqs_on+0x91/0x130 [ 64.019695][ C0] ? _raw_spin_unlock_irqrestore+0x53/0x80 [ 64.019697][ C0] ? _raw_spin_unlock_irqrestore+0x40/0x80 [ 64.019698][ C0] ? anon_pipe_write+0x871/0x1800 [ 64.019702][ C0] ? kvm_clock_get_cycles+0x19/0x30 [ 64.019704][ C0] ? ktime_get+0x1dd/0x2d0 [ 64.019706][ C0] ? __sock_sendmsg+0xce/0x190 [ 64.019708][ C0] __sock_sendmsg+0xce/0x190 [ 64.019709][ C0] ? fdget+0x4f/0x1e0 [ 64.019712][ C0] __sys_sendto+0x260/0x320 [ 64.019714][ C0] ? __ia32_sys_getpeername+0xd0/0xd0 [ 64.019717][ C0] ? ksys_write+0x1ac/0x250 [ 64.019721][ C0] __x64_sys_sendto+0xe4/0x1f0 [ 64.019722][ C0] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 64.019724][ C0] ? lockdep_hardirqs_on+0x91/0x130 [ 64.019725][ C0] ? do_syscall_64+0xa6/0x530 [ 64.019727][ C0] do_syscall_64+0xff/0x530 [ 64.019728][ C0] ? irq_exit_rcu+0x1a/0x30 [ 64.019730][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 64.019731][ C0] RIP: 0033:0x7f242fa5454e [ 64.019735][ C0] 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 [ 64.019737][ C0] RSP: 002b:00007ffe5b904860 EFLAGS: 00000202 ORIG_RAX: 000000000000002c [ 64.019739][ C0] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f242fa5454e [ 64.019741][ C0] RDX: 00000000000005ac RSI: 0000000000405140 RDI: 0000000000000005 [ 64.019742][ C0] RBP: 00007ffe5b904870 R08: 0000000000000000 R09: 0000000000000000 [ 64.019743][ C0] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000005 [ 64.019743][ C0] R13: 000000000000ebd4 R14: 0000000000405140 R15: 00000000000005ac [ 64.019746][ C0] [ 64.019750][ C0] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 64.019752][ C0] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 414, name: udpgso_bench_tx [ 64.019753][ C0] preempt_count: 103, expected: 0 [ 64.019754][ C0] RCU nest depth: 2, expected: 0 [ 64.019755][ C0] INFO: lockdep is turned off. [ 64.019755][ C0] irq event stamp: 2276621 [ 64.019756][ C0] hardirqs last enabled at (2276620): [] irqentry_exit+0x21c/0x790 [ 64.019758][ C0] hardirqs last disabled at (2276621): [] console_emit_next_record+0x3d4/0x4c0 [ 64.019760][ C0] softirqs last enabled at (2276492): [] __dev_queue_xmit+0x974/0x1b90 [ 64.019762][ C0] softirqs last disabled at (2276493): [] do_softirq+0xac/0xe0 [ 64.019763][ C0] Preemption disabled at: [ 64.019764][ C0] [] __dev_queue_xmit+0x20c/0x1b90 [ 64.019767][ C0] CPU: 0 UID: 0 PID: 414 Comm: udpgso_bench_tx Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 64.019769][ C0] Tainted: [W]=WARN [ 64.019769][ C0] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 64.019770][ C0] Call Trace: [ 64.019770][ C0] [ 64.019771][ C0] dump_stack_lvl+0x6f/0xa0 [ 64.019773][ C0] ? __dev_queue_xmit+0x20c/0x1b90 [ 64.019775][ C0] __might_resched.cold+0x1fe/0x2c1 [ 64.019777][ C0] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 64.019780][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019782][ C0] __kmalloc_noprof+0x443/0x760 [ 64.019783][ C0] ? __rwlock_init+0x150/0x150 [ 64.019784][ C0] ? alloc_buf.isra.0+0x4b/0x260 [ 64.019787][ C0] ? do_raw_spin_unlock+0x59/0x250 [ 64.019788][ C0] alloc_buf.isra.0+0x4b/0x260 [ 64.019791][ C0] put_chars+0x1e1/0x2f0 [ 64.019792][ C0] ? __send_to_port+0x420/0x420 [ 64.019795][ C0] hvc_console_print+0x292/0x780 [ 64.019797][ C0] ? __lock_acquire+0x388/0xc20 [ 64.019799][ C0] ? hvc_write+0x3a0/0x3a0 [ 64.019801][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019802][ C0] ? lock_acquire+0x13c/0x160 [ 64.019804][ C0] console_emit_next_record+0x22f/0x4c0 [ 64.019807][ C0] ? devkmsg_read+0x4b0/0x4b0 [ 64.019808][ C0] ? console_flush_one_record+0x106/0x710 [ 64.019810][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019811][ C0] ? lock_acquire+0x13c/0x160 [ 64.019813][ C0] console_flush_one_record+0x46f/0x710 [ 64.019815][ C0] ? console_emit_next_record+0x4c0/0x4c0 [ 64.019817][ C0] ? __lock_acquire+0x518/0xc20 [ 64.019823][ C0] console_unlock+0xee/0x1f0 [ 64.019825][ C0] ? console_flush_one_record+0x710/0x710 [ 64.019827][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019828][ C0] ? lock_acquire+0xe0/0x160 [ 64.019830][ C0] ? __down_trylock_console_sem+0x5e/0xa0 [ 64.019832][ C0] ? vprintk_emit+0x320/0x3e0 [ 64.019833][ C0] vprintk_emit+0x37c/0x3e0 [ 64.019835][ C0] ? wake_up_klogd_work_func+0x90/0x90 [ 64.019836][ C0] ? clocksource_watchdog.part.0+0x450/0x540 [ 64.019838][ C0] _printk+0xc7/0x100 [ 64.019840][ C0] ? snapshot_read.cold+0x21/0x21 [ 64.019841][ C0] ? clocksource_watchdog.part.0+0x450/0x540 [ 64.019843][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019845][ C0] clocksource_watchdog.part.0.cold+0x105/0x1dd [ 64.019847][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 64.019848][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 64.019850][ C0] call_timer_fn+0x160/0x4d0 [ 64.019852][ C0] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 64.019853][ C0] ? detach_if_pending+0x1d0/0x1d0 [ 64.019855][ C0] ? find_held_lock+0x2b/0x80 [ 64.019856][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019858][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019859][ C0] __run_timers+0x68f/0xaa0 [ 64.019861][ C0] ? clocksource_watchdog.part.0+0x540/0x540 [ 64.019863][ C0] ? __bpf_trace_itimer_expire+0x10/0x10 [ 64.019865][ C0] ? __lock_acquire+0x518/0xc20 [ 64.019867][ C0] ? static_obj+0x90/0x90 [ 64.019869][ C0] ? __rwlock_init+0x150/0x150 [ 64.019871][ C0] run_timer_softirq+0xf0/0x160 [ 64.019873][ C0] ? __run_timers+0xaa0/0xaa0 [ 64.019875][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019876][ C0] handle_softirqs+0x1d3/0x900 [ 64.019878][ C0] ? _local_bh_enable+0xc0/0xc0 [ 64.019879][ C0] ? do_raw_spin_unlock+0x59/0x250 [ 64.019881][ C0] ? _raw_spin_unlock+0x2d/0x50 [ 64.019882][ C0] ? __dev_queue_xmit+0x974/0x1b90 [ 64.019885][ C0] do_softirq+0xac/0xe0 [ 64.019887][ C0] [ 64.019888][ C0] [ 64.019889][ C0] __local_bh_enable_ip+0x118/0x150 [ 64.019891][ C0] __dev_queue_xmit+0x989/0x1b90 [ 64.019894][ C0] ? __asan_memset+0x27/0x50 [ 64.019897][ C0] ? iov_iter_zero+0x379/0x1a40 [ 64.019899][ C0] ? netdev_core_pick_tx+0x2c0/0x2c0 [ 64.019902][ C0] ? lock_acquire.part.0+0x60/0x280 [ 64.019904][ C0] ? find_held_lock+0x2b/0x80 [ 64.019906][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019909][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019910][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019912][ C0] ? __asan_memcpy+0x3c/0x60 [ 64.019915][ C0] ? neigh_hh_output+0x152/0x4c0 [ 64.019918][ C0] ip6_finish_output2+0x9e0/0x13f0 [ 64.019922][ C0] ? ip6_dst_lookup+0x80/0x80 [ 64.019924][ C0] ? find_held_lock+0x2b/0x80 [ 64.019927][ C0] ? __lock_release.isra.0+0x69/0x1a0 [ 64.019930][ C0] ? ip6_mtu+0x174/0x410 [ 64.019933][ C0] ip6_finish_output+0x701/0xe80 [ 64.019935][ C0] ip6_output+0x23f/0x7f0 [ 64.019937][ C0] ? ip6_finish_output+0xe80/0xe80 [ 64.019939][ C0] ? l3mdev_l3_out.constprop.0+0xe5/0x340 [ 64.019942][ C0] ip6_send_skb+0xee/0x350 [ 64.019944][ C0] udp_v6_send_skb+0x6ee/0x1630 [ 64.019947][ C0] udpv6_sendmsg+0x1d13/0x2860 [ 64.019949][ C0] ? __might_fault+0x97/0x140 [ 64.019950][ C0] ? udpv6_splice_eof+0x1a0/0x1a0 [ 64.019953][ C0] ? find_held_lock+0x2b/0x80 [ 64.019955][ C0] ? rcu_is_watching+0x16/0xd0 [ 64.019956][ C0] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 64.019957][ C0] ? lockdep_hardirqs_on+0x91/0x130 [ 64.019959][ C0] ? _raw_spin_unlock_irqrestore+0x53/0x80 [ 64.019960][ C0] ? _raw_spin_unlock_irqrestore+0x40/0x80 [ 64.019961][ C0] ? anon_pipe_write+0x871/0x1800 [ 64.019964][ C0] ? kvm_clock_get_cycles+0x19/0x30 [ 64.019965][ C0] ? ktime_get+0x1dd/0x2d0 [ 64.019967][ C0] ? __sock_sendmsg+0xce/0x190 [ 64.019969][ C0] __sock_sendmsg+0xce/0x190 [ 64.019970][ C0] ? fdget+0x4f/0x1e0 [ 64.019972][ C0] __sys_sendto+0x260/0x320 [ 64.019974][ C0] ? __ia32_sys_getpeername+0xd0/0xd0 [ 64.019977][ C0] ? ksys_write+0x1ac/0x250 [ 64.019979][ C0] __x64_sys_sendto+0xe4/0x1f0 [ 64.019981][ C0] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 64.019982][ C0] ? lockdep_hardirqs_on+0x91/0x130 [ 64.019984][ C0] ? do_syscall_64+0xa6/0x530 [ 64.019985][ C0] do_syscall_64+0xff/0x530 [ 64.019987][ C0] ? irq_exit_rcu+0x1a/0x30 [ 64.019989][ C0] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 64.019990][ C0] RIP: 0033:0x7f242fa5454e [ 64.019991][ C0] 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 [ 64.019992][ C0] RSP: 002b:00007ffe5b904860 EFLAGS: 00000202 ORIG_RAX: 000000000000002c [ 64.019993][ C0] RAX: ffffffffffffffda RBX: 0000000000000001 RCX: 00007f242fa5454e [ 64.019994][ C0] RDX: 00000000000005ac RSI: 0000000000405140 RDI: 0000000000000005 [ 64.019995][ C0] RBP: 00007ffe5b904870 R08: 0000000000000000 R09: 0000000000000000 [ 64.019996][ C0] R10: 0000000000000000 R11: 0000000000000202 R12: 0000000000000005 [ 64.019996][ C0] R13: 000000000000ebd4 R14: 0000000000405140 R15: 00000000000005ac [ 64.019998][ C0]