[PATCH v3] lockdep: Move the emergency section out of print_irqtrace_events()

[PATCH v3] lockdep: Move the emergency section out of print_irqtrace_events()

[Breno Leitao]

Commit 59cd94ef8009 ("lockdep: Mark emergency sections in lockdep
splats") made print_irqtrace_events() enter an nbcon emergency section
by itself. That was meant for lockdep splats, but the function is also
used outside lockdep (by verbose KCSAN reports, the soft and hard
lockup detectors, etc).

For KCSAN, as print_report() runs with the raw report_lock held and
interrupts disabled, so every verbose report writes out the whole
console backlog under report_lock. Other CPUs that detect a race in the
meantime spin on report_lock with interrupts disabled, as the lock is
taken before rate_limit_report() gets a chance to drop the report.

That causes this type of problems (as seen in Meta's fleet):

  BUG: KCSAN: data-race in mlx5e_poll_tx_cq+0x5d8/0x998
  ...
  irq event stamp: 28975074
  smp: csd: Detected non-responsive CSD lock (#2) on CPU#35, waiting 5000000052 ns for CPU#26 ipi_mb+0x0/0x18(0x0).
  smp: csd: Detected non-responsive CSD lock (#3) on CPU#65, waiting 5000000020 ns for CPU#00 do_nothing+0x0/0x18(0x0).
  watchdog: CPU71: Watchdog detected hard LOCKUP on cpu 0
  Kernel panic - not syncing: Hard LOCKUP

Drop the emergency section from print_irqtrace_events() and enter it
around the call in check_flags(), the only lockdep splat that prints
the irqtrace events outside of one. The other splats and __warn()
already wrap their whole output in an emergency section.

Fixes: 59cd94ef8009 ("lockdep: Mark emergency sections in lockdep splats")
Suggested-by: John Ogness <john.ogness@linutronix.de>
Signed-off-by: Breno Leitao <leitao@debian.org>
---
Changes in v3:
- Drop the emergency section from print_irqtrace_events() and enter it
  in check_flags(), instead of adding __print_irqtrace_events() for
  KCSAN, so every non-lockdep caller is covered (John Ogness)
- Enter it around print_irqtrace_events() only, not around the whole of
  check_flags(), as DEBUG_LOCKS_WARN_ON() already WARN()s (John Ogness)
- Don't enter it in lockdep_cleanup_dead_cpu(), as that is not a lockdep
  splat (John Ogness)
- Retitle with a lockdep: prefix and reword the commit message, as the
  patch now only touches lockdep.c
- Add Suggested-by: John Ogness
- Link to v2: https://patch.msgid.link/20261104-kcsan-irqtrace-emergency-v2-1-ceafc0098a25@debian.org

Changes in v2:
- Retitled and reworded the commit message: a KCSAN report is not an
  emergency, report_lock only makes it worse (John Ogness)
- Add Fixes: tag (John Ogness)
- Link to v1: https://patch.msgid.link/20261103-kcsan-irqtrace-emergency-v1-1-162288205435@debian.org
---
 kernel/locking/lockdep.c | 9 ++++-----
 1 file changed, 4 insertions(+), 5 deletions(-)

diff --git a/kernel/locking/lockdep.c b/kernel/locking/lockdep.c
index c3dc84a7cef26f..71f1b4b8f06d57 100644
--- a/kernel/locking/lockdep.c
+++ b/kernel/locking/lockdep.c
@@ -4245,8 +4245,6 @@ void print_irqtrace_events(struct task_struct *curr)
 {
 	const struct irqtrace_events *trace = &curr->irqtrace;
 
-	nbcon_cpu_emergency_enter();
-
 	printk("irq event stamp: %u\n", trace->irq_events);
 	printk("hardirqs last  enabled at (%u): [<%px>] %pS\n",
 		trace->hardirq_enable_event, (void *)trace->hardirq_enable_ip,
@@ -4260,8 +4258,6 @@ void print_irqtrace_events(struct task_struct *curr)
 	printk("softirqs last disabled at (%u): [<%px>] %pS\n",
 		trace->softirq_disable_event, (void *)trace->softirq_disable_ip,
 		(void *)trace->softirq_disable_ip);
-
-	nbcon_cpu_emergency_exit();
 }
 
 static int HARDIRQ_verbose(struct lock_class *class)
@@ -5797,8 +5793,11 @@ static noinstr void check_flags(unsigned long flags)
 	}
 #endif
 
-	if (!debug_locks)
+	if (!debug_locks) {
+		nbcon_cpu_emergency_enter();
 		print_irqtrace_events(current);
+		nbcon_cpu_emergency_exit();
+	}
 
 	instrumentation_end();
 #endif

---
base-commit: 6628e7d4c6b25c8d18f1345e3a20d21829aae7e4
change-id: 20261103-kcsan-irqtrace-emergency-f11dd338a43c

Best regards,
--  
Breno Leitao <leitao@debian.org>

Re: [PATCH v3] lockdep: Move the emergency section out of print_irqtrace_events()

[John Ogness]

On 2026-11-09, Breno Leitao <leitao@debian.org> wrote:
> Commit 59cd94ef8009 ("lockdep: Mark emergency sections in lockdep
> splats") made print_irqtrace_events() enter an nbcon emergency section
> by itself. That was meant for lockdep splats, but the function is also
> used outside lockdep (by verbose KCSAN reports, the soft and hard
> lockup detectors, etc).
>
> For KCSAN, as print_report() runs with the raw report_lock held and
> interrupts disabled, so every verbose report writes out the whole
> console backlog under report_lock. Other CPUs that detect a race in the
> meantime spin on report_lock with interrupts disabled, as the lock is
> taken before rate_limit_report() gets a chance to drop the report.
>
> That causes this type of problems (as seen in Meta's fleet):
>
>   BUG: KCSAN: data-race in mlx5e_poll_tx_cq+0x5d8/0x998
>   ...
>   irq event stamp: 28975074
>   smp: csd: Detected non-responsive CSD lock (#2) on CPU#35, waiting 5000000052 ns for CPU#26 ipi_mb+0x0/0x18(0x0).
>   smp: csd: Detected non-responsive CSD lock (#3) on CPU#65, waiting 5000000020 ns for CPU#00 do_nothing+0x0/0x18(0x0).
>   watchdog: CPU71: Watchdog detected hard LOCKUP on cpu 0
>   Kernel panic - not syncing: Hard LOCKUP
>
> Drop the emergency section from print_irqtrace_events() and enter it
> around the call in check_flags(), the only lockdep splat that prints
> the irqtrace events outside of one. The other splats and __warn()
> already wrap their whole output in an emergency section.
>
> Fixes: 59cd94ef8009 ("lockdep: Mark emergency sections in lockdep splats")
> Suggested-by: John Ogness <john.ogness@linutronix.de>
> Signed-off-by: Breno Leitao <leitao@debian.org>

Reviewed-by: John Ogness <john.ogness@linutronix.de>