[PATCH 0/6] improve OPAL cosole flushing and locking

[PATCH 0/6] improve OPAL cosole flushing and locking

[Nicholas Piggin]

This series of patches aims to improve the robustness of the OPAL
console by simplifying and removing locks. If this code is interrupted
due to a panic or xmon request, it may block the xmon IO or panic
console flush because they use the opal console too.

So reducing locking and relaxing atomicity requirements is important
for improving kernel debugging.

Nicholas Piggin (6):
  powerpc/powernv: opal-kmsg use flush fallback from console code
  powerpc/powernv: Implement and use opal_flush_console
  powerpc/powernv: Remove OPALv1 support from opal console driver
  powerpc/powernv: move opal console flushing to udbg
  powerpc/powernv: implement opal_put_chars_nonatomic
  drivers/tty/hvc: remove unexplained "just in case" spin delay

 arch/powerpc/include/asm/opal.h            |   2 +
 arch/powerpc/platforms/powernv/opal-kmsg.c |  38 +-----
 arch/powerpc/platforms/powernv/opal.c      | 141 ++++++++++++++-------
 drivers/tty/hvc/hvc_opal.c                 |  17 ++-
 4 files changed, 106 insertions(+), 92 deletions(-)

-- 
2.17.0

[PATCH 1/6] powerpc/powernv: opal-kmsg use flush fallback from console code

[Nicholas Piggin]

Use the more refined and tested event polling loop from opal_put_chars
as the fallback console flush in the opal-kmsg path. This loop is used
by the console driver today, whereas the opal-kmsg fallback is not
likely to have been used for years.

Use WARN_ONCE rather than a printk when the fallback is invoked to
prepare for moving the console flush into a common function.

Cc: Russell Currey <ruscur@russell.cc>
Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
---
 arch/powerpc/platforms/powernv/opal-kmsg.c | 15 ++++++---------
 1 file changed, 6 insertions(+), 9 deletions(-)

diff --git a/arch/powerpc/platforms/powernv/opal-kmsg.c b/arch/powerpc/platforms/powernv/opal-kmsg.c
index f8f41ccce75f..fd2bbf4fd6dc 100644
--- a/arch/powerpc/platforms/powernv/opal-kmsg.c
+++ b/arch/powerpc/platforms/powernv/opal-kmsg.c
@@ -51,20 +51,17 @@ static void force_opal_console_flush(struct kmsg_dumper *dumper,
 		} while (rc == OPAL_PARTIAL); /* More to flush */
 
 	} else {
-		int i;
+		__be64 evt;
 
+		WARN_ONCE(1, "opal: OPAL_CONSOLE_FLUSH missing.\n");
 		/*
 		 * If OPAL_CONSOLE_FLUSH is not implemented in the firmware,
 		 * the console can still be flushed by calling the polling
-		 * function enough times to flush the buffer.  We don't know
-		 * how much output still needs to be flushed, but we can be
-		 * generous since the kernel is in panic and doesn't need
-		 * to do much else.
+		 * function while it has OPAL_EVENT_CONSOLE_OUTPUT events.
 		 */
-		printk(KERN_NOTICE "opal: OPAL_CONSOLE_FLUSH missing.\n");
-		for (i = 0; i < 1024; i++) {
-			opal_poll_events(NULL);
-		}
+		do {
+			opal_poll_events(&evt);
+		} while (be64_to_cpu(evt) & OPAL_EVENT_CONSOLE_OUTPUT);
 	}
 }
 
-- 
2.17.0

Re: [PATCH 1/6] powerpc/powernv: opal-kmsg use flush fallback from console code

[Russell Currey]

On Mon, 2018-04-09 at 15:40 +1000, Nicholas Piggin wrote:
> Use the more refined and tested event polling loop from
> opal_put_chars
> as the fallback console flush in the opal-kmsg path. This loop is
> used
> by the console driver today, whereas the opal-kmsg fallback is not
> likely to have been used for years.
> 
> Use WARN_ONCE rather than a printk when the fallback is invoked to
> prepare for moving the console flush into a common function.
> 
> Cc: Russell Currey <ruscur@russell.cc>
> Signed-off-by: Nicholas Piggin <npiggin@gmail.com>

Reviewed-by: Russell Currey <ruscur@russell.cc>

[PATCH 2/6] powerpc/powernv: Implement and use opal_flush_console

[Nicholas Piggin]

A new console flushing firmware API was introduced to replace event
polling loops, and implemented in opal-kmsg with affddff69c55e
("powerpc/powernv: Add a kmsg_dumper that flushes console output on
panic"), to flush the console in the panic path.

The OPAL console driver has other situations where interrupts are off
and it needs to flush the console synchronously. These still use a
polling loop.

So move the opal-kmsg flush code to opal_flush_console, and use the
new function in opal-kmsg and opal_put_chars.

Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Cc: Russell Currey <ruscur@russell.cc>
Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
---
 arch/powerpc/include/asm/opal.h            |  1 +
 arch/powerpc/platforms/powernv/opal-kmsg.c | 35 ++----------------
 arch/powerpc/platforms/powernv/opal.c      | 42 +++++++++++++++++++---
 3 files changed, 42 insertions(+), 36 deletions(-)

diff --git a/arch/powerpc/include/asm/opal.h b/arch/powerpc/include/asm/opal.h
index 03e1a920491e..bbff49fab0e5 100644
--- a/arch/powerpc/include/asm/opal.h
+++ b/arch/powerpc/include/asm/opal.h
@@ -303,6 +303,7 @@ extern void opal_configure_cores(void);
 
 extern int opal_get_chars(uint32_t vtermno, char *buf, int count);
 extern int opal_put_chars(uint32_t vtermno, const char *buf, int total_len);
+extern int opal_flush_console(uint32_t vtermno);
 
 extern void hvc_opal_init_early(void);
 
diff --git a/arch/powerpc/platforms/powernv/opal-kmsg.c b/arch/powerpc/platforms/powernv/opal-kmsg.c
index fd2bbf4fd6dc..55691950d981 100644
--- a/arch/powerpc/platforms/powernv/opal-kmsg.c
+++ b/arch/powerpc/platforms/powernv/opal-kmsg.c
@@ -12,7 +12,6 @@
  */
 
 #include <linux/kmsg_dump.h>
-#include <linux/delay.h>
 
 #include <asm/opal.h>
 #include <asm/opal-api.h>
@@ -24,11 +23,9 @@
  * may not be completely printed.  This function does not actually dump the
  * message, it just ensures that OPAL completely flushes the console buffer.
  */
-static void force_opal_console_flush(struct kmsg_dumper *dumper,
+static void kmsg_dump_opal_console_flush(struct kmsg_dumper *dumper,
 				     enum kmsg_dump_reason reason)
 {
-	s64 rc;
-
 	/*
 	 * Outside of a panic context the pollers will continue to run,
 	 * so we don't need to do any special flushing.
@@ -36,37 +33,11 @@ static void force_opal_console_flush(struct kmsg_dumper *dumper,
 	if (reason != KMSG_DUMP_PANIC)
 		return;
 
-	if (opal_check_token(OPAL_CONSOLE_FLUSH)) {
-		do  {
-			rc = OPAL_BUSY;
-			while (rc == OPAL_BUSY || rc == OPAL_BUSY_EVENT) {
-				rc = opal_console_flush(0);
-				if (rc == OPAL_BUSY_EVENT) {
-					mdelay(OPAL_BUSY_DELAY_MS);
-					opal_poll_events(NULL);
-				} else if (rc == OPAL_BUSY) {
-					mdelay(OPAL_BUSY_DELAY_MS);
-				}
-			}
-		} while (rc == OPAL_PARTIAL); /* More to flush */
-
-	} else {
-		__be64 evt;
-
-		WARN_ONCE(1, "opal: OPAL_CONSOLE_FLUSH missing.\n");
-		/*
-		 * If OPAL_CONSOLE_FLUSH is not implemented in the firmware,
-		 * the console can still be flushed by calling the polling
-		 * function while it has OPAL_EVENT_CONSOLE_OUTPUT events.
-		 */
-		do {
-			opal_poll_events(&evt);
-		} while (be64_to_cpu(evt) & OPAL_EVENT_CONSOLE_OUTPUT);
-	}
+	opal_flush_console(0);
 }
 
 static struct kmsg_dumper opal_kmsg_dumper = {
-	.dump = force_opal_console_flush
+	.dump = kmsg_dump_opal_console_flush
 };
 
 void __init opal_kmsg_init(void)
diff --git a/arch/powerpc/platforms/powernv/opal.c b/arch/powerpc/platforms/powernv/opal.c
index 0f03199a8664..d54ac3736c34 100644
--- a/arch/powerpc/platforms/powernv/opal.c
+++ b/arch/powerpc/platforms/powernv/opal.c
@@ -350,7 +350,6 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 	__be64 olen;
 	s64 len, rc;
 	unsigned long flags;
-	__be64 evt;
 
 	if (!opal.entry)
 		return -ENODEV;
@@ -371,7 +370,7 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 		/* Closed -> drop characters */
 		if (rc)
 			return total_len;
-		opal_poll_events(NULL);
+		opal_flush_console(vtermno);
 		return -EAGAIN;
 	}
 
@@ -410,12 +409,47 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 		 * things a bit later to limit that to synchronous path
 		 * such as the kernel console and xmon/udbg
 		 */
+		opal_flush_console(vtermno);
+	}
+	spin_unlock_irqrestore(&opal_write_lock, flags);
+
+	return written;
+}
+
+int opal_flush_console(uint32_t vtermno)
+{
+	s64 rc;
+
+	if (!opal_check_token(OPAL_CONSOLE_FLUSH)) {
+		__be64 evt;
+
+		WARN_ONCE(1, "opal: OPAL_CONSOLE_FLUSH missing.\n");
+		/*
+		 * If OPAL_CONSOLE_FLUSH is not implemented in the firmware,
+		 * the console can still be flushed by calling the polling
+		 * function while it has OPAL_EVENT_CONSOLE_OUTPUT events.
+		 */
 		do {
 			opal_poll_events(&evt);
 		} while (be64_to_cpu(evt) & OPAL_EVENT_CONSOLE_OUTPUT);
+
+		return OPAL_SUCCESS;
 	}
-	spin_unlock_irqrestore(&opal_write_lock, flags);
-	return written;
+
+	do  {
+		rc = OPAL_BUSY;
+		while (rc == OPAL_BUSY || rc == OPAL_BUSY_EVENT) {
+			rc = opal_console_flush(vtermno);
+			if (rc == OPAL_BUSY_EVENT) {
+				mdelay(OPAL_BUSY_DELAY_MS);
+				opal_poll_events(NULL);
+			} else if (rc == OPAL_BUSY) {
+				mdelay(OPAL_BUSY_DELAY_MS);
+			}
+		}
+	} while (rc == OPAL_PARTIAL); /* More to flush */
+
+	return opal_error_code(rc);
 }
 
 static int opal_recover_mce(struct pt_regs *regs,
-- 
2.17.0

Re: [PATCH 2/6] powerpc/powernv: Implement and use opal_flush_console

[Russell Currey]

On Mon, 2018-04-09 at 15:40 +1000, Nicholas Piggin wrote:
> A new console flushing firmware API was introduced to replace event
> polling loops, and implemented in opal-kmsg with affddff69c55e
> ("powerpc/powernv: Add a kmsg_dumper that flushes console output on
> panic"), to flush the console in the panic path.
> 
> The OPAL console driver has other situations where interrupts are off
> and it needs to flush the console synchronously. These still use a
> polling loop.
> 
> So move the opal-kmsg flush code to opal_flush_console, and use the
> new function in opal-kmsg and opal_put_chars.
> 
> Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
> Cc: Russell Currey <ruscur@russell.cc>
> Signed-off-by: Nicholas Piggin <npiggin@gmail.com>

Reviewed-by: Russell Currey <ruscur@russell.cc>

[PATCH 3/6] powerpc/powernv: Remove OPALv1 support from opal console driver

[Nicholas Piggin]

opal_put_chars deals with partial writes because in OPALv1,
opal_console_write_buffer_space did not work correctly. That firmware
is not supported.

This reworks the opal_put_chars code to no longer deal with partial
writes and turn them into full writes. Partial write handling is still
supported in terms of what gets returned to the caller, but it may not
go to the console atomically. A warning message is printed in this
case.

This allows console flushing to be moved out of the opal_write_lock
spinlock. That could cause the lock to be held for long periods if the
console is busy (especially if it was being spammed by firmware),
which is dangerous because the lock is taken by xmon to debug the
system. Flushing outside the lock improves the situation a bit.

Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
---
 arch/powerpc/platforms/powernv/opal.c | 86 +++++++++++++--------------
 1 file changed, 40 insertions(+), 46 deletions(-)

diff --git a/arch/powerpc/platforms/powernv/opal.c b/arch/powerpc/platforms/powernv/opal.c
index d54ac3736c34..a045c446a910 100644
--- a/arch/powerpc/platforms/powernv/opal.c
+++ b/arch/powerpc/platforms/powernv/opal.c
@@ -346,10 +346,10 @@ int opal_get_chars(uint32_t vtermno, char *buf, int count)
 
 int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 {
-	int written = 0;
-	__be64 olen;
-	s64 len, rc;
 	unsigned long flags;
+	int written;
+	__be64 olen;
+	s64 rc;
 
 	if (!opal.entry)
 		return -ENODEV;
@@ -357,62 +357,56 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 	/* We want put_chars to be atomic to avoid mangling of hvsi
 	 * packets. To do that, we first test for room and return
 	 * -EAGAIN if there isn't enough.
-	 *
-	 * Unfortunately, opal_console_write_buffer_space() doesn't
-	 * appear to work on opal v1, so we just assume there is
-	 * enough room and be done with it
 	 */
 	spin_lock_irqsave(&opal_write_lock, flags);
 	rc = opal_console_write_buffer_space(vtermno, &olen);
-	len = be64_to_cpu(olen);
-	if (rc || len < total_len) {
-		spin_unlock_irqrestore(&opal_write_lock, flags);
+	if (rc || be64_to_cpu(olen) < total_len) {
 		/* Closed -> drop characters */
 		if (rc)
-			return total_len;
-		opal_flush_console(vtermno);
-		return -EAGAIN;
+			written = total_len;
+		else
+			written = -EAGAIN;
+		goto out;
 	}
 
-	/* We still try to handle partial completions, though they
-	 * should no longer happen.
-	 */
-
-	while (total_len > 0) {
-		olen = cpu_to_be64(total_len);
-
-		rc = OPAL_BUSY;
-		while (rc == OPAL_BUSY || rc == OPAL_BUSY_EVENT) {
-			rc = opal_console_write(vtermno, &olen, data);
-			if (rc == OPAL_BUSY_EVENT) {
-				mdelay(OPAL_BUSY_DELAY_MS);
-				opal_poll_events(NULL);
-			} else if (rc == OPAL_BUSY) {
-				mdelay(OPAL_BUSY_DELAY_MS);
-			}
-		}
-
-		len = be64_to_cpu(olen);
-
-		/* Closed or other error drop */
-		if (rc != OPAL_SUCCESS) {
-			written += total_len; /* drop remaining chars */
-			break;
+	/* Should not get a partial write here because space is available. */
+	olen = cpu_to_be64(total_len);
+	rc = opal_console_write(vtermno, &olen, data);
+	if (rc == OPAL_BUSY || rc == OPAL_BUSY_EVENT) {
+		if (rc == OPAL_BUSY_EVENT) {
+			mdelay(OPAL_BUSY_DELAY_MS);
+			opal_poll_events(NULL);
+		} else if (rc == OPAL_BUSY_EVENT) {
+			mdelay(OPAL_BUSY_DELAY_MS);
 		}
+		written = -EAGAIN;
+		goto out;
+	}
 
-		total_len -= len;
-		data += len;
-		written += len;
+	/* Closed or other error drop */
+	if (rc != OPAL_SUCCESS) {
+		written = opal_error_code(rc);
+		goto out;
+	}
 
-		/* This is a bit nasty but we need that for the console to
-		 * flush when there aren't any interrupts. We will clean
-		 * things a bit later to limit that to synchronous path
-		 * such as the kernel console and xmon/udbg
-		 */
-		opal_flush_console(vtermno);
+	written = be64_to_cpu(olen);
+	if (written < total_len) {
+		/* Should not happen */
+		pr_warn("atomic console write returned partial len=%d written=%d\n", total_len, written);
+		if (!written)
+			written = -EAGAIN;
 	}
+
+out:
 	spin_unlock_irqrestore(&opal_write_lock, flags);
 
+	/* This is a bit nasty but we need that for the console to
+	 * flush when there aren't any interrupts. We will clean
+	 * things a bit later to limit that to synchronous path
+	 * such as the kernel console and xmon/udbg
+	 */
+	opal_flush_console(vtermno);
+
 	return written;
 }
 
-- 
2.17.0

[PATCH 4/6] powerpc/powernv: move opal console flushing to udbg

[Nicholas Piggin]

OPAL console writes do not have to synchronously flush firmware /
hardware buffers unless they are going through the udbg path.

Remove the unconditional flushing from opal_put_chars. Flush if
there was no space in the buffer as an optimisation (callers loop
waiting for success in that case). udbg flushing is moved to
udbg_opal_putc.

Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
---
 arch/powerpc/platforms/powernv/opal.c | 12 +++++++-----
 drivers/tty/hvc/hvc_opal.c            |  5 +++++
 2 files changed, 12 insertions(+), 5 deletions(-)

diff --git a/arch/powerpc/platforms/powernv/opal.c b/arch/powerpc/platforms/powernv/opal.c
index a045c446a910..b05500a70f58 100644
--- a/arch/powerpc/platforms/powernv/opal.c
+++ b/arch/powerpc/platforms/powernv/opal.c
@@ -400,12 +400,14 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 out:
 	spin_unlock_irqrestore(&opal_write_lock, flags);
 
-	/* This is a bit nasty but we need that for the console to
-	 * flush when there aren't any interrupts. We will clean
-	 * things a bit later to limit that to synchronous path
-	 * such as the kernel console and xmon/udbg
+	/* In the -EAGAIN case, callers loop, so we have to flush the console
+	 * here in case they have interrupts off (and we don't want to wait
+	 * for async flushing if we can make immediate progress here). If
+	 * necessary the API could be made entirely non-flushing if the
+	 * callers had a ->flush API to use.
 	 */
-	opal_flush_console(vtermno);
+	if (written == -EAGAIN)
+		opal_flush_console(vtermno);
 
 	return written;
 }
diff --git a/drivers/tty/hvc/hvc_opal.c b/drivers/tty/hvc/hvc_opal.c
index 2ed07ca6389e..af122ad7f06d 100644
--- a/drivers/tty/hvc/hvc_opal.c
+++ b/drivers/tty/hvc/hvc_opal.c
@@ -275,6 +275,11 @@ static void udbg_opal_putc(char c)
 			count = hvc_opal_hvsi_put_chars(termno, &c, 1);
 			break;
 		}
+
+		/* This is needed for the cosole to flush
+		 * when there aren't any interrupts.
+		 */
+		opal_flush_console(termno);
 	} while(count == 0 || count == -EAGAIN);
 }
 
-- 
2.17.0

[PATCH 5/6] powerpc/powernv: implement opal_put_chars_nonatomic

[Nicholas Piggin]

The RAW console does not need writes to be atomic, so implement a
_nonatomic variant which does not take a spinlock. This API is used
in xmon, so the less locking thta's used, the better chance there is
that a crash can be debugged.

Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
---
 arch/powerpc/include/asm/opal.h       |  1 +
 arch/powerpc/platforms/powernv/opal.c | 35 +++++++++++++++++++--------
 drivers/tty/hvc/hvc_opal.c            |  4 +--
 3 files changed, 28 insertions(+), 12 deletions(-)

diff --git a/arch/powerpc/include/asm/opal.h b/arch/powerpc/include/asm/opal.h
index bbff49fab0e5..66954d671831 100644
--- a/arch/powerpc/include/asm/opal.h
+++ b/arch/powerpc/include/asm/opal.h
@@ -303,6 +303,7 @@ extern void opal_configure_cores(void);
 
 extern int opal_get_chars(uint32_t vtermno, char *buf, int count);
 extern int opal_put_chars(uint32_t vtermno, const char *buf, int total_len);
+extern int opal_put_chars_nonatomic(uint32_t vtermno, const char *buf, int total_len);
 extern int opal_flush_console(uint32_t vtermno);
 
 extern void hvc_opal_init_early(void);
diff --git a/arch/powerpc/platforms/powernv/opal.c b/arch/powerpc/platforms/powernv/opal.c
index b05500a70f58..dc77fc57d1e9 100644
--- a/arch/powerpc/platforms/powernv/opal.c
+++ b/arch/powerpc/platforms/powernv/opal.c
@@ -344,9 +344,9 @@ int opal_get_chars(uint32_t vtermno, char *buf, int count)
 	return 0;
 }
 
-int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
+static int __opal_put_chars(uint32_t vtermno, const char *data, int total_len, bool atomic)
 {
-	unsigned long flags;
+	unsigned long flags = 0 /* shut up gcc */;
 	int written;
 	__be64 olen;
 	s64 rc;
@@ -354,11 +354,8 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 	if (!opal.entry)
 		return -ENODEV;
 
-	/* We want put_chars to be atomic to avoid mangling of hvsi
-	 * packets. To do that, we first test for room and return
-	 * -EAGAIN if there isn't enough.
-	 */
-	spin_lock_irqsave(&opal_write_lock, flags);
+	if (atomic)
+		spin_lock_irqsave(&opal_write_lock, flags);
 	rc = opal_console_write_buffer_space(vtermno, &olen);
 	if (rc || be64_to_cpu(olen) < total_len) {
 		/* Closed -> drop characters */
@@ -391,14 +388,18 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 
 	written = be64_to_cpu(olen);
 	if (written < total_len) {
-		/* Should not happen */
-		pr_warn("atomic console write returned partial len=%d written=%d\n", total_len, written);
+		if (atomic) {
+			/* Should not happen */
+			pr_warn("atomic console write returned partial "
+				"len=%d written=%d\n", total_len, written);
+		}
 		if (!written)
 			written = -EAGAIN;
 	}
 
 out:
-	spin_unlock_irqrestore(&opal_write_lock, flags);
+	if (atomic)
+		spin_unlock_irqrestore(&opal_write_lock, flags);
 
 	/* In the -EAGAIN case, callers loop, so we have to flush the console
 	 * here in case they have interrupts off (and we don't want to wait
@@ -412,6 +413,20 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
 	return written;
 }
 
+int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
+{
+	/* We want put_chars to be atomic to avoid mangling of hvsi
+	 * packets. To do that, we first test for room and return
+	 * -EAGAIN if there isn't enough.
+	 */
+	return __opal_put_chars(vtermno, data, total_len, true);
+}
+
+int opal_put_chars_nonatomic(uint32_t vtermno, const char *data, int total_len)
+{
+	return __opal_put_chars(vtermno, data, total_len, false);
+}
+
 int opal_flush_console(uint32_t vtermno)
 {
 	s64 rc;
diff --git a/drivers/tty/hvc/hvc_opal.c b/drivers/tty/hvc/hvc_opal.c
index af122ad7f06d..e151cfacf2a7 100644
--- a/drivers/tty/hvc/hvc_opal.c
+++ b/drivers/tty/hvc/hvc_opal.c
@@ -51,7 +51,7 @@ static u32 hvc_opal_boot_termno;
 
 static const struct hv_ops hvc_opal_raw_ops = {
 	.get_chars = opal_get_chars,
-	.put_chars = opal_put_chars,
+	.put_chars = opal_put_chars_nonatomic,
 	.notifier_add = notifier_add_irq,
 	.notifier_del = notifier_del_irq,
 	.notifier_hangup = notifier_hangup_irq,
@@ -269,7 +269,7 @@ static void udbg_opal_putc(char c)
 	do {
 		switch(hvc_opal_boot_priv.proto) {
 		case HV_PROTOCOL_RAW:
-			count = opal_put_chars(termno, &c, 1);
+			count = opal_put_chars_nonatomic(termno, &c, 1);
 			break;
 		case HV_PROTOCOL_HVSI:
 			count = hvc_opal_hvsi_put_chars(termno, &c, 1);
-- 
2.17.0

Re: [PATCH 5/6] powerpc/powernv: implement opal_put_chars_nonatomic

[Benjamin Herrenschmidt]

On Mon, 2018-04-09 at 15:40 +1000, Nicholas Piggin wrote:
> The RAW console does not need writes to be atomic, so implement a
> _nonatomic variant which does not take a spinlock. This API is used
> in xmon, so the less locking thta's used, the better chance there is
> that a crash can be debugged.

I find the term "nonatomic" confusing... don't we have a problem if we
start hitting OPAL without a lock where we can't trust
opal_console_write_buffer_space anymore ? I think we need to handle
partial writes in that case. Maybe we should return how much was
written and leave the caller to deal with it.

I was hoping (but that isn't the case) that by nonatomic you actually
meant calls that could be done in a non-atomic context, where we can do
msleep instead of mdelay. That would be handy for the console coming
from the hvc thread (the tty one).

Cheers,
Ben.

> 
> Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
> Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
> ---
>  arch/powerpc/include/asm/opal.h       |  1 +
>  arch/powerpc/platforms/powernv/opal.c | 35 +++++++++++++++++++--------
>  drivers/tty/hvc/hvc_opal.c            |  4 +--
>  3 files changed, 28 insertions(+), 12 deletions(-)
> 
> diff --git a/arch/powerpc/include/asm/opal.h b/arch/powerpc/include/asm/opal.h
> index bbff49fab0e5..66954d671831 100644
> --- a/arch/powerpc/include/asm/opal.h
> +++ b/arch/powerpc/include/asm/opal.h
> @@ -303,6 +303,7 @@ extern void opal_configure_cores(void);
>  
>  extern int opal_get_chars(uint32_t vtermno, char *buf, int count);
>  extern int opal_put_chars(uint32_t vtermno, const char *buf, int total_len);
> +extern int opal_put_chars_nonatomic(uint32_t vtermno, const char *buf, int total_len);
>  extern int opal_flush_console(uint32_t vtermno);
>  
>  extern void hvc_opal_init_early(void);
> diff --git a/arch/powerpc/platforms/powernv/opal.c b/arch/powerpc/platforms/powernv/opal.c
> index b05500a70f58..dc77fc57d1e9 100644
> --- a/arch/powerpc/platforms/powernv/opal.c
> +++ b/arch/powerpc/platforms/powernv/opal.c
> @@ -344,9 +344,9 @@ int opal_get_chars(uint32_t vtermno, char *buf, int count)
>  	return 0;
>  }
>  
> -int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
> +static int __opal_put_chars(uint32_t vtermno, const char *data, int total_len, bool atomic)
>  {
> -	unsigned long flags;
> +	unsigned long flags = 0 /* shut up gcc */;
>  	int written;
>  	__be64 olen;
>  	s64 rc;
> @@ -354,11 +354,8 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
>  	if (!opal.entry)
>  		return -ENODEV;
>  
> -	/* We want put_chars to be atomic to avoid mangling of hvsi
> -	 * packets. To do that, we first test for room and return
> -	 * -EAGAIN if there isn't enough.
> -	 */
> -	spin_lock_irqsave(&opal_write_lock, flags);
> +	if (atomic)
> +		spin_lock_irqsave(&opal_write_lock, flags);
>  	rc = opal_console_write_buffer_space(vtermno, &olen);
>  	if (rc || be64_to_cpu(olen) < total_len) {
>  		/* Closed -> drop characters */
> @@ -391,14 +388,18 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
>  
>  	written = be64_to_cpu(olen);
>  	if (written < total_len) {
> -		/* Should not happen */
> -		pr_warn("atomic console write returned partial len=%d written=%d\n", total_len, written);
> +		if (atomic) {
> +			/* Should not happen */
> +			pr_warn("atomic console write returned partial "
> +				"len=%d written=%d\n", total_len, written);
> +		}
>  		if (!written)
>  			written = -EAGAIN;
>  	}
>  
>  out:
> -	spin_unlock_irqrestore(&opal_write_lock, flags);
> +	if (atomic)
> +		spin_unlock_irqrestore(&opal_write_lock, flags);
>  
>  	/* In the -EAGAIN case, callers loop, so we have to flush the console
>  	 * here in case they have interrupts off (and we don't want to wait
> @@ -412,6 +413,20 @@ int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
>  	return written;
>  }
>  
> +int opal_put_chars(uint32_t vtermno, const char *data, int total_len)
> +{
> +	/* We want put_chars to be atomic to avoid mangling of hvsi
> +	 * packets. To do that, we first test for room and return
> +	 * -EAGAIN if there isn't enough.
> +	 */
> +	return __opal_put_chars(vtermno, data, total_len, true);
> +}
> +
> +int opal_put_chars_nonatomic(uint32_t vtermno, const char *data, int total_len)
> +{
> +	return __opal_put_chars(vtermno, data, total_len, false);
> +}
> +
>  int opal_flush_console(uint32_t vtermno)
>  {
>  	s64 rc;
> diff --git a/drivers/tty/hvc/hvc_opal.c b/drivers/tty/hvc/hvc_opal.c
> index af122ad7f06d..e151cfacf2a7 100644
> --- a/drivers/tty/hvc/hvc_opal.c
> +++ b/drivers/tty/hvc/hvc_opal.c
> @@ -51,7 +51,7 @@ static u32 hvc_opal_boot_termno;
>  
>  static const struct hv_ops hvc_opal_raw_ops = {
>  	.get_chars = opal_get_chars,
> -	.put_chars = opal_put_chars,
> +	.put_chars = opal_put_chars_nonatomic,
>  	.notifier_add = notifier_add_irq,
>  	.notifier_del = notifier_del_irq,
>  	.notifier_hangup = notifier_hangup_irq,
> @@ -269,7 +269,7 @@ static void udbg_opal_putc(char c)
>  	do {
>  		switch(hvc_opal_boot_priv.proto) {
>  		case HV_PROTOCOL_RAW:
> -			count = opal_put_chars(termno, &c, 1);
> +			count = opal_put_chars_nonatomic(termno, &c, 1);
>  			break;
>  		case HV_PROTOCOL_HVSI:
>  			count = hvc_opal_hvsi_put_chars(termno, &c, 1);

Re: [PATCH 5/6] powerpc/powernv: implement opal_put_chars_nonatomic

[Nicholas Piggin]

On Mon, 09 Apr 2018 15:57:55 +1000
Benjamin Herrenschmidt <benh@kernel.crashing.org> wrote:

> On Mon, 2018-04-09 at 15:40 +1000, Nicholas Piggin wrote:
> > The RAW console does not need writes to be atomic, so implement a
> > _nonatomic variant which does not take a spinlock. This API is used
> > in xmon, so the less locking thta's used, the better chance there is
> > that a crash can be debugged.  
> 
> I find the term "nonatomic" confusing...

I guess it is to go with the "atomic" comment for the hvsi console
case -- all characters must get to the console together or not at
all.

> don't we have a problem if we
> start hitting OPAL without a lock where we can't trust
> opal_console_write_buffer_space anymore ? I think we need to handle
> partial writes in that case. Maybe we should return how much was
> written and leave the caller to deal with it.

Yes, the _nonatomic variant doesn't use opal_console_write_buffer_space
and it does handle partial writes by returning written bytes (although
callers generally tend to loop at the moment, we might do something
smarter with them later).

> I was hoping (but that isn't the case) that by nonatomic you actually
> meant calls that could be done in a non-atomic context, where we can do
> msleep instead of mdelay. That would be handy for the console coming
> from the hvc thread (the tty one).

Ah right, no. However we no longer loop until everything is written, so
the hvc console driver (or the console layer) should be able to deal with
that with sleeping. I don't think we need to put it at this level of the
driver, but I don't know much about the console code.

Thanks,
Nick

Re: [PATCH 5/6] powerpc/powernv: implement opal_put_chars_nonatomic

[Benjamin Herrenschmidt]

On Mon, 2018-04-09 at 16:23 +1000, Nicholas Piggin wrote:
> On Mon, 09 Apr 2018 15:57:55 +1000
> Benjamin Herrenschmidt <benh@kernel.crashing.org> wrote:
> 
> > On Mon, 2018-04-09 at 15:40 +1000, Nicholas Piggin wrote:
> > > The RAW console does not need writes to be atomic, so implement a
> > > _nonatomic variant which does not take a spinlock. This API is used
> > > in xmon, so the less locking thta's used, the better chance there is
> > > that a crash can be debugged.  
> > 
> > I find the term "nonatomic" confusing...
> 
> I guess it is to go with the "atomic" comment for the hvsi console
> case -- all characters must get to the console together or not at
> all.

Yeah ok, it's just that in Linux "atomic" usually means something else
:-) Why not just call it "unlocked" which is what it's about and
matches existing practices thorough the kernel ?

> > don't we have a problem if we
> > start hitting OPAL without a lock where we can't trust
> > opal_console_write_buffer_space anymore ? I think we need to handle
> > partial writes in that case. Maybe we should return how much was
> > written and leave the caller to deal with it.
> 
> Yes, the _nonatomic variant doesn't use opal_console_write_buffer_space
> and it does handle partial writes by returning written bytes (although
> callers generally tend to loop at the moment, we might do something
> smarter with them later).
> 
> > I was hoping (but that isn't the case) that by nonatomic you actually
> > meant calls that could be done in a non-atomic context, where we can do
> > msleep instead of mdelay. That would be handy for the console coming
> > from the hvc thread (the tty one).
> 
> Ah right, no. However we no longer loop until everything is written, so
> the hvc console driver (or the console layer) should be able to deal with
> that with sleeping. I don't think we need to put it at this level of the
> driver, but I don't know much about the console code.

Ok, so hopefully we shouldn't be hitting the delay..

Cheers,
Ben.

Re: [PATCH 5/6] powerpc/powernv: implement opal_put_chars_nonatomic

[Nicholas Piggin]

On Mon, 09 Apr 2018 18:24:46 +1000
Benjamin Herrenschmidt <benh@kernel.crashing.org> wrote:

> On Mon, 2018-04-09 at 16:23 +1000, Nicholas Piggin wrote:
> > On Mon, 09 Apr 2018 15:57:55 +1000
> > Benjamin Herrenschmidt <benh@kernel.crashing.org> wrote:
> >   
> > > On Mon, 2018-04-09 at 15:40 +1000, Nicholas Piggin wrote:  
> > > > The RAW console does not need writes to be atomic, so implement a
> > > > _nonatomic variant which does not take a spinlock. This API is used
> > > > in xmon, so the less locking thta's used, the better chance there is
> > > > that a crash can be debugged.    
> > > 
> > > I find the term "nonatomic" confusing...  
> > 
> > I guess it is to go with the "atomic" comment for the hvsi console
> > case -- all characters must get to the console together or not at
> > all.  
> 
> Yeah ok, it's just that in Linux "atomic" usually means something else
> :-) Why not just call it "unlocked" which is what it's about and
> matches existing practices thorough the kernel ?

Sure, I'll change it.
 
> > > don't we have a problem if we
> > > start hitting OPAL without a lock where we can't trust
> > > opal_console_write_buffer_space anymore ? I think we need to handle
> > > partial writes in that case. Maybe we should return how much was
> > > written and leave the caller to deal with it.  
> > 
> > Yes, the _nonatomic variant doesn't use opal_console_write_buffer_space
> > and it does handle partial writes by returning written bytes (although
> > callers generally tend to loop at the moment, we might do something
> > smarter with them later).
> >   
> > > I was hoping (but that isn't the case) that by nonatomic you actually
> > > meant calls that could be done in a non-atomic context, where we can do
> > > msleep instead of mdelay. That would be handy for the console coming
> > > from the hvc thread (the tty one).  
> > 
> > Ah right, no. However we no longer loop until everything is written, so
> > the hvc console driver (or the console layer) should be able to deal with
> > that with sleeping. I don't think we need to put it at this level of the
> > driver, but I don't know much about the console code.  
> 
> Ok, so hopefully we shouldn't be hitting the delay..

I *think* so. It may actually hit it once on the way out, but I don't
know if it's worth adding a new API to avoid it. Probably warrants
somebody to take a look and measure things though.

Actually I did just take a look. The bigger problem actually is because
we do the console flush here and even the "good" hvc path holds an irq
lock in this case:

   dmesg-8334   12d...    0us : _raw_spin_lock_irqsave
   dmesg-8334   12d...    0us : hvc_push <-hvc_write
   dmesg-8334   12d...    1us : opal_put_chars_nonatomic <-hvc_push
   dmesg-8334   12d...    1us : __opal_put_chars <-hvc_push
   dmesg-8334   12d...    2us : opal_flush_console <-__opal_put_chars
   dmesg-8334   12d...    4us!: udelay <-opal_flush_console
   dmesg-8334   12d...  787us : soft_nmi_interrupt <-soft_nmi_common
   dmesg-8334   12d...  787us : printk_nmi_enter <-soft_nmi_interrupt
   dmesg-8334   12d.Z.  788us : rcu_nmi_enter <-soft_nmi_interrupt
   dmesg-8334   12d.Z.  788us : rcu_nmi_exit <-soft_nmi_interrupt
   dmesg-8334   12d...  788us#: printk_nmi_exit <-soft_nmi_interrupt
   dmesg-8334   12d... 10005us*: udelay <-opal_flush_console
   dmesg-8334   12d... 20007us*: udelay <-opal_flush_console
   dmesg-8334   12d... 30020us*: udelay <-opal_flush_console
   dmesg-8334   12d... 40022us*: udelay <-opal_flush_console
   dmesg-8334   12d... 50023us*: udelay <-opal_flush_console
   dmesg-8334   12d... 60024us : opal_error_code <-opal_flush_console
   dmesg-8334   12d... 60025us : _raw_spin_unlock_irqrestore <-hvc_write
   dmesg-8334   12d... 60025us : _raw_spin_unlock_irqrestore
   dmesg-8334   12d... 60025us : trace_hardirqs_on <-_raw_spin_unlock_irqrestore
   dmesg-8334   12d... 60027us : <stack trace>

60ms interrupt off latency waiting for the console to flush (just
running `dmesg` from OpenBMC console).

That requires some reworking of the hvc code, we can't fix it in
the OPAL driver alone.

Thanks,
Nick

[PATCH 6/6] drivers/tty/hvc: remove unexplained "just in case" spin delay

[Nicholas Piggin]

This delay was in the very first OPAL console commit 6.5 years ago.
The firmware console has hardened sufficiently to remove it.

Cc: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
---
 drivers/tty/hvc/hvc_opal.c | 8 +-------
 1 file changed, 1 insertion(+), 7 deletions(-)

diff --git a/drivers/tty/hvc/hvc_opal.c b/drivers/tty/hvc/hvc_opal.c
index e151cfacf2a7..436b98258e60 100644
--- a/drivers/tty/hvc/hvc_opal.c
+++ b/drivers/tty/hvc/hvc_opal.c
@@ -307,14 +307,8 @@ static int udbg_opal_getc(void)
 	int ch;
 	for (;;) {
 		ch = udbg_opal_getc_poll();
-		if (ch == -1) {
-			/* This shouldn't be needed...but... */
-			volatile unsigned long delay;
-			for (delay=0; delay < 2000000; delay++)
-				;
-		} else {
+		if (ch != -1)
 			return ch;
-		}
 	}
 }
 
-- 
2.17.0

Re: [PATCH 6/6] drivers/tty/hvc: remove unexplained "just in case" spin delay

[Benjamin Herrenschmidt]

On Mon, 2018-04-09 at 15:40 +1000, Nicholas Piggin wrote:
> This delay was in the very first OPAL console commit 6.5 years ago.
> The firmware console has hardened sufficiently to remove it.
> 

Reviewed-by: Benjamin Herrenschmidt <benh@kernel.crashing.org>
> Signed-off-by: Nicholas Piggin <npiggin@gmail.com>
> ---
>  drivers/tty/hvc/hvc_opal.c | 8 +-------
>  1 file changed, 1 insertion(+), 7 deletions(-)
> 
> diff --git a/drivers/tty/hvc/hvc_opal.c b/drivers/tty/hvc/hvc_opal.c
> index e151cfacf2a7..436b98258e60 100644
> --- a/drivers/tty/hvc/hvc_opal.c
> +++ b/drivers/tty/hvc/hvc_opal.c
> @@ -307,14 +307,8 @@ static int udbg_opal_getc(void)
>  	int ch;
>  	for (;;) {
>  		ch = udbg_opal_getc_poll();
> -		if (ch == -1) {
> -			/* This shouldn't be needed...but... */
> -			volatile unsigned long delay;
> -			for (delay=0; delay < 2000000; delay++)
> -				;
> -		} else {
> +		if (ch != -1)
>  			return ch;
> -		}
>  	}
>  }
>