printk: Add force_early_printk boot param

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

This still leaves vprintk_nmi() outside of the kbd reach, should that be fixed too?

Cc Jason Wessel <[email protected]>

Signed-off-by Peter Zijlstra (Intel) <[email protected]>

---
 kernel/printk/printk.c |   18 ++++++------------
 1 file changed, 6 insertions(+), 12 deletions(-)

kernel/printk/printk.c +5 -2

@@ -1811,6 +1811,11 @@ asmlinkage int vprintk_emit(int facility
 	int printed_len;
 	bool in_sched = false;
 
+#ifdef CONFIG_KGDB_KDB
+	if (unlikely(kdb_trap_printk && kdb_printf_cpu < 0))
+		return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args);
+#endif
+
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
 		in_sched = true;

@@ -1903,18 +1908,7 @@ EXPORT_SYMBOL(printk_emit);
 
 int vprintk_default(const char *fmt, va_list args)
 {
-	int r;
-

kernel/printk/printk.c +1 -0

+	return vprintk_emit(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
 }
 EXPORT_SYMBOL_GPL(vprintk_default);
 

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

This still leaves vprintk_nmi() outside of the kbd reach, should that be fixed too?

Cc Jason Wessel <[email protected]>

Signed-off-by Peter Zijlstra (Intel) <[email protected]>

---
 kernel/printk/printk.c |   18 ++++++------------
 1 file changed, 6 insertions(+), 12 deletions(-)

Or can the kdb console commands be called in NMI context?

Quoted 1 line · Petr Mladek

Or can the kdb console commands be called in NMI context?

IIRC most of KDB runs from NMI context.

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

This still leaves vprintk_nmi() outside of the kbd reach, should that be fixed too?

From 0da097266f617c2d62956f3abc8e5f39f119c674 Mon Sep 17 00:00:00 2001

Hi,

I thought about this a lot from several angles. And I would prefer sligly different placement, see the patch below.

Quoted 2 lines · Peter Zijlstra

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

Sigh, printk() API is pretty complicated and this export made it much worse. Well, there are two things:

First, kdb_trap_printk name is a bit misleading. It is not a generic trap of any printk message. Instead it seems to be used to redirect only particular messages from some existing functions, e.g. show_regs() called from kdb_dumpregs().

Second, it seems that the only user of the exported vprintk_emit() is dev_vprintk_emit(). I believe that code using this wrapper is not called in the sections where kdb_trap_printk is incremented.

Quoted 17 lines · Petr Mladek

Hi,

I thought about this a lot from several angles. And I would prefer sligly different placement, see the patch below.

Quoted 2 lines · Peter Zijlstra

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

Sigh, printk() API is pretty complicated and this export made it much worse. Well, there are two things:

First, kdb_trap_printk name is a bit misleading. It is not a generic trap of any printk message. Instead it seems to be used to redirect only particular messages from some existing functions, e.g. show_regs() called from kdb_dumpregs().

Quoted 3 lines

Second, it seems that the only user of the exported vprintk_emit() is dev_vprintk_emit(). I believe that code using this wrapper is not called in the sections where kdb_trap_printk is incremented.

Well, I wonder if we should go even further and stop exporting vprintk_emit(). IMHO, the only reason was dev_print_emit() and the ability to pass the extra "dict" parameter.

My aim is to redirect all the exported interfaces into vprintk_func (need another name?) where the right implementation will be chosen by the context (NMI, printk_safe, kdb, deferred?, printk_early, normal).

In each case, I would like to have all these re-directions on a single place to make the printk() code better readable.

IMHO, it would make sense to do this clean up first before this patchset adds more twists. But I am afraid that we will meet some problems and it make take longer. I am open for opinions.

Best Regards,
Petr

Quoted 22 lines · Petr Mladek

Quoted 20 lines · Petr Mladek

Hi,

I thought about this a lot from several angles. And I would prefer sligly different placement, see the patch below.

Quoted 2 lines · Peter Zijlstra

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

Sigh, printk() API is pretty complicated and this export made it much worse. Well, there are two things:

First, kdb_trap_printk name is a bit misleading. It is not a generic trap of any printk message. Instead it seems to be used to redirect only particular messages from some existing functions, e.g. show_regs() called from kdb_dumpregs().

Second, it seems that the only user of the exported vprintk_emit() is dev_vprintk_emit(). I believe that code using this wrapper is not called in the sections where kdb_trap_printk is incremented.

Quoted 3 lines

Well, I wonder if we should go even further and stop exporting vprintk_emit(). IMHO, the only reason was dev_print_emit() and the ability to pass the extra "dict" parameter.

You have my blessing there, but the device folks might have an opinion on that; Cc'ed Gregkh.

Quoted 23 lines · Peter Zijlstra

Quoted 22 lines · Petr Mladek

Quoted 20 lines · Petr Mladek

Hi,

I thought about this a lot from several angles. And I would prefer sligly different placement, see the patch below.

Quoted 2 lines · Peter Zijlstra

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

Sigh, printk() API is pretty complicated and this export made it much worse. Well, there are two things:

First, kdb_trap_printk name is a bit misleading. It is not a generic trap of any printk message. Instead it seems to be used to redirect only particular messages from some existing functions, e.g. show_regs() called from kdb_dumpregs().

Second, it seems that the only user of the exported vprintk_emit() is dev_vprintk_emit(). I believe that code using this wrapper is not called in the sections where kdb_trap_printk is incremented.

Quoted 6 lines

Quoted 3 lines

Well, I wonder if we should go even further and stop exporting vprintk_emit(). IMHO, the only reason was dev_print_emit() and the ability to pass the extra "dict" parameter.

You have my blessing there, but the device folks might have an opinion on that; Cc'ed Gregkh.

Hm, we "need" that dict option, otherwise the whole dev_printk() family of messages will not work properly, right?

Or am I missing something? If you can figure out a way to still support the same thing (we need a prefix at the beginning of the message that shows the device/driver/binding/etc that emitted the message), that's fine with me, I'm not wed to vprintk_emit() :)

Quoted 31 lines · Greg Kroah-Hartman

Quoted 23 lines · Peter Zijlstra

Quoted 22 lines · Petr Mladek

Quoted 20 lines · Petr Mladek

Hi,

I thought about this a lot from several angles. And I would prefer sligly different placement, see the patch below.

Quoted 2 lines · Peter Zijlstra

Some people figured vprintk_emit() makes for a nice API and exported it, bypassing the kdb trap.

Sigh, printk() API is pretty complicated and this export made it much worse. Well, there are two things:

First, kdb_trap_printk name is a bit misleading. It is not a generic trap of any printk message. Instead it seems to be used to redirect only particular messages from some existing functions, e.g. show_regs() called from kdb_dumpregs().

Second, it seems that the only user of the exported vprintk_emit() is dev_vprintk_emit(). I believe that code using this wrapper is not called in the sections where kdb_trap_printk is incremented.

Quoted 6 lines

Quoted 3 lines

Well, I wonder if we should go even further and stop exporting vprintk_emit(). IMHO, the only reason was dev_print_emit() and the ability to pass the extra "dict" parameter.

You have my blessing there, but the device folks might have an opinion on that; Cc'ed Gregkh.

Quoted 7 lines

Hm, we "need" that dict option, otherwise the whole dev_printk() family of messages will not work properly, right?

Or am I missing something? If you can figure out a way to still support the same thing (we need a prefix at the beginning of the message that shows the device/driver/binding/etc that emitted the message), that's fine with me, I'm not wed to vprintk_emit() :)

Nope, this doesn't seem to deal with the prefix, except in some odd way that is tied to the dynamic debugging logic. I really don't know what this does anymore. Joe wrote it in 2012 as part of the dynamic debug code.

Joe, any thoughts?

Quoted 24 lines · Greg Kroah-Hartman

Quoted 10 lines · Greg Kroah-Hartman

Quoted 8 lines · Peter Zijlstra

Quoted 4 lines · Petr Mladek

On Thu 2017-10-12 11:45:37, Petr Mladek wrote:
Well, I wonder if we should go even further and stop exporting vprintk_emit(). IMHO, the only reason was dev_print_emit() and the ability to pass the extra "dict" parameter.

You have my blessing there, but the device folks might have an opinion on that; Cc'ed Gregkh.

Quoted 7 lines

Hm, we "need" that dict option, otherwise the whole dev_printk() family of messages will not work properly, right?

Or am I missing something? If you can figure out a way to still support the same thing (we need a prefix at the beginning of the message that shows the device/driver/binding/etc that emitted the message), that's fine with me, I'm not wed to vprintk_emit() :)

Nope, this doesn't seem to deal with the prefix, except in some odd way that is tied to the dynamic debugging logic. I really don't know what this does anymore. Joe wrote it in 2012 as part of the dynamic debug code.

Quoted 1 line

Joe, any thoughts?

Man I hate rabbit-holes. I need a few days as I'm otherwise busy.

This stuff has been broken for half a decade now.
Perhaps it doesn't need fixing?

In any case, printk needs a thorough breaking up
and refactoring.

Pushing around at its edges just makes it worse.

vprintk_emit came from Kay Sievers.

commit 7ff9554bb578ba02166071d2d487b7fc7d860d62
Author: Kay Sievers <[email protected]>
Date:   Thu May 3 02:29:13 2012 +0200

    printk: convert byte-buffer to variable-length record buffer

It seems printk_emit is also exported and unused.

I think that it is safe after all, see the commit message in the patch below.

Please add that kernel parameter to Documentation/admin-guide/kernel-parameters.txt.

Quoted 1 line · Randy Dunlap

Please add that kernel parameter to Documentation/admin-guide/kernel-parameters.txt.

Something like so?

Documentation/admin-guide/kernel-parameters.txt +5 -0

@@ -1165,6 +1165,11 @@
 			parameter will force ia64_sal_cache_flush to call
 			ia64_pal_cache_flush instead of SAL_CACHE_FLUSH.
 
+	force_early_printk
+			Forcefully uses early_console (as per earlyprintk=)
+			usage for regular printk, bypassing everything,
+			including the syslog (dmesg will be empty).
+
 	forcepae [X86-32]
 			Forcefully enable Physical Address Extension (PAE).
 			Many Pentium M systems disable PAE but may have a

Add add the 'force_early_printk' kernel parameter to override printk() and force it into early_printk(). This bypasses all the cruft and fail from printk() and makes things work again.

Signed-off-by Peter Zijlstra (Intel) <[email protected]>

---
 kernel/printk/printk.c |   68 +++++++++++++++++++++++++++++++++----------------
 1 file changed, 47 insertions(+), 21 deletions(-)

kernel/printk/printk.c +47 -21

@@ -365,6 +365,42 @@ __packed __aligned(4)
 #endif
 ;
 
+#ifdef CONFIG_EARLY_PRINTK
+struct console *early_console;
+
+static bool __read_mostly force_early_printk;
+
+static int __init force_early_printk_setup(char *str)
+{
+	force_early_printk = true;
+	return 0;
+}
+early_param("force_early_printk", force_early_printk_setup);
+
+static int early_vprintk(const char *fmt, va_list args)
+{
+	char buf[512];
+	int n;
+
+	n = vscnprintf(buf, sizeof(buf), fmt, args);
+	early_console->write(early_console, buf, n);
+
+	return n;
+}
+
+asmlinkage __visible void early_printk(const char *fmt, ...)
+{
+	va_list ap;
+
+	if (!early_console)
+		return;
+
+	va_start(ap, fmt);
+	early_vprintk(fmt, ap);
+	va_end(ap);
+}
+#endif
+
 /*
  * The logbuf_lock protects kmsg buffer, indices, counters.  This can be taken
  * within the scheduler's rq lock. It must be released before calling

@@ -1816,6 +1852,11 @@ asmlinkage int vprintk_emit(int facility
 		return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args);
 #endif
 
+#ifdef CONFIG_EARLY_PRINTK
+	if (force_early_printk && early_console)
+		return early_vprintk(fmt, args);
+#endif
+
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
 		in_sched = true;

@@ -1939,7 +1980,12 @@ asmlinkage __visible int printk(const ch
 	int r;
 
 	va_start(args, fmt);
-	r = vprintk_func(fmt, args);
+#ifdef CONFIG_EARLY_PRINTK
+	if (force_early_printk && early_console)
+		r = vprintk_default(fmt, args);
+	else
+#endif
+		r = vprintk_func(fmt, args);
 	va_end(args);
 
 	return r;

@@ -1975,26 +2021,6 @@ static size_t msg_print_text(const struc
 static bool suppress_message_printing(int level) { return false; }
 #endif /* CONFIG_PRINTK */
 
-#ifdef CONFIG_EARLY_PRINTK
-struct console *early_console;
-
-asmlinkage __visible void early_printk(const char *fmt, ...)
-{
-	va_list ap;
-	char buf[512];
-	int n;
-
-	if (!early_console)
-		return;
-
-	va_start(ap, fmt);
-	n = vscnprintf(buf, sizeof(buf), fmt, ap);
-	va_end(ap);
-
-	early_console->write(early_console, buf, n);
-}
-#endif
-
 static int __add_preferred_console(char *name, int idx, char *options,
 				   char *brl_options)
 {

Add add the 'force_early_printk' kernel parameter to override printk() and force it into early_printk(). This bypasses all the cruft and fail from printk() and makes things work again.

Signed-off-by Peter Zijlstra (Intel) <[email protected]>

---
 kernel/printk/printk.c |   68 +++++++++++++++++++++++++++++++++----------------
 1 file changed, 47 insertions(+), 21 deletions(-)

kernel/printk/printk.c +1 -0

@@ -365,6 +365,42 @@ __packed __aligned(4)
 #endif
 ;
 
+#ifdef CONFIG_EARLY_PRINTK

kernel/printk/printk.c +5 -0

@@ -1816,6 +1852,11 @@ asmlinkage int vprintk_emit(int facility
 		return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args);
 #endif
 
+#ifdef CONFIG_EARLY_PRINTK
+	if (force_early_printk && early_console)
+		return early_vprintk(fmt, args);
+#endif
+
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
 		in_sched = true;

kernel/printk/printk.c __packed __aligned(4) · line 378

Quoted 11 lines · Peter Zijlstra

kernel/printk/printk.c +11 -0

+#ifdef CONFIG_EARLY_PRINTK
+struct console *early_console;
+
+static bool __read_mostly force_early_printk;
+
+static int __init force_early_printk_setup(char *str)
+{
+	force_early_printk = true;
+	return 0;
+}
+early_param("force_early_printk", force_early_printk_setup);

The parameter is currently used only when CONFIG_PRINTK is enabled. But CONFIG_EARLY_PRINTK is independent. What would be your preferred behavior when CONFIG_PRINTK is disabled, please?

Quoted 15 lines

kernel/printk/printk.c +5 -0

@@ -1816,6 +1852,11 @@ asmlinkage int vprintk_emit(int facility
 		return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args);
 #endif
 
+#ifdef CONFIG_EARLY_PRINTK
+	if (force_early_printk && early_console)
+		return early_vprintk(fmt, args);
+#endif
+
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
 		in_sched = true;

@@ -1939,7 +1980,12 @@ asmlinkage __visible int printk(const ch
 	int r;
 

kernel/printk/printk.c asmlinkage __visible int printk(const ch · line 1988

Quoted 8 lines

kernel/printk/printk.c +6 -1

 	va_start(args, fmt);
-	r = vprintk_func(fmt, args);
+#ifdef CONFIG_EARLY_PRINTK
+	if (force_early_printk && early_console)
+		r = vprintk_default(fmt, args);
+	else
+#endif
+		r = vprintk_func(fmt, args);

There is rather theoretical race. We skip vprintk_func() because we believe that vprintk_default()/vprintk_emit() would choose handle this by early_printk().

Quoted 17 lines · Petr Mladek

kernel/printk/printk.c __packed __aligned(4) · line 378

Quoted 11 lines · Peter Zijlstra

kernel/printk/printk.c +11 -0

+#ifdef CONFIG_EARLY_PRINTK
+struct console *early_console;
+
+static bool __read_mostly force_early_printk;
+
+static int __init force_early_printk_setup(char *str)
+{
+	force_early_printk = true;
+	return 0;
+}
+early_param("force_early_printk", force_early_printk_setup);

The parameter is currently used only when CONFIG_PRINTK is enabled. But CONFIG_EARLY_PRINTK is independent. What would be your preferred behavior when CONFIG_PRINTK is disabled, please?

Can we even have !PRINTK && EARLY_PRINTK? If so it seems to me continued usage of early_printk() is what makes most sense.

Quoted 15 lines

Quoted 15 lines

kernel/printk/printk.c +5 -0

@@ -1816,6 +1852,11 @@ asmlinkage int vprintk_emit(int facility
 		return vkdb_printf(KDB_MSGSRC_PRINTK, fmt, args);
 #endif
 
+#ifdef CONFIG_EARLY_PRINTK
+	if (force_early_printk && early_console)
+		return early_vprintk(fmt, args);
+#endif
+
 	if (level == LOGLEVEL_SCHED) {
 		level = LOGLEVEL_DEFAULT;
 		in_sched = true;

@@ -1939,7 +1980,12 @@ asmlinkage __visible int printk(const ch
 	int r;
 

Quoted 12 lines

kernel/printk/printk.c asmlinkage __visible int printk(const ch · line 1988

Quoted 8 lines

kernel/printk/printk.c +6 -1

 	va_start(args, fmt);
-	r = vprintk_func(fmt, args);
+#ifdef CONFIG_EARLY_PRINTK
+	if (force_early_printk && early_console)
+		r = vprintk_default(fmt, args);
+	else
+#endif
+		r = vprintk_func(fmt, args);

There is rather theoretical race. We skip vprintk_func() because we believe that vprintk_default()/vprintk_emit() would choose handle this by early_printk().

Do you mean if someone were to toggle force_early_printk at runtime?

The reason I did it like this and not use that function pointer thing is that I didn't want to risk anybody hijacking my output ever.

Or we should call early_printk() from printk() also when PRINTK is disabled.

Quoted 1 line

Do you mean if someone were to toggle force_early_printk at runtime?

Or that someone unregisters the early console.

Quoted 3 lines

Can we even have !PRINTK && EARLY_PRINTK? If so it seems to me continued usage of early_printk() is what makes most sense.

Yes, !PRINTK && EARLY_PRINTK is possible at the moment. It makes some sense because EARLY_PRINTK needs only consoles and they are needed also for !PRINTK stuff.

We either should define force_early_printk only when PRINTK is enabled.

Quoted 2 lines

The reason I did it like this and not use that function pointer thing is that I didn't want to risk anybody hijacking my output ever.

I understand. I think about refactoring the code so that all *printk*() variants call printk_func(). This function could then call the right printk implementation according to the context or global setting.

This way we could have all the logic on a single place and avoid the race.

Note that printk_func() is not longer a pointer. It is a function since the commit 099f1c84c0052ec1b2 ("printk: introduce per-cpu safe_print seq buffer").

In order to avoid multiple CPUs banging on the serial port at the same time, add simple serialization. This explicitly deals with nested contexts (like IRQs etc.).

Signed-off-by Peter Zijlstra (Intel) <[email protected]>

---
 kernel/printk/printk.c |   35 ++++++++++++++++++++++++++++++++++-
 1 file changed, 34 insertions(+), 1 deletion(-)

kernel/printk/printk.c +6 -1

@@ -378,14 +378,47 @@ static int __init force_early_printk_set
 }
 early_param("force_early_printk", force_early_printk_setup);
 
+static int early_printk_cpu = -1;
+
 static int early_vprintk(const char *fmt, va_list args)
 {
+	int n, cpu, old;
 	char buf[512];
-	int n;
+
+	cpu = get_cpu();
+	/*

kernel/printk/printk.c +18 -0

+			old = cmpxchg(&early_printk_cpu, -1, cpu);
+			if (old == -1)
+				break;
+		}
+		/*
+		 * Allow recursion for interrupts and the like.
+		 */
+		if (old == cpu)
+			break;
+
+		cpu_relax();
+	}
 
 	n = vscnprintf(buf, sizeof(buf), fmt, args);
 	early_console->write(early_console, buf, n);
 
+	/*
+	 * Unlock -- in case @old == @cpu, this is a no-op.
+	 */
+	smp_store_release(&early_printk_cpu, old);
+	put_cpu();
+
 	return n;
 }
 

Quoted 12 lines · On Thu, 28 Sep 2017 14:18:26 +0200 Peter Zijlstra <[email protected]> wrote:

static int early_vprintk(const char *fmt, va_list args) {

kernel/printk/printk.c +9 -0

+	int n, cpu, old;
 	char buf[512];
+
+	cpu = get_cpu();
+	/*
+	 * Test-and-Set inter-cpu spinlock with recursion.
+	 */
+	for (;;) {
+		/*
+		 * c-cas to avoid the exclusive bouncing on spin.

kernel/printk/printk.c static int __init force_early_printk_set · line 399

Quoted 5 lines

kernel/printk/printk.c +5 -0

+		 * Depends on the memory barrier implied by cmpxchg
+		 * for ACQUIRE semantics.
+		 */
+		old = READ_ONCE(early_printk_cpu);
+		if (old == -1) {

If old != -1 and old != cpu, is it possible that the CPU could have fetched an old value, and never try to fetch it again?

The cmpxchg memory barrier only happens when old == -1.

Quoted 24 lines

kernel/printk/printk.c +18 -0

+			old = cmpxchg(&early_printk_cpu, -1, cpu);
+			if (old == -1)
+				break;
+		}
+		/*
+		 * Allow recursion for interrupts and the like.
+		 */
+		if (old == cpu)
+			break;
+
+		cpu_relax();
+	}
 
 	n = vscnprintf(buf, sizeof(buf), fmt, args);
 	early_console->write(early_console, buf, n);
 
+	/*
+	 * Unlock -- in case @old == @cpu, this is a no-op.
+	 */
+	smp_store_release(&early_printk_cpu, old);
+	put_cpu();
+
 	return n;
 }

Quoted 14 lines · Steven Rostedt

Quoted 12 lines · On Thu, 28 Sep 2017 14:18:26 +0200 Peter Zijlstra <[email protected]> wrote:

static int early_vprintk(const char *fmt, va_list args) {

kernel/printk/printk.c +9 -0

+	int n, cpu, old;
 	char buf[512];
+
+	cpu = get_cpu();
+	/*
+	 * Test-and-Set inter-cpu spinlock with recursion.
+	 */
+	for (;;) {
+		/*
+		 * c-cas to avoid the exclusive bouncing on spin.

Quoted 8 lines

kernel/printk/printk.c static int __init force_early_printk_set · line 399

Quoted 5 lines

kernel/printk/printk.c +5 -0

+		 * Depends on the memory barrier implied by cmpxchg
+		 * for ACQUIRE semantics.
+		 */
+		old = READ_ONCE(early_printk_cpu);
+		if (old == -1) {  

If old != -1 and old != cpu, is it possible that the CPU could have fetched an old value, and never try to fetch it again?

What? If old != -1 and old != cpu, we'll hit the cpu_relax() and do the READ_ONCE() again. The READ_ONCE() guarantees we'll do the load again, as does the barrier() implied by cpu_relax().

Quoted 2 lines

The cmpxchg memory barrier only happens when old == -1.

Yeah, so?

Quoted 24 lines

Quoted 24 lines

kernel/printk/printk.c +18 -0

+			old = cmpxchg(&early_printk_cpu, -1, cpu);
+			if (old == -1)
+				break;
+		}
+		/*
+		 * Allow recursion for interrupts and the like.
+		 */
+		if (old == cpu)
+			break;
+
+		cpu_relax();
+	}
 
 	n = vscnprintf(buf, sizeof(buf), fmt, args);
 	early_console->write(early_console, buf, n);
 
+	/*
+	 * Unlock -- in case @old == @cpu, this is a no-op.
+	 */
+	smp_store_release(&early_printk_cpu, old);
+	put_cpu();
+
 	return n;
 }  

Quoted 6 lines

Quoted 2 lines

If old != -1 and old != cpu, is it possible that the CPU could have fetched an old value, and never try to fetch it again?

What? If old != -1 and old != cpu, we'll hit the cpu_relax() and do the READ_ONCE() again. The READ_ONCE() guarantees we'll do the load again, as does the barrier() implied by cpu_relax().

I'm more worried about other architectures that don't have as strong of a cache coherency.

Quoted 24 lines · On Wed, 4 Oct 2017 11:08:30 +0200 Peter Zijlstra <[email protected]> wrote:

Quoted 14 lines · Steven Rostedt

Quoted 12 lines · On Thu, 28 Sep 2017 14:18:26 +0200 Peter Zijlstra <[email protected]> wrote:

static int early_vprintk(const char *fmt, va_list args) {

kernel/printk/printk.c +9 -0

+	int n, cpu, old;
 	char buf[512];
+
+	cpu = get_cpu();
+	/*
+	 * Test-and-Set inter-cpu spinlock with recursion.
+	 */
+	for (;;) {
+		/*
+		 * c-cas to avoid the exclusive bouncing on spin.

Quoted 8 lines

kernel/printk/printk.c static int __init force_early_printk_set · line 399

Quoted 5 lines

kernel/printk/printk.c +5 -0

+		 * Depends on the memory barrier implied by cmpxchg
+		 * for ACQUIRE semantics.
+		 */
+		old = READ_ONCE(early_printk_cpu);
+		if (old == -1) {  

If old != -1 and old != cpu, is it possible that the CPU could have fetched an old value, and never try to fetch it again?

Quoted 3 lines

What? If old != -1 and old != cpu, we'll hit the cpu_relax() and do the READ_ONCE() again. The READ_ONCE() guarantees we'll do the load again, as does the barrier() implied by cpu_relax().

I'm more worried about other architectures that don't have as strong of a cache coherency.

[ Added Paul as he knows a lot about odd architectures ]

Is there any architecture that we support that can have the following:

	CPU0			CPU1
	----			----
			    early_printk_cpu = 1
 for (;;)
   old = READ_ONCE(early_printk_cpu);
   [ old = 1 ]

			    early_printk_cpu = -1

   [...]
   cpu_relax();
   old = READ_ONCE(early_printk_cpu);

   [ but the CPU uses the cache and not the memory? ]

   old = 1;

-- Steve

Quoted 29 lines

Quoted 2 lines

The cmpxchg memory barrier only happens when old == -1.

Yeah, so?

Quoted 24 lines

Quoted 24 lines

kernel/printk/printk.c +18 -0

+			old = cmpxchg(&early_printk_cpu, -1, cpu);
+			if (old == -1)
+				break;
+		}
+		/*
+		 * Allow recursion for interrupts and the like.
+		 */
+		if (old == cpu)
+			break;
+
+		cpu_relax();
+	}
 
 	n = vscnprintf(buf, sizeof(buf), fmt, args);
 	early_console->write(early_console, buf, n);
 
+	/*
+	 * Unlock -- in case @old == @cpu, this is a no-op.
+	 */
+	smp_store_release(&early_printk_cpu, old);
+	put_cpu();
+
 	return n;
 }  

Quoted 7 lines

I'm more worried about other architectures that don't have as strong of a cache coherency.

[ Added Paul as he knows a lot about odd architectures ]

Is there any architecture that we support that can have the following:

Quoted 16 lines

	CPU0			CPU1
	----			----
			    early_printk_cpu = 1
 for (;;)
   old = READ_ONCE(early_printk_cpu);
   [ old = 1 ]

			    early_printk_cpu = -1

   [...]
   cpu_relax();
   old = READ_ONCE(early_printk_cpu);

   [ but the CPU uses the cache and not the memory? ]

   old = 1;  

If you use READ_ONCE(), then all architectures I know of enforce full ordering for accesses to a single variable. (If you don't use READ_ONCE(), then in theory Itanium can reorder reads.) Me, I would argue for WRITE_ONCE() as well to prevent store tearing.

It is only when you have at least two variables and at least two threads than things start getting really "interesting". ;-)

My question is not about ordering, but about coherency. Can you have one CPU read a variable that goes into cache, and keep using the cached variable every time the program asks to read it, instead of going out to memory.

Quoted 5 lines · Steven Rostedt

My question is not about ordering, but about coherency. Can you have one CPU read a variable that goes into cache, and keep using the cached variable every time the program asks to read it, instead of going out to memory.

No, not on a coherent system.

Quoted 5 lines · Steven Rostedt

My question is not about ordering, but about coherency. Can you have one CPU read a variable that goes into cache, and keep using the cached variable every time the program asks to read it, instead of going out to memory.

No, not on a coherent system.

If you use READ_ONCE(), then all architectures I know of enforce full ordering for accesses to a single variable. (If you don't use READ_ONCE(), then in theory Itanium can reorder reads.) Me, I would argue for WRITE_ONCE() as well to prevent store tearing.

Quoted 4 lines · Paul E. McKenney

If you use READ_ONCE(), then all architectures I know of enforce full ordering for accesses to a single variable. (If you don't use READ_ONCE(), then in theory Itanium can reorder reads.) Me, I would argue for WRITE_ONCE() as well to prevent store tearing.

Note that the stores are either cmpxchg() or smp_store_release() both of which imply a WRITE_ONCE().

Most all printk() bits are terminally broken because they rely on the scheduler and blocking locks to function, making them unsuitable for debugging the scheduler and NMI context things.

but what's up with that scheduler thing I keep hearing about, must be something new, can I disable it in kconfig? it seems to be conflicting with CONFIG_PRINTK.