[ 20.287502][ T227] packetdrill (227) used greatest stack depth: 24232 bytes left [ 20.299759][ C1] [ 20.299980][ C1] ================================ [ 20.300332][ C1] WARNING: inconsistent lock state [ 20.300629][ C1] 6.15.0-virtme #1 Not tainted [ 20.300928][ C1] -------------------------------- [ 20.301245][ C1] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. [ 20.301608][ C1] ksoftirqd/1/22 [HC0[0]:SC1[1]:HE1:SE0] takes: [ 20.301994][ C1] ffffffff97dc5af8 (pin_fs_lock){+.?.}-{3:3}, at: simple_pin_fs+0x24/0x150 [ 20.302513][ C1] {SOFTIRQ-ON-W} state was registered at: [ 20.302779][ C1] __lock_acquire+0x20b/0x7e0 [ 20.303087][ C1] lock_acquire.part.0+0xb6/0x240 [ 20.303386][ C1] _raw_spin_lock+0x33/0x40 [ 20.303691][ C1] simple_pin_fs+0x24/0x150 [ 20.303985][ C1] start_creating.part.0+0x52/0x310 [ 20.304320][ C1] debugfs_create_dir+0x6a/0x540 [ 20.304635][ C1] component_debug_init+0x17/0x30 [ 20.304938][ C1] do_one_initcall+0x8f/0x1e0 [ 20.305240][ C1] do_initcalls+0x176/0x280 [ 20.305589][ C1] kernel_init_freeable+0x22d/0x300 [ 20.305897][ C1] kernel_init+0x20/0x200 [ 20.306185][ C1] ret_from_fork+0x240/0x320 [ 20.306439][ C1] ret_from_fork_asm+0x1a/0x30 [ 20.306666][ C1] irq event stamp: 275880 [ 20.306886][ C1] hardirqs last enabled at (275880): [] _raw_spin_unlock_irqrestore+0x5d/0x80 [ 20.307288][ C1] hardirqs last disabled at (275879): [] _raw_spin_lock_irqsave+0x5b/0x60 [ 20.307681][ C1] softirqs last enabled at (275582): [] handle_softirqs+0x358/0x620 [ 20.308016][ C1] softirqs last disabled at (275591): [] run_ksoftirqd+0x3f/0x70 [ 20.308360][ C1] [ 20.308360][ C1] other info that might help us debug this: [ 20.308643][ C1] Possible unsafe locking scenario: [ 20.308643][ C1] [ 20.308959][ C1] CPU0 [ 20.309100][ C1] ---- [ 20.309239][ C1] lock(pin_fs_lock); [ 20.309400][ C1] [ 20.309559][ C1] lock(pin_fs_lock); [ 20.309710][ C1] [ 20.309710][ C1] *** DEADLOCK *** [ 20.309710][ C1] [ 20.310017][ C1] 1 lock held by ksoftirqd/1/22: [ 20.310210][ C1] #0: ffffffff97b774c0 (rcu_callback){....}-{0:0}, at: rcu_do_batch+0x2e4/0xf20 [ 20.310559][ C1] [ 20.310559][ C1] stack backtrace: [ 20.310829][ C1] CPU: 1 UID: 0 PID: 22 Comm: ksoftirqd/1 Not tainted 6.15.0-virtme #1 PREEMPT(full) [ 20.310836][ C1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 20.310838][ C1] Call Trace: [ 20.310841][ C1] [ 20.310844][ C1] dump_stack_lvl+0x82/0xd0 [ 20.310852][ C1] print_usage_bug.part.0+0x25f/0x360 [ 20.310859][ C1] mark_lock_irq+0x343/0x400 [ 20.310863][ C1] ? __pfx_unwind_next_frame+0x10/0x10 [ 20.310868][ C1] ? save_trace+0x52/0x170 [ 20.310874][ C1] mark_lock+0x174/0x2f0 [ 20.310878][ C1] mark_usage+0x46/0x150 [ 20.310881][ C1] __lock_acquire+0x20b/0x7e0 [ 20.310884][ C1] ? __lock_acquire+0x44d/0x7e0 [ 20.310888][ C1] lock_acquire.part.0+0xb6/0x240 [ 20.310892][ C1] ? simple_pin_fs+0x24/0x150 [ 20.310897][ C1] ? rcu_is_watching+0x12/0xc0 [ 20.310902][ C1] ? lock_acquire+0x10c/0x170 [ 20.310904][ C1] ? simple_pin_fs+0x24/0x150 [ 20.310909][ C1] _raw_spin_lock+0x33/0x40 [ 20.310914][ C1] ? simple_pin_fs+0x24/0x150 [ 20.310917][ C1] simple_pin_fs+0x24/0x150 [ 20.310921][ C1] debugfs_remove+0x35/0x70 [ 20.310925][ C1] ref_tracker_dir_exit+0xcf/0x740 [ 20.310932][ C1] ? __pfx_ref_tracker_free+0x10/0x10 [ 20.310935][ C1] ? __sk_destruct+0x383/0x780 [ 20.310941][ C1] ? rcu_do_batch+0x34c/0xf20 [ 20.310944][ C1] ? __pfx_ref_tracker_dir_exit+0x10/0x10 [ 20.310947][ C1] ? smpboot_thread_fn+0x30a/0x960 [ 20.310952][ C1] ? kthread+0x37e/0x600 [ 20.310955][ C1] ? ret_from_fork+0x240/0x320 [ 20.310959][ C1] ? ret_from_fork_asm+0x1a/0x30 [ 20.310964][ C1] ? migrate_enable+0x1f2/0x270 [ 20.310968][ C1] ? __pfx_migrate_enable+0x10/0x10 [ 20.310974][ C1] __put_net+0x19/0x60 [ 20.310978][ C1] __sk_destruct+0x58a/0x780 [ 20.310982][ C1] ? rcu_do_batch+0x34a/0xf20 [ 20.310984][ C1] rcu_do_batch+0x34c/0xf20 [ 20.310989][ C1] ? __pfx_rcu_do_batch+0x10/0x10 [ 20.310992][ C1] ? rcu_is_watching+0x12/0xc0 [ 20.310995][ C1] ? note_gp_changes+0x182/0x1e0 [ 20.310998][ C1] ? lockdep_hardirqs_on+0x7c/0x110 [ 20.311003][ C1] rcu_core+0x2bb/0x500 [ 20.311007][ C1] handle_softirqs+0x218/0x620 [ 20.311013][ C1] ? __pfx_run_ksoftirqd+0x10/0x10 [ 20.311016][ C1] run_ksoftirqd+0x3f/0x70 [ 20.311019][ C1] smpboot_thread_fn+0x30a/0x960 [ 20.311023][ C1] ? __pfx_smpboot_thread_fn+0x10/0x10 [ 20.311027][ C1] kthread+0x37e/0x600 [ 20.311030][ C1] ? __pfx_kthread+0x10/0x10 [ 20.311032][ C1] ? ret_from_fork+0x1b/0x320 [ 20.311034][ C1] ? __lock_release+0x5d/0x170 [ 20.311038][ C1] ? rcu_is_watching+0x12/0xc0 [ 20.311041][ C1] ? __pfx_kthread+0x10/0x10 [ 20.311044][ C1] ret_from_fork+0x240/0x320 [ 20.311046][ C1] ? __pfx_kthread+0x10/0x10 [ 20.311049][ C1] ret_from_fork_asm+0x1a/0x30 [ 20.311056][ C1] [ 20.325359][ C1] BUG: sleeping function called from invalid context at kernel/locking/rwsem.c:1576 [ 20.325825][ C1] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 22, name: ksoftirqd/1 [ 20.326281][ C1] preempt_count: 100, expected: 0 [ 20.326540][ C1] RCU nest depth: 0, expected: 0 [ 20.326810][ C1] INFO: lockdep is turned off. [ 20.327087][ C1] Preemption disabled at: [ 20.327090][ C1] [] handle_softirqs+0xe5/0x620 [ 20.327627][ C1] CPU: 1 UID: 0 PID: 22 Comm: ksoftirqd/1 Not tainted 6.15.0-virtme #1 PREEMPT(full) [ 20.327635][ C1] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 20.327639][ C1] Call Trace: [ 20.327642][ C1] [ 20.327647][ C1] dump_stack_lvl+0xb0/0xd0 [ 20.327658][ C1] __might_resched+0x360/0x5a0 [ 20.327668][ C1] down_write+0x72/0x210 [ 20.327674][ C1] ? __pfx_down_write+0x10/0x10 [ 20.327678][ C1] ? simple_recursive_removal+0x33/0x610 [ 20.327684][ C1] ? rcu_is_watching+0x12/0xc0 [ 20.327691][ C1] ? do_raw_spin_unlock+0x58/0x220 [ 20.327702][ C1] simple_recursive_removal+0x6a/0x610 [ 20.327707][ C1] ? do_raw_spin_unlock+0x58/0x220 [ 20.327712][ C1] ? __pfx_remove_one+0x10/0x10 [ 20.327722][ C1] debugfs_remove+0x44/0x70 [ 20.327727][ C1] ref_tracker_dir_exit+0xcf/0x740 [ 20.327735][ C1] ? __pfx_ref_tracker_free+0x10/0x10 [ 20.327740][ C1] ? __sk_destruct+0x383/0x780 [ 20.327748][ C1] ? rcu_do_batch+0x34c/0xf20 [ 20.327757][ C1] ? __pfx_ref_tracker_dir_exit+0x10/0x10 [ 20.327762][ C1] ? smpboot_thread_fn+0x30a/0x960 [ 20.327768][ C1] ? kthread+0x37e/0x600 [ 20.327773][ C1] ? ret_from_fork+0x240/0x320 [ 20.327779][ C1] ? ret_from_fork_asm+0x1a/0x30 [ 20.327786][ C1] ? migrate_enable+0x1f2/0x270 [ 20.327792][ C1] ? __pfx_migrate_enable+0x10/0x10 [ 20.327802][ C1] __put_net+0x19/0x60 [ 20.327809][ C1] __sk_destruct+0x58a/0x780 [ 20.327816][ C1] ? rcu_do_batch+0x34a/0xf20 [ 20.327820][ C1] rcu_do_batch+0x34c/0xf20 [ 20.327830][ C1] ? __pfx_rcu_do_batch+0x10/0x10 [ 20.327836][ C1] ? rcu_is_watching+0x12/0xc0 [ 20.327840][ C1] ? note_gp_changes+0x182/0x1e0 [ 20.327845][ C1] ? lockdep_hardirqs_on+0x7c/0x110 [ 20.327853][ C1] rcu_core+0x2bb/0x500 [ 20.327860][ C1] handle_softirqs+0x218/0x620 [ 20.327868][ C1] ? __pfx_run_ksoftirqd+0x10/0x10 [ 20.327874][ C1] run_ksoftirqd+0x3f/0x70 [ 20.327879][ C1] smpboot_thread_fn+0x30a/0x960 [ 20.327886][ C1] ? __pfx_smpboot_thread_fn+0x10/0x10 [ 20.327892][ C1] kthread+0x37e/0x600 [ 20.327897][ C1] ? __pfx_kthread+0x10/0x10 [ 20.327901][ C1] ? ret_from_fork+0x1b/0x320 [ 20.327906][ C1] ? __lock_release+0x5d/0x170 [ 20.327912][ C1] ? rcu_is_watching+0x12/0xc0 [ 20.327917][ C1] ? __pfx_kthread+0x10/0x10 [ 20.327923][ C1] ret_from_fork+0x240/0x320 [ 20.327928][ C1] ? __pfx_kthread+0x10/0x10 [ 20.327933][ C1] ret_from_fork_asm+0x1a/0x30 [ 20.327946][ C1] [ 24.329535][ C2] BUG: sleeping function called from invalid context at kernel/locking/rwsem.c:1576 [ 24.330005][ C2] in_atomic(): 1, irqs_disabled(): 0, non_block: 0, pid: 218, name: timeout [ 24.330419][ C2] preempt_count: 101, expected: 0 [ 24.330634][ C2] RCU nest depth: 1, expected: 0 [ 24.330857][ C2] INFO: lockdep is turned off. [ 24.331068][ C2] Preemption disabled at: [ 24.331070][ C2] [] __slab_alloc.constprop.0+0x2c/0xb0 [ 24.331548][ C2] CPU: 2 UID: 0 PID: 218 Comm: timeout Tainted: G W 6.15.0-virtme #1 PREEMPT(full) [ 24.331555][ C2] Tainted: [W]=WARN [ 24.331557][ C2] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011 [ 24.331559][ C2] Call Trace: [ 24.331561][ C2] [ 24.331563][ C2] dump_stack_lvl+0xb0/0xd0 [ 24.331571][ C2] __might_resched+0x360/0x5a0 [ 24.331578][ C2] down_write+0x72/0x210 [ 24.331582][ C2] ? __pfx_down_write+0x10/0x10 [ 24.331585][ C2] ? simple_recursive_removal+0x33/0x610 [ 24.331589][ C2] ? rcu_is_watching+0x12/0xc0 [ 24.331595][ C2] ? do_raw_spin_unlock+0x58/0x220 [ 24.331600][ C2] simple_recursive_removal+0x6a/0x610 [ 24.331603][ C2] ? do_raw_spin_unlock+0x58/0x220 [ 24.331606][ C2] ? __pfx_remove_one+0x10/0x10 [ 24.331612][ C2] debugfs_remove+0x44/0x70 [ 24.331615][ C2] ref_tracker_dir_exit+0xcf/0x740 [ 24.331621][ C2] ? __pfx_ref_tracker_free+0x10/0x10 [ 24.331625][ C2] ? __sk_destruct+0x383/0x780 [ 24.331630][ C2] ? rcu_do_batch+0x34c/0xf20 [ 24.331633][ C2] ? __pfx_ref_tracker_dir_exit+0x10/0x10 [ 24.331637][ C2] ? irq_exit_rcu+0xe/0x30 [ 24.331641][ C2] ? sysvec_apic_timer_interrupt+0xa8/0xc0 [ 24.331646][ C2] ? asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 24.331650][ C2] ? __orc_find+0x7/0xf0 [ 24.331654][ C2] ? unwind_next_frame+0x244/0x1e10 [ 24.331657][ C2] ? arch_stack_walk+0x8b/0xf0 [ 24.331661][ C2] ? stack_trace_save+0x93/0xd0 [ 24.331664][ C2] ? set_track_prepare+0x30/0x70 [ 24.331668][ C2] ? ___slab_alloc+0xba4/0x1170 [ 24.331671][ C2] ? __slab_alloc.constprop.0+0x5b/0xb0 [ 24.331674][ C2] ? __kmalloc_cache_noprof+0x1cf/0x360 [ 24.331677][ C2] ? bpf_sk_storage_free+0x9f/0x1c0 [ 24.331681][ C2] ? rcu_is_watching+0x12/0xc0 [ 24.331686][ C2] __put_net+0x19/0x60 [ 24.331689][ C2] __sk_destruct+0x58a/0x780 [ 24.331693][ C2] ? rcu_do_batch+0x34a/0xf20 [ 24.331696][ C2] rcu_do_batch+0x34c/0xf20 [ 24.331700][ C2] ? __pfx_rcu_do_batch+0x10/0x10 [ 24.331704][ C2] ? rcu_is_watching+0x12/0xc0 [ 24.331707][ C2] ? trace_irq_enable.constprop.0+0xd4/0x130 [ 24.331714][ C2] rcu_core+0x2bb/0x500 [ 24.331718][ C2] handle_softirqs+0x218/0x620 [ 24.331724][ C2] __irq_exit_rcu+0xfa/0x160 [ 24.331727][ C2] irq_exit_rcu+0xe/0x30 [ 24.331730][ C2] sysvec_apic_timer_interrupt+0xa8/0xc0 [ 24.331734][ C2] [ 24.331735][ C2] [ 24.331736][ C2] asm_sysvec_apic_timer_interrupt+0x1a/0x20 [ 24.331739][ C2] RIP: 0010:__orc_find+0x7/0xf0 [ 24.331742][ C2] Code: 90 90 90 48 8b 07 c3 cc cc cc cc 0f 1f 84 00 00 00 00 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 0f 1f 44 00 00 41 57 <41> 56 41 55 49 89 cd 89 d1 41 54 4c 8d 64 8f fc 55 53 48 83 ec 08 [ 24.331745][ C2] RSP: 0018:ffffc90000737840 EFLAGS: 00000282 [ 24.331749][ C2] RAX: 0000000000013b13 RBX: 1ffff920000e6f13 RCX: ffffffff94280d27 [ 24.331754][ C2] RDX: 0000000000000001 RSI: ffffffff989b22aa RDI: ffffffff9867616c [ 24.331756][ C2] RBP: 0000000000000001 R08: 0000000000000000 R09: ffffc90000737991 [ 24.331757][ C2] R10: ffffffff94212687 R11: ffffc90000737990 R12: ffffc900007379a8 [ 24.331759][ C2] R13: ffffc90000737950 R14: ffff888004ec0040 R15: 0000000000000000 [ 24.331763][ C2] ? unwind_next_frame+0x147/0x1e10 [ 24.331766][ C2] ? do_group_exit+0xb7/0x260 [ 24.331773][ C2] unwind_next_frame+0x244/0x1e10 [ 24.331776][ C2] ? do_group_exit+0xb8/0x260 [ 24.331780][ C2] ? arch_stack_walk+0xa1/0xf0 [ 24.331783][ C2] ? __pfx_unwind_next_frame+0x10/0x10 [ 24.331788][ C2] ? do_group_exit+0xb8/0x260 [ 24.331791][ C2] ? kernel_text_address+0x17/0xe0 [ 24.331795][ C2] ? __pfx_stack_trace_consume_entry+0x10/0x10 [ 24.331798][ C2] arch_stack_walk+0x8b/0xf0 [ 24.331804][ C2] ? do_group_exit+0xb8/0x260 [ 24.331808][ C2] stack_trace_save+0x93/0xd0 [ 24.331811][ C2] ? __pfx_stack_trace_save+0x10/0x10 [ 24.331815][ C2] ? rcu_is_watching+0x12/0xc0 [ 24.331818][ C2] set_track_prepare+0x30/0x70 [ 24.331821][ C2] ? __kmalloc_cache_noprof+0x1cf/0x360 [ 24.331824][ C2] ? kmem_cache_free+0xf3/0x330 [ 24.331828][ C2] ? exit_mmap+0x3cd/0x800 [ 24.331833][ C2] ? mmput+0xb8/0x3f0 [ 24.331836][ C2] ? exit_mm+0x146/0x1d0 [ 24.331839][ C2] ? do_exit+0x433/0xc20 [ 24.331842][ C2] ? do_group_exit+0xb8/0x260 [ 24.331847][ C2] ___slab_alloc+0xba4/0x1170 [ 24.331851][ C2] ? kmem_cache_free+0xf3/0x330 [ 24.331856][ C2] ? kmem_cache_free+0xf3/0x330 [ 24.331859][ C2] __slab_alloc.constprop.0+0x5b/0xb0 [ 24.331863][ C2] ? kmem_cache_free+0xf3/0x330 [ 24.331865][ C2] __kmalloc_cache_noprof+0x1cf/0x360 [ 24.331870][ C2] kmem_cache_free+0xf3/0x330 [ 24.331874][ C2] ? exit_mmap+0x3cd/0x800 [ 24.331878][ C2] exit_mmap+0x3cd/0x800 [ 24.331883][ C2] ? __pfx_exit_mmap+0x10/0x10 [ 24.331886][ C2] ? __mutex_lock+0x19c/0xcd0 [ 24.331891][ C2] ? lock_release+0x13/0xc0 [ 24.331894][ C2] ? __mutex_unlock_slowpath+0x144/0x400 [ 24.331902][ C2] mmput+0xb8/0x3f0 [ 24.331906][ C2] exit_mm+0x146/0x1d0 [ 24.331910][ C2] do_exit+0x433/0xc20 [ 24.331914][ C2] do_group_exit+0xb8/0x260 [ 24.331918][ C2] __x64_sys_exit_group+0x3e/0x50 [ 24.331922][ C2] x64_sys_call+0xf76/0x18a0 [ 24.331926][ C2] do_syscall_64+0xc1/0x380 [ 24.331930][ C2] entry_SYSCALL_64_after_hwframe+0x77/0x7f [ 24.331933][ C2] RIP: 0033:0x7f5235f02abd [ 24.331936][ C2] Code: Unable to access opcode bytes at 0x7f5235f02a93. [ 24.331938][ C2] RSP: 002b:00007fffb20285f8 EFLAGS: 00000246 ORIG_RAX: 00000000000000e7 [ 24.331941][ C2] RAX: ffffffffffffffda RBX: 00007f5235fdf9c0 RCX: 00007f5235f02abd [ 24.331942][ C2] RDX: 00000000000000e7 RSI: ffffffffffffff80 RDI: 0000000000000000 [ 24.331944][ C2] RBP: 0000000000000000 R08: 0000000000000000 R09: 0000000000000020 [ 24.331945][ C2] R10: 00007fffb20284a0 R11: 0000000000000246 R12: 00007f5235fdf9c0 [ 24.331947][ C2] R13: 00007f5235fe4ee0 R14: 0000000000000002 R15: 00007f5235fe4ec8 [ 24.331953][ C2]