Re: Linux 6.3-rc2
From: Guenter Roeck
Date: Mon Mar 13 2023 - 20:52:58 EST
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