MLK-16068 printk: use console_trylock() in console_cpu_notify()

There is no need to always call blocking console_lock() in
console_cpu_notify(), it's quite possible that console_sem can
be locked by other CPU on the system, either already printing
or soon to begin printing the messages. console_lock() in this
case can simply block CPU hotplug for unknown period of time
(console_unlock() is time unbound). Not that hotplug is very
fast, but still, with other CPUs being online and doing
printk() console_cpu_notify() can stuck.

Use console_trylock() instead and opt-out if console_sem is
already acquired from another CPU, since that CPU will do
the printing for us.

Link: http://lkml.kernel.org/r/20170121104729.8585-1-sergey.senozhatsky@gmail.com
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Sebastian Andrzej Siewior <bigeasy@linutronix.de>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: linux-kernel@vger.kernel.org
Signed-off-by: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
Signed-off-by: Petr Mladek <pmladek@suse.com>

This patch also fixes a deadlock that happens if while holding the
console lock someone issues a call that eventually takes the cpu
hotplug lock, like in the case below, where the following happens:

* task Xorg issues an ioctl to the fb layer which takes the console
lock and calls the driver's ioctl routine

* at the same time, task bat-cpuhotplug issue a hotplug cpu enable
operation which takes the cpu hotplug lock and waits for the cpu
bringup operation to complete

* the fb driver calls dma_alloc_coherent which, on this platform,
eventually tries to take the cpu hotplug

* task cpuhp/2 tries to flush the console

* at this point task Xorg waits after task bat-cpuhotplug to release
the cpu hotplug lock which waits after task cpuhp/2 to signal that
the CPU is up which waits after the Xorg to release the console
lock

Linux version 4.9.11-02771-gd85d61b-dirty
CPU: ARMv7 Processor [412fc09a] revision 10 (ARMv7), cr=10c53c7d
CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
OF: fdt:Machine model: Freescale i.MX6 Quad SABRE Smart Device Board

sysrq: SysRq : Show Blocked State

task                PC stack   pid father
cpuhp/2         D    0    18      2 0x00000000
[<80a794ac>] (__schedule) from [<80a79904>] (schedule+0x4c/0xac)
[<80a79904>] (schedule) from [<80a7e680>] (schedule_timeout+0x1e8/0x2fc)
[<80a7e680>] (schedule_timeout) from [<80a7d208>] (__down+0x64/0x9c)
[<80a7d208>] (__down) from [<80174224>] (down+0x44/0x58)
[<80174224>] (down) from [<80181a6c>] (console_lock+0x2c/0x74)
[<80181a6c>] (console_lock) from [<801849b4>] (console_cpu_notify+0x28/0x34)
[<801849b4>] (console_cpu_notify) from [<80150e58>] (notifier_call_chain+0x44/0x84)
[<80150e58>] (notifier_call_chain) from [<8012ed34>] (__cpu_notify+0x38/0x50)
[<8012ed34>] (__cpu_notify) from [<8012ed64>] (notify_online+0x18/0x20)
[<8012ed64>] (notify_online) from [<8012ea4c>] (cpuhp_up_callbacks+0x24/0xd4)
[<8012ea4c>] (cpuhp_up_callbacks) from [<8012f4c8>] (cpuhp_thread_fun+0x13c/0x148)
[<8012f4c8>] (cpuhp_thread_fun) from [<80153544>] (smpboot_thread_fn+0x17c/0x2dc)
[<80153544>] (smpboot_thread_fn) from [<8014f7d8>] (kthread+0xf0/0x108)
[<8014f7d8>] (kthread) from [<801077d0>] (ret_from_fork+0x14/0x24)

bat-cpuhotplug. D    0   841    718 0x00000000
[<80a794ac>] (__schedule) from [<80a79904>] (schedule+0x4c/0xac)
[<80a79904>] (schedule) from [<80a7e680>] (schedule_timeout+0x1e8/0x2fc)
[<80a7e680>] (schedule_timeout) from [<80a7a47c>] (wait_for_common+0xb0/0x160)
[<80a7a47c>] (wait_for_common) from [<8012f600>] (bringup_cpu+0x50/0xa8)
[<8012f600>] (bringup_cpu) from [<8012ea4c>] (cpuhp_up_callbacks+0x24/0xd4)
[<8012ea4c>] (cpuhp_up_callbacks) from [<8012ff58>] (_cpu_up+0xa8/0xec)
[<8012ff58>] (_cpu_up) from [<80130010>] (do_cpu_up+0x74/0x9c)
[<80130010>] (do_cpu_up) from [<80520c88>] (device_online+0x68/0x8c)
[<80520c88>] (device_online) from [<80520d14>] (online_store+0x68/0x74)
[<80520d14>] (online_store) from [<8029842c>] (kernfs_fop_write+0xf4/0x1f8)
[<8029842c>] (kernfs_fop_write) from [<80223da0>] (__vfs_write+0x1c/0x114)
[<80223da0>] (__vfs_write) from [<80224c78>] (vfs_write+0xa4/0x168)
[<80224c78>] (vfs_write) from [<802259c4>] (SyS_write+0x3c/0x90)
[<802259c4>] (SyS_write) from [<80107740>] (ret_fast_syscall+0x0/0x1c)

Xorg            D    0   860    832 0x00000000
[<80a794ac>] (__schedule) from [<80a79904>] (schedule+0x4c/0xac)
[<80a79904>] (schedule) from [<80a79d98>] (schedule_preempt_disabled+0x14/0x20)
[<80a79d98>] (schedule_preempt_disabled) from [<80a7ab10>] (mutex_lock_nested+0x1f8/0x4a4)
[<80a7ab10>] (mutex_lock_nested) from [<8012ef94>] (get_online_cpus+0x78/0xbc)
[<8012ef94>] (get_online_cpus) from [<801e7858>] (lru_add_drain_all+0x48/0x1b4)
[<801e7858>] (lru_add_drain_all) from [<8021f65c>] (migrate_prep+0x8/0x10)
[<8021f65c>] (migrate_prep) from [<801e1bc8>] (alloc_contig_range+0xd0/0x320)
[<801e1bc8>] (alloc_contig_range) from [<80220ec4>] (cma_alloc+0xb8/0x1a8)
[<80220ec4>] (cma_alloc) from [<80113b38>] (__alloc_from_contiguous+0x38/0xd8)
[<80113b38>] (__alloc_from_contiguous) from [<80113c0c>] (cma_allocator_alloc+0x34/0x3c)
[<80113c0c>] (cma_allocator_alloc) from [<80113d88>] (__dma_alloc+0x174/0x338)
[<80113d88>] (__dma_alloc) from [<80113fc8>] (arm_dma_alloc+0x40/0x48)
[<80113fc8>] (arm_dma_alloc) from [<80478a88>] (mxcfb_set_par+0x8ec/0xd7c)
[<80478a88>] (mxcfb_set_par) from [<8045f200>] (fb_set_var+0x1d4/0x358)
[<8045f200>] (fb_set_var) from [<8045f9e8>] (do_fb_ioctl+0x4e4/0x704)
[<8045f9e8>] (do_fb_ioctl) from [<8023773c>] (do_vfs_ioctl+0xa0/0xa10)
[<8023773c>] (do_vfs_ioctl) from [<802380e0>] (SyS_ioctl+0x34/0x5c)
[<802380e0>] (SyS_ioctl) from [<80107740>] (ret_fast_syscall+0x0/0x1c)

Signed-off-by: Octavian Purdila <octavian.purdila@nxp.com>
Reviewed-by: Leonard Crestez <leonard.crestez@nxp.com>

1 files changed, 6 insertions, 5 deletions

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index ab6855a4218b..9ae22e845029 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2171,9 +2171,9 @@ void resume_console(void)
  * @hcpu: unused
  *
  * If printk() is called from a CPU that is not online yet, the messages
- * will be spooled but will not show up on the console.  This function is
- * called when a new CPU comes online (or fails to come up), and ensures
- * that any such output gets printed.
+ * will be printed on the console only if there are CON_ANYTIME consoles.
+ * This function is called when a new CPU comes online (or fails to come
+ * up) or goes offline.
  */
 static int console_cpu_notify(struct notifier_block *self,
 	unsigned long action, void *hcpu)
@@ -2183,8 +2183,9 @@ static int console_cpu_notify(struct notifier_block *self,
 	case CPU_DEAD:
 	case CPU_DOWN_FAILED:
 	case CPU_UP_CANCELED:
-		console_lock();
-		console_unlock();
+		/* If trylock fails, someone else is doing the printing */
+		if (console_trylock())
+			console_unlock();
 	}
 	return NOTIFY_OK;
 }