[ 10.985545][ T242] br1: port 1(veth1) entered blocking state [ 10.985729][ T242] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 10.985732][ T242] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 242, name: ip [ 10.985733][ T242] preempt_count: 1, expected: 0 [ 10.985734][ T242] RCU nest depth: 0, expected: 0 [ 10.985735][ T242] locks held by ip/242: 5, last CPU#3: [ 10.985738][ T242] #0: ffffffffa64d2c40 (rtnl_mutex){+.+.}-{4:4}, at: rtnl_newlink+0x9a8/0x11c0 [ 10.985749][ T242] #1: ffffffffa5d69cc0 (console_lock){+.+.}-{0:0}, at: vprintk_emit+0x320/0x3e0 [ 10.985756][ T242] #2: ffffffffa5d69d38 (console_srcu){....}-{0:0}, at: console_flush_one_record+0x106/0x710 [ 10.985760][ T242] #3: ffffffffa5c89660 (console_owner){....}-{0:0}, at: console_lock_spinning_enable+0x40/0x60 [ 10.985763][ T242] #4: ffffffffa5c89560 (printk_legacy_map-wait-type-override){....}-{3:3}, at: console_emit_next_record+0x1df/0x4c0 [ 10.985767][ T242] irq event stamp: 12140 [ 10.985768][ T242] hardirqs last enabled at (12139): [] irqentry_exit+0x21c/0x790 [ 10.985772][ T242] hardirqs last disabled at (12140): [] console_emit_next_record+0x3d4/0x4c0 [ 10.985774][ T242] softirqs last enabled at (12048): [] __alloc_skb+0x4c2/0x5f0 [ 10.985777][ T242] softirqs last disabled at (12046): [] __alloc_skb+0x4c2/0x5f0 [ 10.985780][ T242] Preemption disabled at: [ 10.985781][ T242] [] vprintk_emit+0x31b/0x3e0 [ 10.985786][ T242] CPU: 3 UID: 0 PID: 242 Comm: ip Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 10.985790][ T242] Tainted: [W]=WARN [ 10.985791][ T242] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 10.985792][ T242] Call Trace: [ 10.985794][ T242] [ 10.985795][ T242] dump_stack_lvl+0x6f/0xa0 [ 10.985801][ T242] ? vprintk_emit+0x31b/0x3e0 [ 10.985803][ T242] __might_resched.cold+0x1fe/0x2c1 [ 10.985808][ T242] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 10.985812][ T242] ? __kmalloc_noprof+0xdb/0x760 [ 10.985818][ T242] __kmalloc_noprof+0x443/0x760 [ 10.985820][ T242] ? alloc_buf.isra.0+0x4b/0x260 [ 10.985825][ T242] ? do_raw_spin_unlock+0x59/0x250 [ 10.985828][ T242] alloc_buf.isra.0+0x4b/0x260 [ 10.985831][ T242] put_chars+0x1e1/0x2f0 [ 10.985834][ T242] ? __send_to_port+0x420/0x420 [ 10.985838][ T242] ? validate_chain+0x34a/0xc20 [ 10.985842][ T242] hvc_console_print+0x292/0x780 [ 10.985845][ T242] ? mark_usage+0x61/0x170 [ 10.985847][ T242] ? __lock_acquire+0x518/0xc20 [ 10.985849][ T242] ? __lock_acquire+0x518/0xc20 [ 10.985853][ T242] ? hvc_write+0x3a0/0x3a0 [ 10.985855][ T242] ? console_emit_next_record+0x1df/0x4c0 [ 10.985858][ T242] ? rcu_is_watching+0x16/0xd0 [ 10.985862][ T242] ? lock_acquire+0x13c/0x160 [ 10.985866][ T242] console_emit_next_record+0x22f/0x4c0 [ 10.985870][ T242] ? devkmsg_read+0x4b0/0x4b0 [ 10.985873][ T242] ? console_flush_one_record+0x272/0x710 [ 10.985878][ T242] console_flush_one_record+0x46f/0x710 [ 10.985882][ T242] ? console_emit_next_record+0x4c0/0x4c0 [ 10.985884][ T242] ? __lock_acquire+0x518/0xc20 [ 10.985889][ T242] console_unlock+0xee/0x1f0 [ 10.985892][ T242] ? console_flush_one_record+0x710/0x710 [ 10.985894][ T242] ? rcu_is_watching+0x16/0xd0 [ 10.985897][ T242] ? lock_acquire+0x60/0x160 [ 10.985900][ T242] ? __down_trylock_console_sem+0x5e/0xa0 [ 10.985902][ T242] ? vprintk_emit+0x320/0x3e0 [ 10.985906][ T242] vprintk_emit+0x37c/0x3e0 [ 10.985909][ T242] ? wake_up_klogd_work_func+0x90/0x90 [ 10.985912][ T242] ? __lock_release.isra.0+0x69/0x1a0 [ 10.985914][ T242] ? _raw_spin_unlock_irqrestore+0x40/0x80 [ 10.985917][ T242] ? mark_held_locks+0x40/0x70 [ 10.985921][ T242] _printk+0xc7/0x100 [ 10.985924][ T242] ? snapshot_read.cold+0x21/0x21 [ 10.985928][ T242] ? br_multicast_flood+0xab0/0xab0 [bridge] [ 10.985941][ T242] ? do_setlink.isra.0+0xa31/0x2750 [ 10.985942][ T242] ? rtnl_newlink+0x9f1/0x11c0 [ 10.985943][ T242] ? rtnetlink_rcv_msg+0x6fd/0xbd0 [ 10.985948][ T242] br_set_state+0x22f/0x430 [bridge] [ 10.985958][ T242] br_init_port+0xc4/0x200 [bridge] [ 10.985966][ T242] new_nbp+0x39c/0x580 [bridge] [ 10.985976][ T242] br_add_if+0x212/0x1320 [bridge] [ 10.985983][ T242] ? is_bpf_text_address+0x72/0x110 [ 10.985987][ T242] ? kernel_text_address+0x149/0x170 [ 10.985990][ T242] ? __kernel_text_address+0x12/0x30 [ 10.985994][ T242] do_set_master+0x357/0x580 [ 10.985998][ T242] do_setlink.isra.0+0xa31/0x2750 [ 10.986002][ T242] ? stack_trace_save+0x93/0xc0 [ 10.986005][ T242] ? rtnl_link_get_size+0x350/0x350 [ 10.986006][ T242] ? rcu_read_lock_any_held+0x66/0x90 [ 10.986009][ T242] ? stack_depot_save_flags+0x38e/0x790 [ 10.986013][ T242] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 10.986015][ T242] ? rcu_read_lock_any_held+0x3c/0x90 [ 10.986017][ T242] ? validate_chain+0x38b/0xc20 [ 10.986020][ T242] ? kasan_save_stack+0x3d/0x50 [ 10.986023][ T242] ? kasan_save_stack+0x2f/0x50 [ 10.986024][ T242] ? kasan_save_track+0x14/0x30 [ 10.986027][ T242] ? __lock_acquire+0x518/0xc20 [ 10.986029][ T242] ? netlink_seq_next+0xe/0x60 [ 10.986032][ T242] ? ___sys_sendmsg+0xb0/0x1d0 [ 10.986036][ T242] ? lock_acquire.part.0+0xd4/0x280 [ 10.986038][ T242] ? rtnl_newlink+0x9a8/0x11c0 [ 10.986041][ T242] ? rcu_is_watching+0x16/0xd0 [ 10.986043][ T242] ? lock_acquire+0x13c/0x160 [ 10.986045][ T242] ? rcu_is_watching+0x16/0xd0 [ 10.986047][ T242] ? rcu_is_watching+0x16/0xd0 [ 10.986049][ T242] ? trace_contention_end+0xb3/0x180 [ 10.986053][ T242] ? __mutex_lock+0x1db/0x1ea0 [ 10.986055][ T242] ? __mutex_lock+0x9a3/0x1ea0 [ 10.986057][ T242] ? rtnl_newlink+0x9a8/0x11c0 [ 10.986060][ T242] ? ww_mutex_lock+0x160/0x160 [ 10.986062][ T242] ? nla_get_range_signed+0x3d0/0x3d0 [ 10.986067][ T242] ? __rtnl_newlink+0x3fa/0xa50 [ 10.986072][ T242] rtnl_newlink+0x9f1/0x11c0 [ 10.986078][ T242] ? rtnl_bridge_getlink+0x850/0x850 [ 10.986080][ T242] ? __lock_acquire+0x518/0xc20 [ 10.986084][ T242] ? lock_acquire.part.0+0xd4/0x280 [ 10.986086][ T242] ? find_held_lock+0x2b/0x80 [ 10.986088][ T242] ? rtnl_bridge_getlink+0x850/0x850 [ 10.986090][ T242] ? __lock_release.isra.0+0x69/0x1a0 [ 10.986093][ T242] ? rtnl_bridge_getlink+0x850/0x850 [ 10.986095][ T242] rtnetlink_rcv_msg+0x6fd/0xbd0 [ 10.986099][ T242] ? rtnl_link_fill+0x920/0x920 [ 10.986100][ T242] ? __lock_acquire+0x518/0xc20 [ 10.986104][ T242] ? lock_acquire.part.0+0xd4/0x280 [ 10.986106][ T242] ? find_held_lock+0x2b/0x80 [ 10.986110][ T242] netlink_rcv_skb+0x14e/0x3a0 [ 10.986111][ T242] ? rtnl_link_fill+0x920/0x920 [ 10.986114][ T242] ? netlink_ack+0xcf0/0xcf0 [ 10.986121][ T242] ? netlink_deliver_tap+0xc5/0x330 [ 10.986122][ T242] ? netlink_deliver_tap+0x13c/0x330 [ 10.986126][ T242] netlink_unicast+0x486/0x750 [ 10.986130][ T242] ? netlink_attachskb+0x810/0x810 [ 10.986133][ T242] ? __lock_acquire+0x518/0xc20 [ 10.986137][ T242] netlink_sendmsg+0x735/0xc60 [ 10.986141][ T242] ? netlink_unicast+0x750/0x750 [ 10.986145][ T242] ? __might_fault+0x97/0x140 [ 10.986150][ T242] ____sys_sendmsg+0x415/0x880 [ 10.986152][ T242] ? copy_msghdr_from_user+0x279/0x420 [ 10.986155][ T242] ? get_timestamp.constprop.0+0x390/0x390 [ 10.986156][ T242] ? move_addr_to_kernel+0x40/0x40 [ 10.986164][ T242] ___sys_sendmsg+0x14e/0x1d0 [ 10.986166][ T242] ? copy_msghdr_from_user+0x420/0x420 [ 10.986182][ T242] __sys_sendmsg+0x12c/0x1d0 [ 10.986185][ T242] ? __sys_sendmsg_sock+0x20/0x20 [ 10.986192][ T242] ? rcu_is_watching+0x16/0xd0 [ 10.986195][ T242] do_syscall_64+0xff/0x530 [ 10.986197][ T242] ? exc_page_fault+0xee/0x100 [ 10.986200][ T242] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 10.986202][ T242] RIP: 0033:0x7f1a854ec54e [ 10.986206][ T242] 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 [ 10.986208][ T242] RSP: 002b:00007ffee5ad4db0 EFLAGS: 00000202 ORIG_RAX: 000000000000002e [ 10.986211][ T242] RAX: ffffffffffffffda RBX: 0000000000000004 RCX: 00007f1a854ec54e [ 10.986212][ T242] RDX: 0000000000000000 RSI: 00007ffee5ad4e60 RDI: 0000000000000005 [ 10.986213][ T242] RBP: 00007ffee5ad4dc0 R08: 0000000000000000 R09: 0000000000000000 [ 10.986214][ T242] R10: 0000000000000000 R11: 0000000000000202 R12: 000000006a91ad65 [ 10.986215][ T242] R13: 00000000004a1620 R14: 0000000000000000 R15: 00007ffee5ad5520 [ 10.986222][ T242] [ 11.026677][ T242] br1: port 1(veth1) entered disabled state [ 11.027088][ T242] veth1: entered allmulticast mode [ 11.028712][ T242] veth1: entered promiscuous mode [ 11.044526][ T242] ip (242) used greatest stack depth: 23336 bytes left [ 11.072409][ T101] br1: port 1(veth1) entered blocking state [ 11.073146][ T101] br1: port 1(veth1) entered forwarding state [ 11.103040][ T244] br1: port 2(veth2) entered blocking state [ 11.103360][ T244] br1: port 2(veth2) entered disabled state [ 11.110758][ T244] veth2: entered allmulticast mode [ 11.112297][ T244] veth2: entered promiscuous mode [ 11.139978][ T101] br1: port 2(veth2) entered blocking state [ 11.140301][ T101] br1: port 2(veth2) entered forwarding state [ 26.486651][ C1] [ 26.486670][ C1] BUG: sleeping function called from invalid context at ./include/linux/sched/mm.h:322 [ 26.486673][ C1] in_atomic(): 1, irqs_disabled(): 1, non_block: 0, pid: 0, name: swapper/1 [ 26.486675][ C1] preempt_count: 104, expected: 0 [ 26.486677][ C1] RCU nest depth: 0, expected: 0 [ 26.486678][ C1] INFO: lockdep is turned off. [ 26.486679][ C1] irq event stamp: 876996 [ 26.486680][ C1] hardirqs last enabled at (876996): [] _raw_spin_unlock_irq+0x28/0x50 [ 26.486691][ C1] hardirqs last disabled at (876995): [] _raw_spin_lock_irq+0x4a/0x50 [ 26.486693][ C1] softirqs last enabled at (876980): [] handle_softirqs+0x67c/0x900 [ 26.486698][ C1] softirqs last disabled at (876993): [] __irq_exit_rcu+0x145/0x1c0 [ 26.486701][ C1] Preemption disabled at: [ 26.486702][ C1] [<0000000000000000>] 0x0 [ 26.486710][ C1] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 26.486715][ C1] Tainted: [W]=WARN [ 26.486716][ C1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 26.486719][ C1] Call Trace: [ 26.486721][ C1] [ 26.486723][ C1] dump_stack_lvl+0x6f/0xa0 [ 26.486729][ C1] __might_resched.cold+0x1fe/0x2c1 [ 26.486734][ C1] ? perf_trace_sched_switch+0x7c0/0x7c0 [ 26.486738][ C1] ? __asan_memcpy+0x3c/0x60 [ 26.486742][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.486747][ C1] __kmalloc_noprof+0x443/0x760 [ 26.486751][ C1] ? __rwlock_init+0x150/0x150 [ 26.486754][ C1] ? alloc_buf.isra.0+0x4b/0x260 [ 26.486759][ C1] ? do_raw_spin_unlock+0x59/0x250 [ 26.486761][ C1] alloc_buf.isra.0+0x4b/0x260 [ 26.486765][ C1] put_chars+0x1e1/0x2f0 [ 26.486767][ C1] ? __send_to_port+0x420/0x420 [ 26.486770][ C1] ? console_prepend_replay+0x20/0x20 [ 26.486775][ C1] hvc_console_print+0x292/0x780 [ 26.486780][ C1] ? hvc_write+0x3a0/0x3a0 [ 26.486782][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.486785][ C1] ? lock_acquire+0x13c/0x160 [ 26.486788][ C1] console_emit_next_record+0x22f/0x4c0 [ 26.486792][ C1] ? devkmsg_read+0x4b0/0x4b0 [ 26.486795][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.486797][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.486800][ C1] ? lock_acquire+0x13c/0x160 [ 26.486803][ C1] ? console_flush_one_record+0x111/0x710 [ 26.486806][ C1] console_flush_one_record+0x46f/0x710 [ 26.486809][ C1] ? console_emit_next_record+0x4c0/0x4c0 [ 26.486813][ C1] console_unlock+0xee/0x1f0 [ 26.486816][ C1] ? lock_acquire+0x13c/0x160 [ 26.486818][ C1] ? console_flush_one_record+0x710/0x710 [ 26.486821][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.486823][ C1] ? lock_release+0x184/0x1f0 [ 26.486825][ C1] ? lock_acquire+0x60/0x160 [ 26.486828][ C1] ? __down_trylock_console_sem+0x5e/0xa0 [ 26.486831][ C1] ? vprintk_emit+0x320/0x3e0 [ 26.486834][ C1] vprintk_emit+0x37c/0x3e0 [ 26.486838][ C1] ? wake_up_klogd_work_func+0x90/0x90 [ 26.486841][ C1] ? br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.486858][ C1] ? lock_release+0x184/0x1f0 [ 26.486860][ C1] ? br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.486872][ C1] ? br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.486883][ C1] ? is_module_text_address+0x154/0x250 [ 26.486888][ C1] _printk+0xc7/0x100 [ 26.486892][ C1] ? snapshot_read.cold+0x21/0x21 [ 26.486894][ C1] ? arch_stack_walk+0xd7/0x130 [ 26.486900][ C1] ? rcu_lockdep_current_cpu_online+0x3f/0x1b0 [ 26.486903][ C1] ? nbcon_cpu_emergency_enter+0x28/0x80 [ 26.486906][ C1] print_irq_inversion_bug.part.0+0x32/0xc0 [ 26.486910][ C1] mark_lock_irq+0x989/0x9c0 [ 26.486915][ C1] mark_lock+0x1d7/0xa00 [ 26.486918][ C1] mark_usage+0x42/0x170 [ 26.486920][ C1] __lock_acquire+0x388/0xc20 [ 26.486924][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.486926][ C1] ? br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.486938][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.486940][ C1] ? lock_acquire+0x13c/0x160 [ 26.486943][ C1] ? br_message_age_timer_expired+0x70/0x70 [bridge] [ 26.486955][ C1] _raw_spin_lock+0x33/0x40 [ 26.486957][ C1] ? br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.486968][ C1] br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.486979][ C1] ? br_message_age_timer_expired+0x70/0x70 [bridge] [ 26.486988][ C1] call_timer_fn+0x160/0x4d0 [ 26.486992][ C1] ? detach_if_pending+0x1d0/0x1d0 [ 26.486995][ C1] ? debug_object_active_state+0x430/0x430 [ 26.486999][ C1] ? find_held_lock+0x2b/0x80 [ 26.487003][ C1] ? __lock_release.isra.0+0x69/0x1a0 [ 26.487005][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.487009][ C1] __run_timers+0x68f/0xaa0 [ 26.487012][ C1] ? br_message_age_timer_expired+0x70/0x70 [bridge] [ 26.487022][ C1] ? __bpf_trace_itimer_expire+0x10/0x10 [ 26.487025][ C1] ? __lock_acquire+0x518/0xc20 [ 26.487029][ C1] ? __rwlock_init+0x150/0x150 [ 26.487033][ C1] run_timer_softirq+0xf0/0x160 [ 26.487036][ C1] ? __run_timers+0xaa0/0xaa0 [ 26.487039][ C1] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 26.487042][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.487045][ C1] handle_softirqs+0x1d3/0x900 [ 26.487047][ C1] ? __lock_release.isra.0+0x69/0x1a0 [ 26.487050][ C1] ? _local_bh_enable+0xc0/0xc0 [ 26.487054][ C1] __irq_exit_rcu+0x145/0x1c0 [ 26.487056][ C1] irq_exit_rcu+0xe/0x30 [ 26.487058][ C1] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 26.487061][ C1] [ 26.487062][ C1] [ 26.487063][ C1] ? lockdep_hardirqs_on+0x91/0x130 [ 26.487066][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 26.487069][ C1] RIP: 0010:pv_native_safe_halt+0xf/0x10 [ 26.487072][ C1] Code: 48 8b 3d 94 d2 f5 01 e8 1f 00 00 00 48 2b 05 58 93 95 00 c3 0f 1f 80 00 00 00 00 f3 0f 1e fa eb 07 0f 00 2d 13 86 11 00 fb f4 0f 1f 40 d6 48 83 ec 20 8b 17 49 89 f8 83 e2 fe 41 89 d2 0f 01 [ 26.487074][ C1] RSP: 0018:ffa0000000147e00 EFLAGS: 00000282 [ 26.487078][ C1] RAX: 00000000000d61bf RBX: ff11000001bea380 RCX: ffffffffa2af0307 [ 26.487080][ C1] RDX: ff11000001bea380 RSI: ffffffffa5838af6 RDI: ffffffffa528d8e0 [ 26.487081][ C1] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000 [ 26.487082][ C1] R10: 0000000000000001 R11: 0000000000000001 R12: 1ff4000000028fc3 [ 26.487084][ C1] R13: 0000000000000000 R14: dffffc0000000000 R15: 0000000000000000 [ 26.487086][ C1] ? cpuidle_idle_call.constprop.0+0x237/0x410 [ 26.487091][ C1] default_idle+0x9/0x10 [ 26.487093][ C1] default_idle_call+0x6e/0xb0 [ 26.487096][ C1] cpuidle_idle_call.constprop.0+0x237/0x410 [ 26.487098][ C1] ? arch_cpu_idle_exit+0x40/0x40 [ 26.487101][ C1] ? mark_tsc_async_resets+0x30/0x30 [ 26.487104][ C1] ? default_idle_call+0x98/0xb0 [ 26.487106][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.487110][ C1] do_idle+0xd8/0x190 [ 26.487112][ C1] cpu_startup_entry+0x53/0x70 [ 26.487114][ C1] start_secondary+0x204/0x2b0 [ 26.487117][ C1] ? set_cpu_sibling_map+0x2130/0x2130 [ 26.487121][ C1] common_startup_64+0x13e/0x148 [ 26.487127][ C1] [ 26.515902][ C1] ======================================================== [ 26.516280][ C1] WARNING: possible irq lock inversion dependency detected [ 26.516588][ C1] 7.2.0-virtme #1 Tainted: G W [ 26.516840][ C1] -------------------------------------------------------- [ 26.517211][ C1] swapper/1/0 just changed the state of lock: [ 26.517546][ C1] ff1100000cc2ae58 (&br->lock){+.-.}-{3:3}, at: br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.518039][ C1] but this lock took another, SOFTIRQ-unsafe lock in the past: [ 26.518341][ C1] (fs_reclaim){+.+.}-{0:0} [ 26.518351][ C1] [ 26.518351][ C1] [ 26.518351][ C1] and interrupts could create inverse lock ordering between them. [ 26.518351][ C1] [ 26.519249][ C1] [ 26.519249][ C1] other info that might help us debug this: [ 26.519605][ C1] Chain exists of: [ 26.519605][ C1] &br->lock --> console_owner --> fs_reclaim [ 26.519605][ C1] [ 26.520134][ C1] Possible interrupt unsafe locking scenario: [ 26.520134][ C1] [ 26.520518][ C1] CPU0 CPU1 [ 26.520721][ C1] ---- ---- [ 26.521005][ C1] lock(fs_reclaim); [ 26.521164][ C1] local_irq_disable(); [ 26.521539][ C1] lock(&br->lock); [ 26.521801][ C1] lock(console_owner); [ 26.522127][ C1] [ 26.522284][ C1] lock(&br->lock); [ 26.522519][ C1] [ 26.522519][ C1] *** DEADLOCK *** [ 26.522519][ C1] [ 26.522889][ C1] locks held by swapper/1/0: 1, last CPU#1: [ 26.523142][ C1] #0: ffa00000001d0c90 ((&p->forward_delay_timer)){+.-.}-{0:0}, at: call_timer_fn+0x110/0x4d0 [ 26.523633][ C1] [ 26.523633][ C1] the shortest dependencies between 2nd lock and 1st lock: [ 26.524061][ C1] -> (fs_reclaim){+.+.}-{0:0} { [ 26.524371][ C1] HARDIRQ-ON-W at: [ 26.524547][ C1] __lock_acquire+0x388/0xc20 [ 26.524912][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.525170][ C1] fs_reclaim_acquire+0xd5/0x120 [ 26.525511][ C1] __kmalloc_cache_noprof+0x6e/0x620 [ 26.525899][ C1] kthread_create_worker_on_node+0xea/0x210 [ 26.526212][ C1] workqueue_init+0x2a/0x680 [ 26.533042][ C1] kernel_init_freeable+0x2fe/0x630 [ 26.533442][ C1] kernel_init+0x21/0x150 [ 26.533713][ C1] ret_from_fork+0x474/0x6b0 [ 26.534059][ C1] ret_from_fork_asm+0x11/0x20 [ 26.534397][ C1] SOFTIRQ-ON-W at: [ 26.534560][ C1] __lock_acquire+0x388/0xc20 [ 26.534900][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.535161][ C1] fs_reclaim_acquire+0xd5/0x120 [ 26.535503][ C1] __kmalloc_cache_noprof+0x6e/0x620 [ 26.535885][ C1] kthread_create_worker_on_node+0xea/0x210 [ 26.536189][ C1] workqueue_init+0x2a/0x680 [ 26.536531][ C1] kernel_init_freeable+0x2fe/0x630 [ 26.536911][ C1] kernel_init+0x21/0x150 [ 26.537170][ C1] ret_from_fork+0x474/0x6b0 [ 26.537514][ C1] ret_from_fork_asm+0x11/0x20 [ 26.537849][ C1] INITIAL USE at: [ 26.538003][ C1] __lock_acquire+0x388/0xc20 [ 26.538331][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.538591][ C1] fs_reclaim_acquire+0xd5/0x120 [ 26.538920][ C1] __kmalloc_cache_noprof+0x6e/0x620 [ 26.539290][ C1] kthread_create_worker_on_node+0xea/0x210 [ 26.539601][ C1] workqueue_init+0x2a/0x680 [ 26.539928][ C1] kernel_init_freeable+0x2fe/0x630 [ 26.540256][ C1] kernel_init+0x21/0x150 [ 26.540524][ C1] ret_from_fork+0x474/0x6b0 [ 26.540851][ C1] ret_from_fork_asm+0x11/0x20 [ 26.541106][ C1] } [ 26.541286][ C1] ... key at: [] __fs_reclaim_map+0x0/0xbe0 [ 26.541620][ C1] ... acquired at: [ 26.541867][ C1] __lock_acquire+0x518/0xc20 [ 26.542074][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.542354][ C1] fs_reclaim_acquire+0xd5/0x120 [ 26.542560][ C1] __kmalloc_noprof+0xd3/0x760 [ 26.542834][ C1] alloc_buf.isra.0+0x4b/0x260 [ 26.543034][ C1] put_chars+0x1e1/0x2f0 [ 26.543309][ C1] hvc_console_print+0x292/0x780 [ 26.543516][ C1] console_emit_next_record+0x22f/0x4c0 [ 26.543791][ C1] console_flush_one_record+0x46f/0x710 [ 26.543989][ C1] console_unlock+0xee/0x1f0 [ 26.544257][ C1] vprintk_emit+0x37c/0x3e0 [ 26.544463][ C1] dev_vprintk_emit+0x27f/0x2c0 [ 26.544735][ C1] dev_printk_emit+0xb9/0xee [ 26.544931][ C1] _dev_info+0xe2/0x116 [ 26.545149][ C1] __devm_rtc_register_device.cold+0xc3/0x3a8 [ 26.545411][ C1] cmos_do_probe+0x73b/0x98a [ 26.545736][ C1] platform_probe+0xfe/0x1f0 [ 26.545963][ C1] call_driver_probe+0x61/0x1c0 [ 26.546238][ C1] really_probe+0x199/0x760 [ 26.546441][ C1] __driver_probe_device+0x24f/0x440 [ 26.546715][ C1] driver_probe_device+0x4a/0xf0 [ 26.546914][ C1] __driver_attach+0x1b8/0x540 [ 26.547186][ C1] bus_for_each_dev+0x130/0x1e0 [ 26.547397][ C1] bus_add_driver+0x2c8/0x530 [ 26.547671][ C1] driver_register+0x1a3/0x390 [ 26.547869][ C1] __platform_driver_probe+0x13f/0x270 [ 26.548141][ C1] cmos_init+0x31/0x40 [ 26.548296][ C1] do_one_initcall+0x124/0x4f0 [ 26.548580][ C1] kernel_init_freeable+0x596/0x630 [ 26.548770][ C1] kernel_init+0x21/0x150 [ 26.549040][ C1] ret_from_fork+0x474/0x6b0 [ 26.549248][ C1] ret_from_fork_asm+0x11/0x20 [ 26.549547][ C1] [ 26.549673][ C1] -> (console_owner){....}-{0:0} { [ 26.549879][ C1] INITIAL USE at: [ 26.550104][ C1] } [ 26.550206][ C1] ... key at: [] console_owner_dep_map+0x0/0x60 [ 26.550584][ C1] ... acquired at: [ 26.550738][ C1] __lock_acquire+0x518/0xc20 [ 26.551014][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.551218][ C1] console_lock_spinning_enable+0x5c/0x60 [ 26.551546][ C1] console_emit_next_record+0x1d1/0x4c0 [ 26.551746][ C1] console_flush_one_record+0x46f/0x710 [ 26.552017][ C1] console_unlock+0xee/0x1f0 [ 26.552219][ C1] vprintk_emit+0x37c/0x3e0 [ 26.552500][ C1] _printk+0xc7/0x100 [ 26.552652][ C1] br_set_state+0x22f/0x430 [bridge] [ 26.552935][ C1] br_init_port+0xc4/0x200 [bridge] [ 26.553149][ C1] br_stp_enable_port+0x12/0x50 [bridge] [ 26.553487][ C1] br_port_carrier_check+0x220/0x430 [bridge] [ 26.553748][ C1] br_device_event+0x52d/0x8f0 [bridge] [ 26.554033][ C1] notifier_call_chain+0xae/0x300 [ 26.554236][ C1] netif_state_change+0x139/0x340 [ 26.554517][ C1] __linkwatch_run_queue+0x34c/0x750 [ 26.554719][ C1] linkwatch_event+0x7f/0xb0 [ 26.554991][ C1] process_one_work+0xe3e/0x1560 [ 26.555192][ C1] worker_thread+0x4f1/0xd60 [ 26.555472][ C1] kthread+0x367/0x460 [ 26.555622][ C1] ret_from_fork+0x474/0x6b0 [ 26.555895][ C1] ret_from_fork_asm+0x11/0x20 [ 26.556094][ C1] [ 26.556261][ C1] -> (&br->lock){+.-.}-{3:3} { [ 26.556473][ C1] HARDIRQ-ON-W at: [ 26.556626][ C1] __lock_acquire+0x388/0xc20 [ 26.556960][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.557288][ C1] _raw_spin_lock_bh+0x38/0x50 [ 26.557549][ C1] recalculate_group_addr+0x51/0x120 [bridge] [ 26.557942][ C1] br_vlan_filter_toggle+0x85/0x110 [bridge] [ 26.558324][ C1] br_changelink+0x575/0x16e0 [bridge] [ 26.558590][ C1] br_dev_newlink+0xeb/0x160 [bridge] [ 26.558924][ C1] rtnl_newlink_create+0x2d0/0x750 [ 26.559252][ C1] __rtnl_newlink+0x22b/0xa50 [ 26.559511][ C1] rtnl_newlink+0x9f1/0x11c0 [ 26.559843][ C1] rtnetlink_rcv_msg+0x6fd/0xbd0 [ 26.560170][ C1] netlink_rcv_skb+0x14e/0x3a0 [ 26.560430][ C1] netlink_unicast+0x486/0x750 [ 26.560682][ C1] netlink_sendmsg+0x735/0xc60 [ 26.560939][ C1] ____sys_sendmsg+0x415/0x880 [ 26.561267][ C1] ___sys_sendmsg+0x14e/0x1d0 [ 26.561595][ C1] __sys_sendmsg+0x12c/0x1d0 [ 26.561850][ C1] do_syscall_64+0xff/0x530 [ 26.562175][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 26.562565][ C1] IN-SOFTIRQ-W at: [ 26.562725][ C1] __lock_acquire+0x388/0xc20 [ 26.563048][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.563300][ C1] _raw_spin_lock+0x33/0x40 [ 26.563642][ C1] br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.564026][ C1] call_timer_fn+0x160/0x4d0 [ 26.564278][ C1] __run_timers+0x68f/0xaa0 [ 26.564649][ C1] run_timer_softirq+0xf0/0x160 [ 26.564984][ C1] handle_softirqs+0x1d3/0x900 [ 26.565239][ C1] __irq_exit_rcu+0x145/0x1c0 [ 26.565576][ C1] irq_exit_rcu+0xe/0x30 [ 26.565831][ C1] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 26.566209][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 26.566593][ C1] pv_native_safe_halt+0xf/0x10 [ 26.566920][ C1] default_idle+0x9/0x10 [ 26.567173][ C1] default_idle_call+0x6e/0xb0 [ 26.567507][ C1] cpuidle_idle_call.constprop.0+0x237/0x410 [ 26.567888][ C1] do_idle+0xd8/0x190 [ 26.568094][ C1] cpu_startup_entry+0x53/0x70 [ 26.568428][ C1] start_secondary+0x204/0x2b0 [ 26.568687][ C1] common_startup_64+0x13e/0x148 [ 26.569013][ C1] INITIAL USE at: [ 26.569162][ C1] __lock_acquire+0x388/0xc20 [ 26.569497][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.569831][ C1] _raw_spin_lock_bh+0x38/0x50 [ 26.570086][ C1] recalculate_group_addr+0x51/0x120 [bridge] [ 26.570478][ C1] br_vlan_filter_toggle+0x85/0x110 [bridge] [ 26.570860][ C1] br_changelink+0x575/0x16e0 [bridge] [ 26.571117][ C1] br_dev_newlink+0xeb/0x160 [bridge] [ 26.571459][ C1] rtnl_newlink_create+0x2d0/0x750 [ 26.571793][ C1] __rtnl_newlink+0x22b/0xa50 [ 26.572045][ C1] rtnl_newlink+0x9f1/0x11c0 [ 26.572379][ C1] rtnetlink_rcv_msg+0x6fd/0xbd0 [ 26.572646][ C1] netlink_rcv_skb+0x14e/0x3a0 [ 26.572973][ C1] netlink_unicast+0x486/0x750 [ 26.573322][ C1] netlink_sendmsg+0x735/0xc60 [ 26.573585][ C1] ____sys_sendmsg+0x415/0x880 [ 26.573908][ C1] ___sys_sendmsg+0x14e/0x1d0 [ 26.574232][ C1] __sys_sendmsg+0x12c/0x1d0 [ 26.574495][ C1] do_syscall_64+0xff/0x530 [ 26.574825][ C1] entry_SYSCALL_64_after_hwframe+0x4b/0x53 [ 26.575201][ C1] } [ 26.575304][ C1] ... key at: [] __key.7+0x0/0x40 [bridge] [ 26.575690][ C1] ... acquired at: [ 26.575841][ C1] mark_lock+0x1d7/0xa00 [ 26.576044][ C1] mark_usage+0x42/0x170 [ 26.576319][ C1] __lock_acquire+0x388/0xc20 [ 26.576509][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.576783][ C1] _raw_spin_lock+0x33/0x40 [ 26.576986][ C1] br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.577322][ C1] call_timer_fn+0x160/0x4d0 [ 26.577618][ C1] __run_timers+0x68f/0xaa0 [ 26.577845][ C1] run_timer_softirq+0xf0/0x160 [ 26.578122][ C1] handle_softirqs+0x1d3/0x900 [ 26.578326][ C1] __irq_exit_rcu+0x145/0x1c0 [ 26.578606][ C1] irq_exit_rcu+0xe/0x30 [ 26.578809][ C1] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 26.579130][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 26.579387][ C1] pv_native_safe_halt+0xf/0x10 [ 26.579660][ C1] default_idle+0x9/0x10 [ 26.579857][ C1] default_idle_call+0x6e/0xb0 [ 26.580128][ C1] cpuidle_idle_call.constprop.0+0x237/0x410 [ 26.580384][ C1] do_idle+0xd8/0x190 [ 26.580610][ C1] cpu_startup_entry+0x53/0x70 [ 26.580808][ C1] start_secondary+0x204/0x2b0 [ 26.581082][ C1] common_startup_64+0x13e/0x148 [ 26.581280][ C1] [ 26.581456][ C1] [ 26.581456][ C1] stack backtrace: [ 26.581701][ C1] CPU: 1 UID: 0 PID: 0 Comm: swapper/1 Tainted: G W 7.2.0-virtme #1 PREEMPT(full) [ 26.581706][ C1] Tainted: [W]=WARN [ 26.581708][ C1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 26.581709][ C1] Call Trace: [ 26.581711][ C1] [ 26.581713][ C1] dump_stack_lvl+0x6f/0xa0 [ 26.581718][ C1] print_irq_inversion_bug.part.0.cold+0xe6/0x143 [ 26.581723][ C1] mark_lock_irq+0x989/0x9c0 [ 26.581727][ C1] mark_lock+0x1d7/0xa00 [ 26.581730][ C1] mark_usage+0x42/0x170 [ 26.581732][ C1] __lock_acquire+0x388/0xc20 [ 26.581736][ C1] lock_acquire.part.0+0xd4/0x280 [ 26.581738][ C1] ? br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.581753][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.581757][ C1] ? lock_acquire+0x13c/0x160 [ 26.581759][ C1] ? br_message_age_timer_expired+0x70/0x70 [bridge] [ 26.581770][ C1] _raw_spin_lock+0x33/0x40 [ 26.581773][ C1] ? br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.581784][ C1] br_forward_delay_timer_expired+0x44/0x5d0 [bridge] [ 26.581796][ C1] ? br_message_age_timer_expired+0x70/0x70 [bridge] [ 26.581806][ C1] call_timer_fn+0x160/0x4d0 [ 26.581810][ C1] ? detach_if_pending+0x1d0/0x1d0 [ 26.581812][ C1] ? debug_object_active_state+0x430/0x430 [ 26.581816][ C1] ? find_held_lock+0x2b/0x80 [ 26.581820][ C1] ? __lock_release.isra.0+0x69/0x1a0 [ 26.581822][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.581826][ C1] __run_timers+0x68f/0xaa0 [ 26.581828][ C1] ? br_message_age_timer_expired+0x70/0x70 [bridge] [ 26.581840][ C1] ? __bpf_trace_itimer_expire+0x10/0x10 [ 26.581843][ C1] ? __lock_acquire+0x518/0xc20 [ 26.581847][ C1] ? __rwlock_init+0x150/0x150 [ 26.581850][ C1] run_timer_softirq+0xf0/0x160 [ 26.581853][ C1] ? __run_timers+0xaa0/0xaa0 [ 26.581856][ C1] ? trace_irq_enable.constprop.0+0x9b/0x160 [ 26.581859][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.581861][ C1] handle_softirqs+0x1d3/0x900 [ 26.581865][ C1] ? __lock_release.isra.0+0x69/0x1a0 [ 26.581867][ C1] ? _local_bh_enable+0xc0/0xc0 [ 26.581870][ C1] __irq_exit_rcu+0x145/0x1c0 [ 26.581873][ C1] irq_exit_rcu+0xe/0x30 [ 26.581875][ C1] sysvec_apic_timer_interrupt+0x9d/0xe0 [ 26.581877][ C1] [ 26.581878][ C1] [ 26.581879][ C1] ? lockdep_hardirqs_on+0x91/0x130 [ 26.581881][ C1] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 26.581884][ C1] RIP: 0010:pv_native_safe_halt+0xf/0x10 [ 26.581887][ C1] Code: 48 8b 3d 94 d2 f5 01 e8 1f 00 00 00 48 2b 05 58 93 95 00 c3 0f 1f 80 00 00 00 00 f3 0f 1e fa eb 07 0f 00 2d 13 86 11 00 fb f4 0f 1f 40 d6 48 83 ec 20 8b 17 49 89 f8 83 e2 fe 41 89 d2 0f 01 [ 26.581890][ C1] RSP: 0018:ffa0000000147e00 EFLAGS: 00000282 [ 26.581893][ C1] RAX: 00000000000d61bf RBX: ff11000001bea380 RCX: ffffffffa2af0307 [ 26.581895][ C1] RDX: ff11000001bea380 RSI: ffffffffa5838af6 RDI: ffffffffa528d8e0 [ 26.581896][ C1] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000000 [ 26.581898][ C1] R10: 0000000000000001 R11: 0000000000000001 R12: 1ff4000000028fc3 [ 26.581899][ C1] R13: 0000000000000000 R14: dffffc0000000000 R15: 0000000000000000 [ 26.581902][ C1] ? cpuidle_idle_call.constprop.0+0x237/0x410 [ 26.581905][ C1] default_idle+0x9/0x10 [ 26.581908][ C1] default_idle_call+0x6e/0xb0 [ 26.581910][ C1] cpuidle_idle_call.constprop.0+0x237/0x410 [ 26.581913][ C1] ? arch_cpu_idle_exit+0x40/0x40 [ 26.581915][ C1] ? mark_tsc_async_resets+0x30/0x30 [ 26.581918][ C1] ? default_idle_call+0x98/0xb0 [ 26.581920][ C1] ? rcu_is_watching+0x16/0xd0 [ 26.581923][ C1] do_idle+0xd8/0x190 [ 26.581926][ C1] cpu_startup_entry+0x53/0x70 [ 26.581928][ C1] start_secondary+0x204/0x2b0 [ 26.581930][ C1] ? set_cpu_sibling_map+0x2130/0x2130 [ 26.581933][ C1] common_startup_64+0x13e/0x148 [ 26.581939][ C1] [ 26.700199][ T623] br1: port 2(veth2) entered disabled state [ 26.721463][ T624] veth2: left allmulticast mode [ 26.722224][ T624] veth2: left promiscuous mode [ 26.722637][ T624] br1: port 2(veth2) entered disabled state [ 26.749539][ T625] br1: port 1(veth1) entered disabled state [ 26.772023][ T626] veth1: left allmulticast mode [ 26.772302][ T626] veth1: left promiscuous mode [ 26.772696][ T626] br1: port 1(veth1) entered disabled state