lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <dc031bc7-8ca4-7ca7-c24f-9db65b5547e4@roeck-us.net>
Date:   Mon, 13 Mar 2023 17:52:49 -0700
From:   Guenter Roeck <linux@...ck-us.net>
To:     Frederic Weisbecker <frederic@...nel.org>,
        Linus Torvalds <torvalds@...ux-foundation.org>
Cc:     "Paul E. McKenney" <paulmck@...nel.org>,
        Peter Zijlstra <peterz@...radead.org>,
        Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
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

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ