Excerpts from Michael Ellerman's message of January 21, 2021 10:50 pm: > Nicholas Piggin <npig...@gmail.com> writes: >> Running softirqs enables interrupts, which can then end up recursing >> into the irq soft-mask code we're adjusting, including replaying >> interrupts itself, which might be theoretically unbounded. >> >> This abridged trace shows how this can occur: >> >> ! NIP replay_soft_interrupts >> LR interrupt_exit_kernel_prepare >> Call Trace: >> interrupt_exit_kernel_prepare (unreliable) >> interrupt_return >> --- interrupt: ea0 at __rb_reserve_next >> NIP __rb_reserve_next >> LR __rb_reserve_next >> Call Trace: >> ring_buffer_lock_reserve >> trace_function >> function_trace_call >> ftrace_call >> __do_softirq >> irq_exit >> timer_interrupt >> ! replay_soft_interrupts >> interrupt_exit_kernel_prepare >> interrupt_return >> --- interrupt: ea0 at arch_local_irq_restore >> >> Fix this by disabling bhs (softirqs) around the interrupt replay. >> >> I don't know that commit 3282a3da25bd ("powerpc/64: Implement soft >> interrupt replay in C") actually introduced the problem. Prior to that >> change, the interrupt replay seems like it should still be subect to >> this recusion, however it's done after all the irq state has been fixed >> up at the end of the replay, so it seems reasonable to fix back to this >> commit. > > This seems very unhappy for me (on P9 bare metal):
Oh, damn lockdep I always forget it has a bunch of interrupt checks. In this case it might have a point though. Thanks, I'll try to fix it. Thanks, Nick > > [ 0.038571] Mountpoint-cache hash table entries: 131072 (order: 4, 1048576 > bytes, linear) > [ 0.040194] ------------[ cut here ]------------ > [ 0.040228] WARNING: CPU: 0 PID: 0 at kernel/softirq.c:176 > __local_bh_enable_ip+0x150/0x210 > [ 0.040263] Modules linked in: > [ 0.040280] CPU: 0 PID: 0 Comm: swapper/0 Not tainted > 5.11.0-rc2-00008-g4899f32e4f2a #1 > [ 0.040321] NIP: c000000000114bc0 LR: c0000000000172a0 CTR: > c00000000002a020 > [ 0.040360] REGS: c00000000177f670 TRAP: 0700 Not tainted > (5.11.0-rc2-00008-g4899f32e4f2a) > [ 0.040410] MSR: 9000000002021033 <SF,HV,VEC,ME,IR,DR,RI,LE> CR: > 28000224 XER: 20040000 > [ 0.040472] CFAR: c000000000114ae8 IRQMASK: 3 > GPR00: c0000000000172a0 c00000000177f910 c000000001783900 > c000000000017290 > GPR04: 0000000000000200 4000000000000000 0000000000000002 > 00000001312d0000 > GPR08: 0000000000000000 c0000000016f3480 0000000000000202 > 0000000000000000 > GPR12: c00000000002a020 c0000000023a0000 0000000000000000 > 0000000000000000 > GPR16: 0000000000000000 0000000000000000 0000000000000000 > 0000000000000000 > GPR20: 0000000000000001 00000000100051c6 0000000000000000 > 0000000000000009 > GPR24: 0000000000000e60 0000000000000900 0000000000000500 > 0000000000000a00 > GPR28: 0000000000000f00 0000000000000002 0000000000000003 > 0000000000000200 > [ 0.040824] NIP [c000000000114bc0] __local_bh_enable_ip+0x150/0x210 > [ 0.040863] LR [c0000000000172a0] replay_soft_interrupts+0x2e0/0x340 > [ 0.040904] Call Trace: > [ 0.040926] [c00000000177f910] [0000000000000500] 0x500 (unreliable) > [ 0.040962] [c00000000177f950] [c0000000000172a0] > replay_soft_interrupts+0x2e0/0x340 > [ 0.041008] [c00000000177fb50] [c000000000017370] > arch_local_irq_restore+0x70/0xe0 > [ 0.041042] [c00000000177fb80] [c000000000476514] > kmem_cache_alloc+0x474/0x520 > [ 0.041066] [c00000000177fc00] [c0000000004e394c] __d_alloc+0x4c/0x2e0 > [ 0.041109] [c00000000177fc50] [c0000000004e40ac] d_make_root+0x3c/0xa0 > [ 0.041142] [c00000000177fc80] [c000000000679ce0] > ramfs_fill_super+0x80/0xb0 > [ 0.041186] [c00000000177fcb0] [c0000000004c1b04] get_tree_nodev+0xb4/0x130 > [ 0.041230] [c00000000177fcf0] [c000000000679578] ramfs_get_tree+0x28/0x40 > [ 0.041282] [c00000000177fd10] [c0000000004bee78] vfs_get_tree+0x48/0x120 > [ 0.041325] [c00000000177fd80] [c0000000004f7fe0] > vfs_kern_mount.part.0+0xd0/0x130 > [ 0.041368] [c00000000177fdc0] [c000000001366700] mnt_init+0x1c8/0x2fc > [ 0.041420] [c00000000177fe60] [c000000001366178] > vfs_caches_init+0x110/0x138 > [ 0.041454] [c00000000177fee0] [c000000001331020] start_kernel+0x6d8/0x780 > [ 0.041497] [c00000000177ff90] [c00000000000d354] > start_here_common+0x1c/0x5c8 > [ 0.041539] Instruction dump: > [ 0.041555] e9490002 394a0001 91490000 e90d0028 3d42ffcc 394a4730 7d0a42aa > e9490002 > [ 0.041608] 2c280000 394affff 91490000 4082ff30 <0fe00000> 892d0988 > 39400001 994d0988 > [ 0.041660] irq event stamp: 555 > [ 0.041674] hardirqs last enabled at (553): [<c00000000047654c>] > kmem_cache_alloc+0x4ac/0x520 > [ 0.041707] hardirqs last disabled at (554): [<c000000000017368>] > arch_local_irq_restore+0x68/0xe0 > [ 0.041750] softirqs last enabled at (0): [<0000000000000000>] 0x0 > [ 0.041778] softirqs last disabled at (555): [<c000000000016fd0>] > replay_soft_interrupts+0x10/0x340 > [ 0.041824] ---[ end trace aa6f9769e07e43db ]--- > > > And lots and lots of these, or similar: > > > [ 14.369838] ============================= > [ 14.369839] WARNING: suspicious RCU usage > [ 14.369841] 5.11.0-rc2-00008-g4899f32e4f2a #1 Tainted: G W > [ 14.369843] ----------------------------- > [ 14.369844] include/linux/rcupdate.h:692 rcu_read_unlock() used illegally > while idle! > [ 14.369846] > other info that might help us debug this: > > [ 14.369848] > rcu_scheduler_active = 2, debug_locks = 1 > [ 14.369850] RCU used illegally from extended quiescent state! > [ 14.369851] 2 locks held by swapper/32/0: > [ 14.369853] #0: c0000000015e6fc0 (rcu_callback){....}-{0:0}, at: > rcu_core+0x2e0/0x990 > [ 14.369864] #1: c0000000015e6f30 (rcu_read_lock){....}-{1:3}, at: > kmem_cache_free+0x7cc/0x7e0 > [ 14.369874] > stack backtrace: > [ 14.369876] CPU: 32 PID: 0 Comm: swapper/32 Tainted: G W > 5.11.0-rc2-00008-g4899f32e4f2a #1 > [ 14.369879] Call Trace: > [ 14.369880] [c000001fff557c10] [c0000000008630b8] dump_stack+0xec/0x144 > (unreliable) > [ 14.369886] [c000001fff557c60] [c0000000001ad2d0] > lockdep_rcu_suspicious+0x124/0x144 > [ 14.369890] [c000001fff557cf0] [c00000000047783c] > kmem_cache_free+0x2ac/0x7e0 > [ 14.369894] [c000001fff557db0] [c0000000004bdeac] file_free_rcu+0x5c/0xa0 > [ 14.369898] [c000001fff557de0] [c0000000001e214c] rcu_core+0x33c/0x990 > [ 14.369902] [c000001fff557e90] [c000000000f496d0] __do_softirq+0x180/0x688 > [ 14.369906] [c000001fff557f90] [c0000000000307bc] call_do_softirq+0x14/0x24 > [ 14.369911] [c000000002e1fab0] [c000000000017418] > do_softirq_own_stack+0x38/0x50 > [ 14.369916] [c000000002e1fad0] [c000000000114a60] do_softirq+0x120/0x130 > [ 14.369920] [c000000002e1fb00] [c000000000114c64] > __local_bh_enable_ip+0x1f4/0x210 > [ 14.369924] [c000000002e1fb40] [c0000000000172a0] > replay_soft_interrupts+0x2e0/0x340 > [ 14.369928] [c000000002e1fd40] [c000000000017370] > arch_local_irq_restore+0x70/0xe0 > [ 14.369933] [c000000002e1fd70] [c000000000c87184] snooze_loop+0x64/0x2e4 > [ 14.369937] [c000000002e1fdb0] [c000000000c84204] > cpuidle_enter_state+0x2e4/0x550 > [ 14.369941] [c000000002e1fe10] [c000000000c8450c] cpuidle_enter+0x4c/0x70 > [ 14.369946] [c000000002e1fe50] [c00000000016892c] call_cpuidle+0x4c/0x90 > [ 14.369949] [c000000002e1fe70] [c000000000168d74] do_idle+0x2f4/0x380 > [ 14.369953] [c000000002e1ff10] [c000000000169208] > cpu_startup_entry+0x38/0x40 > [ 14.369957] [c000000002e1ff40] [c000000000053484] > start_secondary+0x2a4/0x2b0 > [ 14.369961] [c000000002e1ff90] [c00000000000d254] > start_secondary_prolog+0x10/0x14 > > > cheers >