linux-kernel - [PATCH] x86/irq: Use printk_deferred() on raw_spin

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-next>] [day] [month] [year] [list]
Message-Id: <e68888438cec9a1da53aaa1647720ade638d6ad4.1600705105.git.bristot@redhat.com>
Date:   Mon, 21 Sep 2020 18:22:12 +0200
From:   Daniel Bristot de Oliveira <bristot@...hat.com>
To:     x86@...nel.org
Cc:     Daniel Bristot de Oliveira <bristot@...hat.com>,
        Thomas Gleixner <tglx@...utronix.de>,
        Ingo Molnar <mingo@...hat.com>, Borislav Petkov <bp@...en8.de>,
        "H. Peter Anvin" <hpa@...or.com>, Marc Zyngier <maz@...nel.org>,
        Peter Xu <peterx@...hat.com>,
        Andy Lutomirski <luto@...nel.org>,
        Bjorn Helgaas <bhelgaas@...gle.com>,
        linux-kernel@...r.kernel.org
Subject: [PATCH] x86/irq: Use printk_deferred() on raw_spin_lock() protected sections

While testing hotplug I got this BUG:

 =============================
 [ BUG: Invalid wait context ]
 5.9.0-rc5+ #3 Not tainted
 -----------------------------
 migration/2/20 is trying to lock:
 ffffffffb4315778 (&port->lock){-.-.}-{3:3}, at: serial8250_console_write+0x8e/0x380
 other info that might help us debug this:
 context-{5:5}
 4 locks held by migration/2/20:
  #0: ffff91622a3ff4c0 (&irq_desc_lock_class){-.-.}-{2:2}, at: irq_migrate_all_off_this_cpu+0x41/0x2f0
  #1: ffffffffb2c509b8 (vector_lock){-.-.}-{2:2}, at: irq_force_complete_move+0x2a/0x70
  #2: ffffffffb2c7cec0 (console_lock){+.+.}-{0:0}, at: printk+0x48/0x4a
  #3: ffffffffb2c7cbe0 (console_owner){....}-{0:0}, at: console_unlock+0x1af/0x650
 stack backtrace:
 CPU: 2 PID: 20 Comm: migration/2 Not tainted 5.9.0-rc5+ #3
 Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.13.0-2.fc32 04/01/2014
 Call Trace:
  dump_stack+0x8b/0xb8
  __lock_acquire.cold+0x1ce/0x333
  ? stack_trace_save+0x3b/0x50
  ? save_trace+0x3f/0x360
  lock_acquire+0xbf/0x3e0
  ? serial8250_console_write+0x8e/0x380
  _raw_spin_lock_irqsave+0x48/0x60
  ? serial8250_console_write+0x8e/0x380
  serial8250_console_write+0x8e/0x380
  ? console_unlock+0x1e8/0x650
  console_unlock+0x3f3/0x650
  ? printk+0x48/0x4a
  vprintk_emit+0x1b1/0x440
  printk+0x48/0x4a
  irq_force_complete_move.cold+0xf/0x14
  irq_migrate_all_off_this_cpu+0xfa/0x2f0
  fixup_irqs+0x25/0xe8
  cpu_disable_common+0x2b8/0x2d0
  native_cpu_disable+0x18/0x30
  take_cpu_down+0x2f/0xa0
  multi_cpu_stop+0x6d/0x130
  ? stop_machine_yield+0x10/0x10
  cpu_stopper_thread+0x7b/0x110
  ? smpboot_thread_fn+0x26/0x1e0
  smpboot_thread_fn+0x10b/0x1e0
  ? smpboot_register_percpu_thread+0xf0/0xf0
  kthread+0x13a/0x150
  ? kthread_create_worker_on_cpu+0x40/0x40
  ret_from_fork+0x22/0x30
  smpboot: CPU 2 is now offline
 =============================

It was caused by printk() inside a code section protected by a
raw_spin_lock() that ended up calling a serial console that
uses a regular spin_lock().

Use the printk_deferred() to avoid calling the serial console
in a raw_spin_lock() protected section.

Signed-off-by: Daniel Bristot de Oliveira <bristot@...hat.com>
Suggested-by: Thomas Gleixner <tglx@...utronix.de>
Cc: Thomas Gleixner <tglx@...utronix.de>
Cc: Ingo Molnar <mingo@...hat.com>
Cc: Borislav Petkov <bp@...en8.de>
Cc: "H. Peter Anvin" <hpa@...or.com>
Cc: Marc Zyngier <maz@...nel.org>
Cc: Peter Xu <peterx@...hat.com>
Cc: Andy Lutomirski <luto@...nel.org>
Cc: Bjorn Helgaas <bhelgaas@...gle.com>
Cc: x86@...nel.org
Cc: linux-kernel@...r.kernel.org
---
 arch/x86/kernel/apic/vector.c | 20 ++++++++++++--------
 1 file changed, 12 insertions(+), 8 deletions(-)

diff --git a/arch/x86/kernel/apic/vector.c b/arch/x86/kernel/apic/vector.c
index f8a56b5dc29f..1a0e5535b8ac 100644
--- a/arch/x86/kernel/apic/vector.c
+++ b/arch/x86/kernel/apic/vector.c
@@ -406,8 +406,9 @@ static int activate_reserved(struct irq_data *irqd)
 	 */
 	if (!cpumask_subset(irq_data_get_effective_affinity_mask(irqd),
 			    irq_data_get_affinity_mask(irqd))) {
-		pr_warn("irq %u: Affinity broken due to vector space exhaustion.\n",
-			irqd->irq);
+		printk_deferred(KERN_WARNING
+				"irq %u: Affinity broken due to vector space exhaustion.\n",
+				irqd->irq);
 	}
 
 	return ret;
@@ -1012,8 +1013,9 @@ void irq_force_complete_move(struct irq_desc *desc)
 		 * so we have the necessary information when a problem in that
 		 * area arises.
 		 */
-		pr_warn("IRQ fixup: irq %d move in progress, old vector %d\n",
-			irqd->irq, vector);
+		printk_deferred(KERN_WARNING
+				"IRQ fixup: irq %d move in progress, old vector %d\n",
+				irqd->irq, vector);
 	}
 	free_moved_vector(apicd);
 unlock:
@@ -1034,15 +1036,17 @@ int lapic_can_unplug_cpu(void)
 	tomove = irq_matrix_allocated(vector_matrix);
 	avl = irq_matrix_available(vector_matrix, true);
 	if (avl < tomove) {
-		pr_warn("CPU %u has %u vectors, %u available. Cannot disable CPU\n",
-			cpu, tomove, avl);
+		printk_deferred(KERN_WARNING
+				"CPU %u has %u vectors, %u available. Cannot disable CPU\n",
+				cpu, tomove, avl);
 		ret = -ENOSPC;
 		goto out;
 	}
 	rsvd = irq_matrix_reserved(vector_matrix);
 	if (avl < rsvd) {
-		pr_warn("Reserved vectors %u > available %u. IRQ request may fail\n",
-			rsvd, avl);
+		printk_deferred(KERN_WARNING
+				"Reserved vectors %u > available %u. IRQ request may fail\n",
+				rsvd, avl);
 	}
 out:
 	raw_spin_unlock(&vector_lock);
-- 
2.26.2