Messages in this thread Patch in this message | | | Date | Mon, 13 Mar 2023 17:52:49 -0700 | From | Guenter Roeck <> | Subject | Re: Linux 6.3-rc2 |
| |
On 3/13/23 16:11, Frederic Weisbecker wrote: > On Mon, Mar 13, 2023 at 11:21:44AM -0700, Linus Torvalds wrote: [ ... ] > It would be interesting to see what the IRQ is interrupting. For example does it > happen while softirqs are serviced or just disabled? Or are we even outside any > of that? Any chance we can have a deeper stack trace? If not at least a print of > preempt_count() would be helpful. > > Both would be awesome. > > diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c > index 50d4863974e7..a7d1a65e5425 100644 > --- a/kernel/locking/lockdep.c > +++ b/kernel/locking/lockdep.c > @@ -5523,6 +5523,7 @@ static noinstr void check_flags(unsigned long flags) > */ > if (!hardirq_count()) { > if (softirq_count()) { > + printk("preempt_count(): %x", preempt_count()); > /* like the above, but with softirqs */ > DEBUG_LOCKS_WARN_ON(current->softirqs_enabled); > } else { >
That crashed nicely; it didn't like the unconditional printk(). With
diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c index 50d4863974e7..ea4f76e2d815 100644 --- a/kernel/locking/lockdep.c +++ b/kernel/locking/lockdep.c @@ -5524,7 +5524,9 @@ static noinstr void check_flags(unsigned long flags) if (!hardirq_count()) { if (softirq_count()) { /* like the above, but with softirqs */ - DEBUG_LOCKS_WARN_ON(current->softirqs_enabled); + if (DEBUG_LOCKS_WARN_ON(current->softirqs_enabled)) + printk("preempt_count(): %x softirq_count(): %lx", + preempt_count(), softirq_count()); } else { /* lick the above, does it taste good? */ DEBUG_LOCKS_WARN_ON(!current->softirqs_enabled); I got the following (decoded):
[ 11.360487] WARNING: CPU: 0 PID: 233 at kernel/locking/lockdep.c:5527 check_flags (./arch/arm/include/asm/current.h:36 (discriminator 12) ./include/asm-generic/preempt.h:11 (discriminator 12) kernel/locking/lockdep.c:5528 (discriminator 12)) [ 11.361102] DEBUG_LOCKS_WARN_ON(current->softirqs_enabled) [ 11.361173] Modules linked in: [ 11.361730] CPU: 0 PID: 233 Comm: rcS Tainted: G N 6.3.0-rc2-dirty #2 [ 11.361921] Hardware name: Freescale i.MX6 Ultralite (Device Tree) [ 11.362303] unwind_backtrace from show_stack (arch/arm/kernel/traps.c:258) [ 11.362441] show_stack from dump_stack_lvl (lib/dump_stack.c:107 (discriminator 4)) [ 11.362519] dump_stack_lvl from __warn (./include/linux/jump_label.h:260 ./include/linux/jump_label.h:270 ./include/trace/events/error_report.h:69 kernel/panic.c:681) [ 11.362598] __warn from warn_slowpath_fmt (./arch/arm/include/asm/current.h:36 ./include/asm-generic/preempt.h:16 ./include/asm-generic/preempt.h:59 ./include/linux/context_tracking.h:154 kernel/panic.c:706) [ 11.362702] warn_slowpath_fmt from check_flags (./arch/arm/include/asm/current.h:36 (discriminator 12) ./include/asm-generic/preempt.h:11 (discriminator 12) kernel/locking/lockdep.c:5528 (discriminator 12)) [ 11.362780] check_flags from lock_is_held_type (./arch/arm/include/asm/percpu.h:37 kernel/locking/lockdep.c:462 kernel/locking/lockdep.c:5713) [ 11.362851] lock_is_held_type from rcu_read_lock_sched_held (kernel/rcu/update.c:125) [ 11.362933] rcu_read_lock_sched_held from trace_rcu_dyntick (./include/trace/events/rcu.h:480 (discriminator 28)) [ 11.363016] trace_rcu_dyntick from ct_nmi_enter (./arch/arm/include/asm/percpu.h:37 (discriminator 4) ./include/linux/context_tracking_state.h:90 (discriminator 4) kernel/context_tracking.c:301 (discriminator 4)) [ 11.363108] ct_nmi_enter from irq_enter (kernel/softirq.c:625) [ 11.363177] irq_enter from generic_handle_arch_irq (kernel/irq/handle.c:238) [ 11.363251] generic_handle_arch_irq from call_with_stack (arch/arm/lib/call_with_stack.S:45) [ 11.363339] call_with_stack from __irq_svc (arch/arm/kernel/entry-armv.S:232) [ 11.363438] Exception stack(0xd1819f60 to 0xd1819fa8) [ 11.363629] 9f60: ecac8b10 40000000 b6f88418 c1c2607c 00000000 40000000 c4acc00b 00000001 [ 11.363740] 9f80: 00000b00 c0101278 c4acc0f0 00000000 00000051 d1819fb0 c01011c4 c0103c1c [ 11.363833] 9fa0: 00000013 ffffffff [ 11.363896] __irq_svc from vfp_reload_hw (arch/arm/vfp/vfphw.S:149) [ 11.364015] irq event stamp: 1626 [ 11.364069] hardirqs last enabled at (1625): __und_usr (arch/arm/kernel/entry-armv.S:465) [ 11.364199] hardirqs last disabled at (1626): __irq_svc (arch/arm/kernel/entry-armv.S:221) [ 11.364290] softirqs last enabled at (1424): __do_softirq (./arch/arm/include/asm/current.h:36 ./include/asm-generic/preempt.h:11 kernel/softirq.c:415 kernel/softirq.c:600) [ 11.364396] softirqs last disabled at (1323): __irq_exit_rcu (kernel/softirq.c:445 kernel/softirq.c:650) [ 11.364494] ---[ end trace 0000000000000000 ]--- [ 11.364637] preempt_count(): 201 softirq_count(): 200 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ [ 11.364659] irq event stamp: 1626 [ 11.364757] hardirqs last enabled at (1625): __und_usr (arch/arm/kernel/entry-armv.S:465) [ 11.364843] hardirqs last disabled at (1626): __irq_svc (arch/arm/kernel/entry-armv.S:221) [ 11.364926] softirqs last enabled at (1424): __do_softirq (./arch/arm/include/asm/current.h:36 ./include/asm-generic/preempt.h:11 kernel/softirq.c:415 kernel/softirq.c:600) [ 11.365014] softirqs last disabled at (1323): __irq_exit_rcu (kernel/softirq.c:445 kernel/softirq.c:650) Does that tell you anything ?
Thanks, Guenter
| |