The write callback of legacy consoles makes use of spinlocks.
This is not permitted with PREEMPT_RT in atomic contexts.

For PREEMPT_RT, create a new kthread to handle printing of all
the legacy consoles (and nbcon consoles if boot consoles are
registered).

Since, if running from the kthread, the consoles are printing
in a task context, the legacy nbcon printing can use the
device_lock(), write_thread(), device_unlock() callbacks for
printing.

Introduce the macro force_printkthreads() to query if the
forced threading of legacy consoles is in effect.

These changes only affect CONFIG_PREEMPT_RT.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/internal.h |  11 +-
 kernel/printk/nbcon.c    |  54 ++++++---
 kernel/printk/printk.c   | 241 ++++++++++++++++++++++++++++++++-------
 3 files changed, 246 insertions(+), 60 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index 9e027e08918d..b66dfa865591 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -21,6 +21,12 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
 		(con->flags & CON_BOOT) ? "boot" : "",		\
 		con->name, con->index, ##__VA_ARGS__)
 
+#ifdef CONFIG_PREEMPT_RT
+# define force_printkthreads()		(true)
+#else
+# define force_printkthreads()		(false)
+#endif
+
 #ifdef CONFIG_PRINTK
 
 #ifdef CONFIG_PRINTK_CALLER
@@ -92,9 +98,10 @@ void nbcon_free(struct console *con);
 enum nbcon_prio nbcon_get_default_prio(void);
 void nbcon_atomic_flush_pending(void);
 bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
-				   int cookie);
+				   int cookie, bool use_atomic);
 void nbcon_kthread_create(struct console *con);
 void nbcon_wake_threads(void);
+void nbcon_legacy_kthread_create(void);
 
 /*
  * Check if the given console is currently capable and allowed to print
@@ -181,7 +188,7 @@ static inline void nbcon_free(struct console *con) { }
 static inline enum nbcon_prio nbcon_get_default_prio(void) { return NBCON_PRIO_NONE; }
 static inline void nbcon_atomic_flush_pending(void) { }
 static inline bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
-						 int cookie) { return false; }
+						 int cookie, bool use_atomic) { return false; }
 
 static inline bool console_is_usable(struct console *con, short flags,
 				     bool use_atomic) { return false; }
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index 8c92b076c745..e8060b5abdf8 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -1185,9 +1185,10 @@ enum nbcon_prio nbcon_get_default_prio(void)
 }
 
 /*
- * nbcon_atomic_emit_one - Print one record for an nbcon console using the
- *				write_atomic() callback
+ * nbcon_emit_one - Print one record for an nbcon console using the
+ *			specified callback
  * @wctxt:	An initialized write context struct to use for this context
+ * @use_atomic:	True if the write_atomic() callback is to be used
  *
  * Return:	True, when a record has been printed and there are still
  *		pending records. The caller might want to continue flushing.
@@ -1200,7 +1201,7 @@ enum nbcon_prio nbcon_get_default_prio(void)
  * This is an internal helper to handle the locking of the console before
  * calling nbcon_emit_next_record().
  */
-static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
+static bool nbcon_emit_one(struct nbcon_write_context *wctxt, bool use_atomic)
 {
 	struct nbcon_context *ctxt = &ACCESS_PRIVATE(wctxt, ctxt);
 
@@ -1215,7 +1216,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
 	 * The higher priority printing context takes over responsibility
 	 * to print the pending records.
 	 */
-	if (!nbcon_emit_next_record(wctxt, true))
+	if (!nbcon_emit_next_record(wctxt, use_atomic))
 		return false;
 
 	nbcon_context_release(ctxt);
@@ -1232,6 +1233,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
  *		both the console_lock and the SRCU read lock. Otherwise it
  *		is set to false.
  * @cookie:	The cookie from the SRCU read lock.
+ * @use_atomic:	True if the write_atomic() callback is to be used
  *
  * Context:	Any context except NMI.
  * Return:	True, when a record has been printed and there are still
@@ -1247,26 +1249,38 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
  * Essentially it is the nbcon version of console_emit_next_record().
  */
 bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
-				   int cookie)
+				   int cookie, bool use_atomic)
 {
 	struct nbcon_write_context wctxt = { };
 	struct nbcon_context *ctxt = &ACCESS_PRIVATE(&wctxt, ctxt);
 	unsigned long flags;
 	bool progress;
 
-	/* Use the same procedure as console_emit_next_record(). */
-	printk_safe_enter_irqsave(flags);
-	console_lock_spinning_enable();
-	stop_critical_timings();
+	ctxt->console = con;
 
-	ctxt->console	= con;
-	ctxt->prio	= nbcon_get_default_prio();
+	if (use_atomic) {
+		/* Use the same procedure as console_emit_next_record(). */
+		printk_safe_enter_irqsave(flags);
+		console_lock_spinning_enable();
+		stop_critical_timings();
 
-	progress = nbcon_atomic_emit_one(&wctxt);
+		ctxt->prio = nbcon_get_default_prio();
+		progress = nbcon_emit_one(&wctxt, use_atomic);
 
-	start_critical_timings();
-	*handover = console_lock_spinning_disable_and_check(cookie);
-	printk_safe_exit_irqrestore(flags);
+		start_critical_timings();
+		*handover = console_lock_spinning_disable_and_check(cookie);
+		printk_safe_exit_irqrestore(flags);
+	} else {
+		*handover = false;
+
+		con->device_lock(con, &flags);
+		cant_migrate();
+
+		ctxt->prio = nbcon_get_default_prio();
+		progress = nbcon_emit_one(&wctxt, use_atomic);
+
+		con->device_unlock(con, flags);
+	}
 
 	return progress;
 }
@@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
 		 * to handle it.
 		 */
 		do_trigger_flush = true;
-		if (printing_via_unlock && !is_printk_deferred()) {
+		if (!force_printkthreads() &&
+		    printing_via_unlock &&
+		    !is_printk_deferred()) {
 			if (console_trylock()) {
 				do_trigger_flush = false;
 				console_unlock();
@@ -1530,7 +1546,9 @@ void nbcon_cpu_emergency_flush(void)
 
 	nbcon_atomic_flush_pending();
 
-	if (printing_via_unlock && !is_printk_deferred()) {
+	if (!force_printkthreads() &&
+	    printing_via_unlock &&
+	    !is_printk_deferred()) {
 		if (console_trylock())
 			console_unlock();
 	}
@@ -1601,6 +1619,8 @@ static int __init printk_setup_threads(void)
 	printk_threads_enabled = true;
 	for_each_console(con)
 		nbcon_kthread_create(con);
+	if (force_printkthreads() && printing_via_unlock)
+		nbcon_legacy_kthread_create();
 	console_list_unlock();
 	return 0;
 }
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index cf0d612329bf..1c63fd0c1166 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -487,6 +487,9 @@ bool have_boot_console;
 
 #ifdef CONFIG_PRINTK
 DECLARE_WAIT_QUEUE_HEAD(log_wait);
+
+static DECLARE_WAIT_QUEUE_HEAD(legacy_wait);
+
 /* All 3 protected by @syslog_lock. */
 /* the next printk record to read by syslog(READ) or /proc/kmsg */
 static u64 syslog_seq;
@@ -2345,7 +2348,8 @@ asmlinkage int vprintk_emit(int facility, int level,
 			    const struct dev_printk_info *dev_info,
 			    const char *fmt, va_list args)
 {
-	bool do_trylock_unlock = printing_via_unlock;
+	bool do_trylock_unlock = !force_printkthreads() &&
+				 printing_via_unlock;
 	int printed_len;
 
 	/* Suppress unimportant messages after panic happens */
@@ -2468,6 +2472,14 @@ EXPORT_SYMBOL(_printk);
 static bool pr_flush(int timeout_ms, bool reset_on_progress);
 static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress);
 
+static struct task_struct *nbcon_legacy_kthread;
+
+static inline void wake_up_legacy_kthread(void)
+{
+	if (nbcon_legacy_kthread)
+		wake_up_interruptible(&legacy_wait);
+}
+
 #else /* CONFIG_PRINTK */
 
 #define printk_time		false
@@ -2481,6 +2493,8 @@ static u64 syslog_seq;
 static bool pr_flush(int timeout_ms, bool reset_on_progress) { return true; }
 static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progress) { return true; }
 
+static inline void nbcon_legacy_kthread_create(void) { }
+static inline void wake_up_legacy_kthread(void) { }
 #endif /* CONFIG_PRINTK */
 
 #ifdef CONFIG_EARLY_PRINTK
@@ -2726,6 +2740,8 @@ void resume_console(void)
 	}
 	console_srcu_read_unlock(cookie);
 
+	wake_up_legacy_kthread();
+
 	pr_flush(1000, true);
 }
 
@@ -2740,7 +2756,9 @@ void resume_console(void)
  */
 static int console_cpu_notify(unsigned int cpu)
 {
-	if (!cpuhp_tasks_frozen && printing_via_unlock) {
+	if (!force_printkthreads() &&
+	    !cpuhp_tasks_frozen &&
+	    printing_via_unlock) {
 		/* If trylock fails, someone else is doing the printing */
 		if (console_trylock())
 			console_unlock();
@@ -3000,31 +3018,43 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
 		con->dropped = 0;
 	}
 
-	/*
-	 * While actively printing out messages, if another printk()
-	 * were to occur on another CPU, it may wait for this one to
-	 * finish. This task can not be preempted if there is a
-	 * waiter waiting to take over.
-	 *
-	 * Interrupts are disabled because the hand over to a waiter
-	 * must not be interrupted until the hand over is completed
-	 * (@console_waiter is cleared).
-	 */
-	printk_safe_enter_irqsave(flags);
-	console_lock_spinning_enable();
+	/* Write everything out to the hardware. */
 
-	/* Do not trace print latency. */
-	stop_critical_timings();
+	if (force_printkthreads()) {
+		/*
+		 * With forced threading this function is either in a thread
+		 * or panic context. So there is no need for concern about
+		 * printk reentrance or handovers.
+		 */
 
-	/* Write everything out to the hardware. */
-	con->write(con, outbuf, pmsg.outbuf_len);
+		con->write(con, outbuf, pmsg.outbuf_len);
+		con->seq = pmsg.seq + 1;
+	} else {
+		/*
+		 * While actively printing out messages, if another printk()
+		 * were to occur on another CPU, it may wait for this one to
+		 * finish. This task can not be preempted if there is a
+		 * waiter waiting to take over.
+		 *
+		 * Interrupts are disabled because the hand over to a waiter
+		 * must not be interrupted until the hand over is completed
+		 * (@console_waiter is cleared).
+		 */
+		printk_safe_enter_irqsave(flags);
+		console_lock_spinning_enable();
 
-	start_critical_timings();
+		/* Do not trace print latency. */
+		stop_critical_timings();
 
-	con->seq = pmsg.seq + 1;
+		con->write(con, outbuf, pmsg.outbuf_len);
 
-	*handover = console_lock_spinning_disable_and_check(cookie);
-	printk_safe_exit_irqrestore(flags);
+		start_critical_timings();
+
+		con->seq = pmsg.seq + 1;
+
+		*handover = console_lock_spinning_disable_and_check(cookie);
+		printk_safe_exit_irqrestore(flags);
+	}
 skip:
 	return true;
 }
@@ -3088,12 +3118,13 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
 			if ((flags & CON_NBCON) && con->kthread)
 				continue;
 
-			if (!console_is_usable(con, flags, true))
+			if (!console_is_usable(con, flags, !do_cond_resched))
 				continue;
 			any_usable = true;
 
 			if (flags & CON_NBCON) {
-				progress = nbcon_legacy_emit_next_record(con, handover, cookie);
+				progress = nbcon_legacy_emit_next_record(con, handover, cookie,
+									 !do_cond_resched);
 				printk_seq = nbcon_seq_read(con);
 			} else {
 				progress = console_emit_next_record(con, handover, cookie);
@@ -3132,19 +3163,7 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
 	return false;
 }
 
-/**
- * console_unlock - unblock the console subsystem from printing
- *
- * Releases the console_lock which the caller holds to block printing of
- * the console subsystem.
- *
- * While the console_lock was held, console output may have been buffered
- * by printk().  If this is the case, console_unlock(); emits
- * the output prior to releasing the lock.
- *
- * console_unlock(); may be called from any context.
- */
-void console_unlock(void)
+static void console_flush_and_unlock(void)
 {
 	bool do_cond_resched;
 	bool handover;
@@ -3188,6 +3207,32 @@ void console_unlock(void)
 		 */
 	} while (prb_read_valid(prb, next_seq, NULL) && console_trylock());
 }
+
+/**
+ * console_unlock - unblock the console subsystem from printing
+ *
+ * Releases the console_lock which the caller holds to block printing of
+ * the console subsystem.
+ *
+ * While the console_lock was held, console output may have been buffered
+ * by printk().  If this is the case, console_unlock(); emits
+ * the output prior to releasing the lock.
+ *
+ * console_unlock(); may be called from any context.
+ */
+void console_unlock(void)
+{
+	/*
+	 * Forced threading relies on kthread and atomic consoles for
+	 * printing. It never attempts to print from console_unlock().
+	 */
+	if (force_printkthreads()) {
+		__console_unlock();
+		return;
+	}
+
+	console_flush_and_unlock();
+}
 EXPORT_SYMBOL(console_unlock);
 
 /**
@@ -3411,12 +3456,107 @@ void console_start(struct console *console)
 	flags = console_srcu_read_flags(console);
 	if (flags & CON_NBCON)
 		nbcon_kthread_wake(console);
+	else
+		wake_up_legacy_kthread();
 	console_srcu_read_unlock(cookie);
 
 	__pr_flush(console, 1000, true);
 }
 EXPORT_SYMBOL(console_start);
 
+#ifdef CONFIG_PRINTK
+static bool printer_should_wake(void)
+{
+	bool available = false;
+	struct console *con;
+	int cookie;
+
+	if (kthread_should_stop())
+		return true;
+
+	cookie = console_srcu_read_lock();
+	for_each_console_srcu(con) {
+		short flags = console_srcu_read_flags(con);
+		u64 printk_seq;
+
+		/*
+		 * The legacy printer thread is only for legacy consoles,
+		 * unless the nbcon console has no kthread printer.
+		 */
+		if ((flags & CON_NBCON) && con->kthread)
+			continue;
+
+		if (!console_is_usable(con, flags, false))
+			continue;
+
+		if (flags & CON_NBCON) {
+			printk_seq = nbcon_seq_read(con);
+		} else {
+			/*
+			 * It is safe to read @seq because only this
+			 * thread context updates @seq.
+			 */
+			printk_seq = con->seq;
+		}
+
+		if (prb_read_valid(prb, printk_seq, NULL)) {
+			available = true;
+			break;
+		}
+	}
+	console_srcu_read_unlock(cookie);
+
+	return available;
+}
+
+static int nbcon_legacy_kthread_func(void *unused)
+{
+	int error;
+
+	for (;;) {
+		error = wait_event_interruptible(legacy_wait, printer_should_wake());
+
+		if (kthread_should_stop())
+			break;
+
+		if (error)
+			continue;
+
+		console_lock();
+		console_flush_and_unlock();
+	}
+
+	return 0;
+}
+
+void nbcon_legacy_kthread_create(void)
+{
+	struct task_struct *kt;
+
+	lockdep_assert_held(&console_mutex);
+
+	if (!force_printkthreads())
+		return;
+
+	if (!printk_threads_enabled || nbcon_legacy_kthread)
+		return;
+
+	kt = kthread_run(nbcon_legacy_kthread_func, NULL, "pr/legacy");
+	if (IS_ERR(kt)) {
+		pr_err("unable to start legacy printing thread\n");
+		return;
+	}
+
+	nbcon_legacy_kthread = kt;
+
+	/*
+	 * It is important that console printing threads are scheduled
+	 * shortly after a printk call and with generous runtime budgets.
+	 */
+	sched_set_normal(nbcon_legacy_kthread, -20);
+}
+#endif /* CONFIG_PRINTK */
+
 static int __read_mostly keep_bootcon;
 
 static int __init keep_bootcon_setup(char *str)
@@ -3706,6 +3846,7 @@ void register_console(struct console *newcon)
 	} else {
 		have_legacy_console = true;
 		newcon->seq = init_seq;
+		nbcon_legacy_kthread_create();
 	}
 
 	if (newcon->flags & CON_BOOT)
@@ -3873,6 +4014,13 @@ static int unregister_console_locked(struct console *console)
 			nbcon_kthread_create(c);
 	}
 
+#ifdef CONFIG_PRINTK
+	if (!printing_via_unlock && nbcon_legacy_kthread) {
+		kthread_stop(nbcon_legacy_kthread);
+		nbcon_legacy_kthread = NULL;
+	}
+#endif
+
 	return res;
 }
 
@@ -4031,7 +4179,11 @@ static bool __pr_flush(struct console *con, int timeout_ms, bool reset_on_progre
 
 	seq = prb_next_reserve_seq(prb);
 
-	/* Flush the consoles so that records up to @seq are printed. */
+	/*
+	 * Flush the consoles so that records up to @seq are printed.
+	 * Otherwise this function will just wait for the threaded printers
+	 * to print up to @seq.
+	 */
 	if (printing_via_unlock) {
 		console_lock();
 		console_unlock();
@@ -4146,9 +4298,16 @@ static void wake_up_klogd_work_func(struct irq_work *irq_work)
 	int pending = this_cpu_xchg(printk_pending, 0);
 
 	if (pending & PRINTK_PENDING_OUTPUT) {
-		/* If trylock fails, someone else is doing the printing */
-		if (console_trylock())
-			console_unlock();
+		if (force_printkthreads()) {
+			wake_up_legacy_kthread();
+		} else {
+			/*
+			 * If trylock fails, some other context
+			 * will do the printing.
+			 */
+			if (console_trylock())
+				console_unlock();
+		}
 	}
 
 	if (pending & PRINTK_PENDING_WAKEUP)
-- 
2.39.2

On Tue 2024-06-04 01:30:47, John Ogness wrote:
> The write callback of legacy consoles makes use of spinlocks.
> This is not permitted with PREEMPT_RT in atomic contexts.
> 
> For PREEMPT_RT, create a new kthread to handle printing of all
> the legacy consoles (and nbcon consoles if boot consoles are
> registered).
> 
> Since, if running from the kthread, the consoles are printing
> in a task context, the legacy nbcon printing can use the
> device_lock(), write_thread(), device_unlock() callbacks for
> printing.
> 
> Introduce the macro force_printkthreads() to query if the
> forced threading of legacy consoles is in effect.
> 
> These changes only affect CONFIG_PREEMPT_RT.
> 
> Signed-off-by: John Ogness <john.ogness@linutronix.de>
> ---
>  kernel/printk/internal.h |  11 +-
>  kernel/printk/nbcon.c    |  54 ++++++---
>  kernel/printk/printk.c   | 241 ++++++++++++++++++++++++++++++++-------
>  3 files changed, 246 insertions(+), 60 deletions(-)
> 
> diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
> index 9e027e08918d..b66dfa865591 100644
> --- a/kernel/printk/internal.h
> +++ b/kernel/printk/internal.h
> @@ -21,6 +21,12 @@ int devkmsg_sysctl_set_loglvl(struct ctl_table *table, int write,
>  		(con->flags & CON_BOOT) ? "boot" : "",		\
>  		con->name, con->index, ##__VA_ARGS__)
>  
> +#ifdef CONFIG_PREEMPT_RT
> +# define force_printkthreads()		(true)
> +#else
> +# define force_printkthreads()		(false)
> +#endif

It seems that the only purpose of this variable is to decide
whether the nbcon_legacy_kthread will be used or not.

I know that force_printkthreads() has been choosen to correlate with
force_irqthreads(). But the situation is different here. In irq, there
is only one type of kthreads (ksoftirqd). But in printk(), we
have kthreads for nbcon consoles and a special kthread for legacy
consoles.

Also the variable is used together with:

   + printing_via_unlock: boolean variable which is true when
	some console need to be flushed in the legacy loop
	under console_lock().

   + nbcon_legacy_kthread: pointer to task_struct of the kthread
	flushing the console in the legacy loop under console_lock().

   + wake_up_legacy_kthread(): function for waking up nbcon_legacy_kthread()

   + console_emit_next_record(): function emitting the message in
	the legacy loop under console_lock()


It is a crazy mismatch of names ;-) The main used terms are: legacy, unlock,
nbcon, console. From my POV, the most meaningful are: legacy and unlock.

I would suggest to rename:

   + nbcon_legacy_kthread -> printk_legacy_kthread
   + force_printkthreads -> force_legacy_kthread

or another "more legacy" names.

>  #ifdef CONFIG_PRINTK
>  
>  #ifdef CONFIG_PRINTK_CALLER
> @@ -92,9 +98,10 @@ void nbcon_free(struct console *con);
>  enum nbcon_prio nbcon_get_default_prio(void);
>  void nbcon_atomic_flush_pending(void);
>  bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
> -				   int cookie);
> +				   int cookie, bool use_atomic);
>  void nbcon_kthread_create(struct console *con);
>  void nbcon_wake_threads(void);
> +void nbcon_legacy_kthread_create(void);

It is about legacy consoles. It is even implemented in printk.c.
I would call it:

     + legacy_kthread_create()
     + create_legacy_kthread()

> --- a/kernel/printk/nbcon.c
> +++ b/kernel/printk/nbcon.c
> @@ -1232,6 +1233,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
>   *		both the console_lock and the SRCU read lock. Otherwise it
>   *		is set to false.
>   * @cookie:	The cookie from the SRCU read lock.
> + * @use_atomic:	True if the write_atomic() callback is to be used

I would prefer to use a "hint style". Something like:

 * @use_atomic:	Set true when called in an atomic or unknown context.
 *		It affects which callback will be used: write_atomic()
 *		wrt. write_thread().
 *
 *		When false, the write_thread() callback would be called
 *		in a preemtible context unless disabled by the device_lock().
 *		The handover won't be allowed in this mode.

>   * Context:	Any context except NMI.
>   * Return:	True, when a record has been printed and there are still
> @@ -1247,26 +1249,38 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
>   * Essentially it is the nbcon version of console_emit_next_record().
>   */

>  bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
> -				   int cookie)
> +				   int cookie, bool use_atomic)
>  {
>  	struct nbcon_write_context wctxt = { };
>  	struct nbcon_context *ctxt = &ACCESS_PRIVATE(&wctxt, ctxt);
>  	unsigned long flags;
>  	bool progress;
>  
> -	/* Use the same procedure as console_emit_next_record(). */
> -	printk_safe_enter_irqsave(flags);
> -	console_lock_spinning_enable();
> -	stop_critical_timings();
> +	ctxt->console = con;
>  
> -	ctxt->console	= con;
> -	ctxt->prio	= nbcon_get_default_prio();
> +	if (use_atomic) {
> +		/* Use the same procedure as console_emit_next_record(). */

I would extend it a bit:

		/*
		 * In an atomic or unknown context, use the same procedure as in
		 * console_emit_next_record(). It allows to handower...
		 */

> +		printk_safe_enter_irqsave(flags);
> +		console_lock_spinning_enable();
> +		stop_critical_timings();
>  
> -	progress = nbcon_atomic_emit_one(&wctxt);
> +		ctxt->prio = nbcon_get_default_prio();
> +		progress = nbcon_emit_one(&wctxt, use_atomic);
>  
> -	start_critical_timings();
> -	*handover = console_lock_spinning_disable_and_check(cookie);
> -	printk_safe_exit_irqrestore(flags);
> +		start_critical_timings();
> +		*handover = console_lock_spinning_disable_and_check(cookie);
> +		printk_safe_exit_irqrestore(flags);
> +	} else {

I would add a comment:

		/*
		 * In process context, use the same procedure as in
		 * nbcon_kthread_func(). It might allow scheduling
		 * depending on the devive_lock()...
		 */

> +		*handover = false;
> +
> +		con->device_lock(con, &flags);
> +		cant_migrate();
> +
> +		ctxt->prio = nbcon_get_default_prio();
> +		progress = nbcon_emit_one(&wctxt, use_atomic);

This is repeated in both branches.

> +		con->device_unlock(con, flags);
> +	}


I do not have strong opinion. But I slightly more like the variant
where we do not repeat the common functions. It is easier to see
the difference of the context in which nbcon_emit_one() is called.

	if (use_atomic) {
		/*
		 * In an atomic or unknown context, use the same procedure as in
		 * console_emit_next_record(). It allows to handower...
		 */
		printk_safe_enter_irqsave(flags);
		console_lock_spinning_enable();
		stop_critical_timings();
	} else {
		/*
		 * In process context, use the same procedure as in
		 * nbcon_kthread_func(). It might allow scheduling
		 * depending on the devive_lock()...
		 */
		con->device_lock(con, &flags);
		cant_migrate();
	}

	ctxt->prio = nbcon_get_default_prio();
	progress = nbcon_emit_one(&wctxt, use_atomic);

	if (use_atomic) {
		start_critical_timings();
		*handover = console_lock_spinning_disable_and_check(cookie);
		printk_safe_exit_irqrestore(flags);
	} else {
		con->device_unlock(con, flags);
		*handover = false;
	}

>  	return progress;
>  }
> @@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
>  		 * to handle it.
>  		 */
>  		do_trigger_flush = true;
> -		if (printing_via_unlock && !is_printk_deferred()) {
> +		if (!force_printkthreads() &&

Is this correct? We still need to flush the messages directly
when the legacy kthread is not ready yet.

We should check !nbcon_legacy_kthread instead.


> +		    printing_via_unlock &&
> +		    !is_printk_deferred()) {
>  			if (console_trylock()) {
>  				do_trigger_flush = false;
>  				console_unlock();
> @@ -1530,7 +1546,9 @@ void nbcon_cpu_emergency_flush(void)
>  
>  	nbcon_atomic_flush_pending();
>  
> -	if (printing_via_unlock && !is_printk_deferred()) {
> +	if (!force_printkthreads() &&

Same here. It should rather be !nbcon_legacy_kthread.

> +	    printing_via_unlock &&
> +	    !is_printk_deferred()) {
>  		if (console_trylock())
>  			console_unlock();

The same tricky pattern is repeated in

    + vprintk_emit()
    + nbcon_cpu_emergency_exit()
    + nbcon_cpu_emergency_flush()

With each new condition, it is more and more complicated to see
if all the locations do the right thing.

It would be nice to somehow refactor this or create some
helper scripts. I would do it even at the cost that
some checks will be repeated.

It is already being discussed in the thread about 5th patch,
see https://lore.kernel.org/r/8734p0yca9.fsf@jogness.linutronix.de
Let's continue there.

>  	}
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index cf0d612329bf..1c63fd0c1166 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2345,7 +2348,8 @@ asmlinkage int vprintk_emit(int facility, int level,
>  			    const struct dev_printk_info *dev_info,
>  			    const char *fmt, va_list args)
>  {
> -	bool do_trylock_unlock = printing_via_unlock;
> +	bool do_trylock_unlock = !force_printkthreads() &&

s/force_printkthreads/nbcon_legacy_kthread/  ???


> +				 printing_via_unlock;
>  	int printed_len;
>  
>  	/* Suppress unimportant messages after panic happens */
> @@ -2740,7 +2756,9 @@ void resume_console(void)
>   */
>  static int console_cpu_notify(unsigned int cpu)
>  {
> -	if (!cpuhp_tasks_frozen && printing_via_unlock) {
> +	if (!force_printkthreads() &&

s/force_printkthreads/nbcon_legacy_kthread/  ???

> +	    !cpuhp_tasks_frozen &&
> +	    printing_via_unlock) {
>  		/* If trylock fails, someone else is doing the printing */
>  		if (console_trylock())
>  			console_unlock();
> @@ -3000,31 +3018,43 @@ static bool console_emit_next_record(struct console *con, bool *handover, int co
>  		con->dropped = 0;
>  	}
>  
> -	/*
> -	 * While actively printing out messages, if another printk()
> -	 * were to occur on another CPU, it may wait for this one to
> -	 * finish. This task can not be preempted if there is a
> -	 * waiter waiting to take over.
> -	 *
> -	 * Interrupts are disabled because the hand over to a waiter
> -	 * must not be interrupted until the hand over is completed
> -	 * (@console_waiter is cleared).
> -	 */
> -	printk_safe_enter_irqsave(flags);
> -	console_lock_spinning_enable();
> +	/* Write everything out to the hardware. */
>  
> -	/* Do not trace print latency. */
> -	stop_critical_timings();
> +	if (force_printkthreads()) {

s/force_printkthreads/nbcon_legacy_kthread/  ???

> +		/*
> +		 * With forced threading this function is either in a thread
> +		 * or panic context. So there is no need for concern about
> +		 * printk reentrance or handovers.
> +		 */

The comment describes why it is "safe". But it does not describe the
motivation.

If I get it correctly, the motivation is to call con->write() with interrupts
and preemption enabled. We should document it so that people won't
break it in the future.

Another question is how it is guaranteed. OK, it is called only from
console_flush_all(). But it is called also from get_init_console_seq()
aka from register_console(). I guess that it is OK because it is
a well known and preemptible context. But it is not clear from
the comment.

> -	/* Write everything out to the hardware. */
> -	con->write(con, outbuf, pmsg.outbuf_len);
> +		con->write(con, outbuf, pmsg.outbuf_len);
> +		con->seq = pmsg.seq + 1;
> +	} else {
> +		/*
> +		 * While actively printing out messages, if another printk()
> +		 * were to occur on another CPU, it may wait for this one to
> +		 * finish. This task can not be preempted if there is a
> +		 * waiter waiting to take over.
> +		 *
> +		 * Interrupts are disabled because the hand over to a waiter
> +		 * must not be interrupted until the hand over is completed
> +		 * (@console_waiter is cleared).
> +		 */
> +		printk_safe_enter_irqsave(flags);
> +		console_lock_spinning_enable();
>  
> -	start_critical_timings();
> +		/* Do not trace print latency. */
> +		stop_critical_timings();
>  
> -	con->seq = pmsg.seq + 1;
> +		con->write(con, outbuf, pmsg.outbuf_len);
>  
> -	*handover = console_lock_spinning_disable_and_check(cookie);
> -	printk_safe_exit_irqrestore(flags);
> +		start_critical_timings();
> +
> +		con->seq = pmsg.seq + 1;
> +
> +		*handover = console_lock_spinning_disable_and_check(cookie);
> +		printk_safe_exit_irqrestore(flags);
> +	}
>  skip:
>  	return true;
>  }
> @@ -3188,6 +3207,32 @@ void console_unlock(void)
>  		 */
>  	} while (prb_read_valid(prb, next_seq, NULL) && console_trylock());
>  }
> +
> +/**
> + * console_unlock - unblock the console subsystem from printing
> + *
> + * Releases the console_lock which the caller holds to block printing of
> + * the console subsystem.
> + *
> + * While the console_lock was held, console output may have been buffered
> + * by printk().  If this is the case, console_unlock(); emits
> + * the output prior to releasing the lock.
> + *
> + * console_unlock(); may be called from any context.
> + */
> +void console_unlock(void)
> +{
> +	/*
> +	 * Forced threading relies on kthread and atomic consoles for
> +	 * printing. It never attempts to print from console_unlock().
> +	 */
> +	if (force_printkthreads()) {

s/force_printkthreads/nbcon_legacy_kthread/  ???

> +		__console_unlock();
> +		return;
> +	}
> +
> +	console_flush_and_unlock();
> +}
>  EXPORT_SYMBOL(console_unlock);
>  
>  /**
> @@ -3411,12 +3456,107 @@ void console_start(struct console *console)
>  	flags = console_srcu_read_flags(console);
>  	if (flags & CON_NBCON)
>  		nbcon_kthread_wake(console);
> +	else
> +		wake_up_legacy_kthread();
>  	console_srcu_read_unlock(cookie);
>  
>  	__pr_flush(console, 1000, true);
>  }
>  EXPORT_SYMBOL(console_start);
>  
> +#ifdef CONFIG_PRINTK
> +static bool printer_should_wake(void)

I would call it printk_legacy_kthread_should_wakeup()
to make it consistent with

     + printk_legacy_kthread		# proposed above
     + nbcon_kthread_should_wakeup()

> +{
> +	bool available = false;

Nit: I would use "bool ret = false".

     The word "available" is not much helpful because it is not
     immediately obvious what is available. It might be console,
     kthread, or pending record. One has to read the code and
     "available" is not cscope-friendly ;-)
 

> +	struct console *con;
> +	int cookie;
> +
> +	if (kthread_should_stop())
> +		return true;
> +
> +	cookie = console_srcu_read_lock();
> +	for_each_console_srcu(con) {
> +		short flags = console_srcu_read_flags(con);
> +		u64 printk_seq;
> +
> +		/*
> +		 * The legacy printer thread is only for legacy consoles,
> +		 * unless the nbcon console has no kthread printer.
> +		 */
> +		if ((flags & CON_NBCON) && con->kthread)
> +			continue;
> +
> +		if (!console_is_usable(con, flags, false))
> +			continue;
> +
> +		if (flags & CON_NBCON) {
> +			printk_seq = nbcon_seq_read(con);
> +		} else {
> +			/*
> +			 * It is safe to read @seq because only this
> +			 * thread context updates @seq.
> +			 */
> +			printk_seq = con->seq;
> +		}
> +
> +		if (prb_read_valid(prb, printk_seq, NULL)) {
> +			available = true;
> +			break;
> +		}
> +	}
> +	console_srcu_read_unlock(cookie);
> +
> +	return available;
> +}
> +
> +void nbcon_legacy_kthread_create(void)
> +{
> +	struct task_struct *kt;
> +
> +	lockdep_assert_held(&console_mutex);
> +
> +	if (!force_printkthreads())
> +		return;
> +
> +	if (!printk_threads_enabled || nbcon_legacy_kthread)
> +		return;
> +
> +	kt = kthread_run(nbcon_legacy_kthread_func, NULL, "pr/legacy");
> +	if (IS_ERR(kt)) {
> +		pr_err("unable to start legacy printing thread\n");
> +		return;

Is this acceptable for RT, please?

> +	}
> +
> +	nbcon_legacy_kthread = kt;
> +
> +	/*
> +	 * It is important that console printing threads are scheduled
> +	 * shortly after a printk call and with generous runtime budgets.
> +	 */
> +	sched_set_normal(nbcon_legacy_kthread, -20);
> +}
> +#endif /* CONFIG_PRINTK */
> +
>  static int __read_mostly keep_bootcon;
>  
>  static int __init keep_bootcon_setup(char *str)
> @@ -3706,6 +3846,7 @@ void register_console(struct console *newcon)
>  	} else {
>  		have_legacy_console = true;
>  		newcon->seq = init_seq;
> +		nbcon_legacy_kthread_create();

I would prefer to do:

		if (force_printkthread)
			nbcon_legacy_kthread_create();

to make it clear that we start it only when explicitly requested.

>  	}
>  
>  	if (newcon->flags & CON_BOOT)
> @@ -4146,9 +4298,16 @@ static void wake_up_klogd_work_func(struct irq_work *irq_work)
>  	int pending = this_cpu_xchg(printk_pending, 0);
>  
>  	if (pending & PRINTK_PENDING_OUTPUT) {
> -		/* If trylock fails, someone else is doing the printing */
> -		if (console_trylock())
> -			console_unlock();
> +		if (force_printkthreads()) {

s/force_printkthreads/nbcon_legacy_kthread/  ???

> +			wake_up_legacy_kthread();
> +		} else {
> +			/*
> +			 * If trylock fails, some other context
> +			 * will do the printing.
> +			 */
> +			if (console_trylock())
> +				console_unlock();
> +		}
>  	}
>  
>  	if (pending & PRINTK_PENDING_WAKEUP)

Best Regards,
Petr

On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
>> @@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
>>  		 * to handle it.
>>  		 */
>>  		do_trigger_flush = true;
>> -		if (printing_via_unlock && !is_printk_deferred()) {
>> +		if (!force_printkthreads() &&
>
> Is this correct? We still need to flush the messages directly
> when the legacy kthread is not ready yet.

No! If force_printkthreads() is set, messages will never flush directly
except for console_flush_on_panic().

I see that I implemented get_init_console_seq() to flush since it is
known to be in task state. But that is wrong. Also there it should not
flush directly. It is not about whether or not printing is safe. It is
about deferring to the thread 100% of the time except for panic.

>> +void nbcon_legacy_kthread_create(void)
>> +{
>> +	struct task_struct *kt;
>> +
>> +	lockdep_assert_held(&console_mutex);
>> +
>> +	if (!force_printkthreads())
>> +		return;
>> +
>> +	if (!printk_threads_enabled || nbcon_legacy_kthread)
>> +		return;
>> +
>> +	kt = kthread_run(nbcon_legacy_kthread_func, NULL, "pr/legacy");
>> +	if (IS_ERR(kt)) {
>> +		pr_err("unable to start legacy printing thread\n");
>> +		return;
>
> Is this acceptable for RT, please?

It is not acceptable for mainline. For the next version, any failed
thread creation leads to unregistering the console. In the case of the
legacy thread, it will mean unregistering all legacy consoles on
failure.

John

On Fri 2024-06-28 14:28:47, John Ogness wrote:
> On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
> >> @@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
> >>  		 * to handle it.
> >>  		 */
> >>  		do_trigger_flush = true;
> >> -		if (printing_via_unlock && !is_printk_deferred()) {
> >> +		if (!force_printkthreads() &&
> >
> > Is this correct? We still need to flush the messages directly
> > when the legacy kthread is not ready yet.
> 
> No! If force_printkthreads() is set, messages will never flush directly
> except for console_flush_on_panic().

But this is an _emergency_ context! This would be inconsistent with
the nbcon consoles where the messages are flushed directly.

Is RT sheduling quaranteed when the system reached emergency state?

In fact, we probably should not check force_printkthreads() here at
all. It would be only for NBCON_PRIO_NORMAL context.

Or the option should force the kthreads even for nbcon consoles.


> I see that I implemented get_init_console_seq() to flush since it is
> known to be in task state. But that is wrong. Also there it should not
> flush directly. It is not about whether or not printing is safe. It is
> about deferring to the thread 100% of the time except for panic.
> 
> >> +void nbcon_legacy_kthread_create(void)
> >> +{
> >> +	struct task_struct *kt;
> >> +
> >> +	lockdep_assert_held(&console_mutex);
> >> +
> >> +	if (!force_printkthreads())
> >> +		return;
> >> +
> >> +	if (!printk_threads_enabled || nbcon_legacy_kthread)
> >> +		return;
> >> +
> >> +	kt = kthread_run(nbcon_legacy_kthread_func, NULL, "pr/legacy");
> >> +	if (IS_ERR(kt)) {
> >> +		pr_err("unable to start legacy printing thread\n");
> >> +		return;
> >
> > Is this acceptable for RT, please?
> 
> It is not acceptable for mainline. For the next version, any failed
> thread creation leads to unregistering the console. In the case of the
> legacy thread, it will mean unregistering all legacy consoles on
> failure.

It means that the system would become silent. Is this a good idea?

IMHO, we have a fundamental problem here.
Are RT guarantees more important than printk() or vice versa?

What is happening when the RT guarantees are violated?
For example, when the scheduler detects a problem?
Does it panic() or tries to continue?

From my POV, silent system is the worst solution. The user
might think: "no messages, no problem".

Best Regards,
Petr

On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
> On Fri 2024-06-28 14:28:47, John Ogness wrote:
>> On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
>> >> @@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
>> >>  		 * to handle it.
>> >>  		 */
>> >>  		do_trigger_flush = true;
>> >> -		if (printing_via_unlock && !is_printk_deferred()) {
>> >> +		if (!force_printkthreads() &&
>> >
>> > Is this correct? We still need to flush the messages directly
>> > when the legacy kthread is not ready yet.
>> 
>> No! If force_printkthreads() is set, messages will never flush directly
>> except for console_flush_on_panic().
>
> But this is an _emergency_ context! This would be inconsistent with
> the nbcon consoles where the messages are flushed directly.
>
> Is RT sheduling quaranteed when the system reached emergency state?

No.

> In fact, we probably should not check force_printkthreads() here at
> all. It would be only for NBCON_PRIO_NORMAL context.

On PREEMPT_RT, legacy consoles are not allowed to print from
non-preemptible contexts because they use spinlocks (rtmutexes).

This is a disadvantage for legacy consoles on PREEMPT_RT. If people want
a legacy console to gain the reliability attribute on PREEMPT_RT, then
that console _must_ be converted to nbcon.

force_printkthreads() is used to establish the same console printing
behavior as PREEMPT_RT. (A later patch makes this behavior available to
all preemption models so that users can enjoy the non-interference
attribute of the rework.)

>> For the next version, any failed
>> thread creation leads to unregistering the console. In the case of the
>> legacy thread, it will mean unregistering all legacy consoles on
>> failure.
>
> It means that the system would become silent. Is this a good idea?

In the threaded model, the thread is a critical component of the
console. If the thread cannot start, it is the same as if memory could
not be allocated. The registration must fail. And just as it is now, the
user will only see that it failed via dmesg (or some other console that
did not fail).

> IMHO, we have a fundamental problem here.
> Are RT guarantees more important than printk() or vice versa?

That is not the issue. The problem is that you want legacy consoles in
RT to print without the printing thread. That is not possible. Those
drivers are not RT compatible and will cause deadlocks. They _must_ be
modified i.e. converted to nbcon consoles.

We have worked really hard to allow legacy consoles to work "as is" for
!PREEMPT_RT. But when PREEMPT_RT is enabled legacy consoles must be
forced into the thread (except for panic, where we close our eyes and
hope for the best).

John

On Fri 2024-06-28 16:17:13, John Ogness wrote:
> On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
> > On Fri 2024-06-28 14:28:47, John Ogness wrote:
> >> On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
> >> >> @@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
> >> >>  		 * to handle it.
> >> >>  		 */
> >> >>  		do_trigger_flush = true;
> >> >> -		if (printing_via_unlock && !is_printk_deferred()) {
> >> >> +		if (!force_printkthreads() &&
> >> >
> >> > Is this correct? We still need to flush the messages directly
> >> > when the legacy kthread is not ready yet.
> >> 
> >> No! If force_printkthreads() is set, messages will never flush directly
> >> except for console_flush_on_panic().
> >
> > But this is an _emergency_ context! This would be inconsistent with
> > the nbcon consoles where the messages are flushed directly.
> >
> > Is RT sheduling quaranteed when the system reached emergency state?
> 
> No.
> 
> > In fact, we probably should not check force_printkthreads() here at
> > all. It would be only for NBCON_PRIO_NORMAL context.
> 
> On PREEMPT_RT, legacy consoles are not allowed to print from
> non-preemptible contexts because they use spinlocks (rtmutexes).

Ah, I see.

> This is a disadvantage for legacy consoles on PREEMPT_RT. If people want
> a legacy console to gain the reliability attribute on PREEMPT_RT, then
> that console _must_ be converted to nbcon.

Makes sense.

Thanks a lot for explanation.

Best Regards,
Petr

On Mon 2024-07-01 16:50:31, Petr Mladek wrote:
> On Fri 2024-06-28 16:17:13, John Ogness wrote:
> > On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
> > > On Fri 2024-06-28 14:28:47, John Ogness wrote:
> > >> On 2024-06-28, Petr Mladek <pmladek@suse.com> wrote:
> > >> >> @@ -1494,7 +1508,9 @@ void nbcon_cpu_emergency_exit(void)
> > >> >>  		 * to handle it.
> > >> >>  		 */
> > >> >>  		do_trigger_flush = true;
> > >> >> -		if (printing_via_unlock && !is_printk_deferred()) {
> > >> >> +		if (!force_printkthreads() &&
> > >> >
> > >> > Is this correct? We still need to flush the messages directly
> > >> > when the legacy kthread is not ready yet.
> > >> 
> > >> No! If force_printkthreads() is set, messages will never flush directly
> > >> except for console_flush_on_panic().
> > >
> > > But this is an _emergency_ context! This would be inconsistent with
> > > the nbcon consoles where the messages are flushed directly.
> > >
> > > Is RT sheduling quaranteed when the system reached emergency state?
> > 
> > No.
> > 
> > > In fact, we probably should not check force_printkthreads() here at
> > > all. It would be only for NBCON_PRIO_NORMAL context.
> > 
> > On PREEMPT_RT, legacy consoles are not allowed to print from
> > non-preemptible contexts because they use spinlocks (rtmutexes).
> 
> Ah, I see.
> 
> > This is a disadvantage for legacy consoles on PREEMPT_RT. If people want
> > a legacy console to gain the reliability attribute on PREEMPT_RT, then
> > that console _must_ be converted to nbcon.
> 
> Makes sense.
> 
> Thanks a lot for explanation.

It is clear that the legacy consoles could not be flushed directly in
nbcon_cpu_emergency_exit() with PREEMPT_RT. I thought whether we
could/should allow this for other preemption modes.

My opinion. Let's keep it simple and behave the same in all preemption
modes. force_printkthreads() is enabled only in PREEMPT_RT by default.
Users would get the "expected" legacy behavior in other preemption
modes by default.

By other words, let's keep "force_printkthreads()" to really simulate
RT behavior also in other preemption modes.

That said, I still suggest to rename the variable/function to
"force_legacy_thread". It does not affect the behavior of
the kthreads for nbcon consoles.

Best Regards,
Petr

Hi Petr,

Your comments are sending me into deep thought about this
situation. Some more comments from me...

On 2024-06-28, John Ogness <john.ogness@linutronix.de> wrote:
> On PREEMPT_RT, legacy consoles are not allowed to print from
> non-preemptible contexts because they use spinlocks (rtmutexes).

The above statement is not true for legacy _boot_ consoles
(earlycon/earlyprintk). These are lockless and are intended to execute
from any context (except NMI due to semaphore limitations).

I hate boot consoles because they don't use the Linux driver model and
rely fully on external synchronization. This has made the rework very
difficult and is actually the core reason why our work was reverted back
in 5.19-rc4. But for debugging early boot problems, they are quite
useful.

I have a new proposal. What if we allow boot consoles to always print in
the caller context (for any preemption model)? I hacked a quick test
together by providing console_flush_all() an extra argument for printing
_only_ on boot consoles. Then in vprintk_emit(), I always do a
boot-console-only-flush (under console_trylock) after storing the record
in the ringbuffer.

For PREEMPT_RT this is horrible. But I am OK with mandating that RT
scheduling cannot be guaranteed with boot consoles (just as it is
currently mandated that RT scheduling cannot be guaranteed in emergency
situations). Since the boot consoles are lockless, they pose no deadlock
threat to RT.

This has some nice features:

- We get early debugging in all preemption models.

- We get true synchronous printing when using boot consoles (which
  should make peterz happy).

- Boot consoles are then horrible enough that options such as
  "keep_bootcon" will really be avoided unless debugging kernel issues.

From the tests I have run so far, it looks good.

Looking to the future, I think this would also provide an excellent
foundation for the "sync" console option I would like. For nbcon
consoles with the "sync" option specified, it would work the same way,
flushing boot consoles and nbcon consoles directly in vprintk_emit().

Thoughts?

John

On Fri 2024-06-28 18:02:19, John Ogness wrote:
> Hi Petr,
> 
> Your comments are sending me into deep thought about this
> situation. Some more comments from me...
> 
> On 2024-06-28, John Ogness <john.ogness@linutronix.de> wrote:
> > On PREEMPT_RT, legacy consoles are not allowed to print from
> > non-preemptible contexts because they use spinlocks (rtmutexes).
> 
> The above statement is not true for legacy _boot_ consoles
> (earlycon/earlyprintk). These are lockless and are intended to execute
> from any context (except NMI due to semaphore limitations).
> 
> I hate boot consoles because they don't use the Linux driver model and
> rely fully on external synchronization. This has made the rework very
> difficult and is actually the core reason why our work was reverted back
> in 5.19-rc4. But for debugging early boot problems, they are quite
> useful.
>
> I have a new proposal. What if we allow boot consoles to always print in
> the caller context (for any preemption model)? I hacked a quick test
> together by providing console_flush_all() an extra argument for printing
> _only_ on boot consoles. Then in vprintk_emit(), I always do a
> boot-console-only-flush (under console_trylock) after storing the record
> in the ringbuffer.
> 
> For PREEMPT_RT this is horrible. But I am OK with mandating that RT
> scheduling cannot be guaranteed with boot consoles (just as it is
> currently mandated that RT scheduling cannot be guaranteed in emergency
> situations). Since the boot consoles are lockless, they pose no deadlock
> threat to RT.

Is this really the case for all boot consoles?

I had the feeling that some boot consoles actually used port->lock.
And for example, register_earlycon() is initializing this spin lock.

> This has some nice features:
> 
> - We get early debugging in all preemption models.

It would be great.

> - We get true synchronous printing when using boot consoles (which
>   should make peterz happy).

Well, Peter's mode is really special because it is done without
the console_lock(). Every printk() is flushing its own message
to the console. Parallel printk()'s are busy waiting for each other.

> - Boot consoles are then horrible enough that options such as
>   "keep_bootcon" will really be avoided unless debugging kernel issues.
> 
> >From the tests I have run so far, it looks good.
> 
> Looking to the future, I think this would also provide an excellent
> foundation for the "sync" console option I would like. For nbcon
> consoles with the "sync" option specified, it would work the same way,
> flushing boot consoles and nbcon consoles directly in vprintk_emit().

The sync mode would be nice.

Just to be sure. I guess that you are talking about a sync mode
using some trylock mechanism where the current owner would be
responsible for flushing everything.

Peter Zijlstra's mode (serialized printk()) is easy to implement
and might be needed in some situations. But I am not sure if
it would be good enough for most other users preferring the
current "synchronous" output.

Well, let's see what people request after they get some experience
with the first nbcon consoles and kthreads.

Best Regards,
Petr

On 2024-07-01, Petr Mladek <pmladek@suse.com> wrote:
>> I have a new proposal. What if we allow boot consoles to always print
>> in the caller context (for any preemption model)? I hacked a quick
>> test together by providing console_flush_all() an extra argument for
>> printing _only_ on boot consoles. Then in vprintk_emit(), I always do
>> a boot-console-only-flush (under console_trylock) after storing the
>> record in the ringbuffer.
>> 
>> For PREEMPT_RT this is horrible. But I am OK with mandating that RT
>> scheduling cannot be guaranteed with boot consoles (just as it is
>> currently mandated that RT scheduling cannot be guaranteed in
>> emergency situations). Since the boot consoles are lockless, they
>> pose no deadlock threat to RT.
>
> Is this really the case for all boot consoles?
>
> I had the feeling that some boot consoles actually used port->lock.
> And for example, register_earlycon() is initializing this spin lock.

Doing a naive search, it seems like there are a few that do some spin
locking:

- alpha/kernel/srmcons.c
- tty/hvc/hvc_xen.c
- tty/mips_ejtag_fdc.c
- usb/early/xhci-dbc.c

I will need to look at these in more detail.

>> - We get true synchronous printing when using boot consoles (which
>>   should make peterz happy).
>
> Well, Peter's mode is really special because it is done without
> the console_lock(). Every printk() is flushing its own message
> to the console. Parallel printk()'s are busy waiting for each other.

This is also what I would like to see. For debugging purposes (which is
the purpose of CON_BOOT) this mode of operation is probably preferred.

>> Looking to the future, I think this would also provide an excellent
>> foundation for the "sync" console option I would like. For nbcon
>> consoles with the "sync" option specified, it would work the same
>> way, flushing boot consoles and nbcon consoles directly in
>> vprintk_emit().
>
> The sync mode would be nice.
>
> Just to be sure. I guess that you are talking about a sync mode
> using some trylock mechanism where the current owner would be
> responsible for flushing everything.
>
> Peter Zijlstra's mode (serialized printk()) is easy to implement
> and might be needed in some situations. But I am not sure if
> it would be good enough for most other users preferring the
> current "synchronous" output.

I have always envisioned it being a true sync mode. Each console has its
own nbcon state. So if it was set to sync mode, vprintk_emit() could
local_irq_save() and then busy-wait until it acquires the nbcon state
for that console. There would be no handovers and no relying on another
context to print your message. It would be straight forward and truly
synchronous (for that console). Back to the roots of printk().

> Well, let's see what people request after they get some experience
> with the first nbcon consoles and kthreads.

On Mon 2024-07-01 23:07:23, John Ogness wrote:
> On 2024-07-01, Petr Mladek <pmladek@suse.com> wrote:
> >> I have a new proposal. What if we allow boot consoles to always print
> >> in the caller context (for any preemption model)? I hacked a quick
> >> test together by providing console_flush_all() an extra argument for
> >> printing _only_ on boot consoles. Then in vprintk_emit(), I always do
> >> a boot-console-only-flush (under console_trylock) after storing the
> >> record in the ringbuffer.
> >> 
> >> For PREEMPT_RT this is horrible. But I am OK with mandating that RT
> >> scheduling cannot be guaranteed with boot consoles (just as it is
> >> currently mandated that RT scheduling cannot be guaranteed in
> >> emergency situations). Since the boot consoles are lockless, they
> >> pose no deadlock threat to RT.
> >
> > Is this really the case for all boot consoles?
> >
> > I had the feeling that some boot consoles actually used port->lock.
> > And for example, register_earlycon() is initializing this spin lock.
> 
> Doing a naive search, it seems like there are a few that do some spin
> locking:
> 
> - alpha/kernel/srmcons.c
> - tty/hvc/hvc_xen.c
> - tty/mips_ejtag_fdc.c
> - usb/early/xhci-dbc.c
> 
> I will need to look at these in more detail.

This looks like a non-trivial thing. I assume that you would do this later.
We probably do not want to complicate/delay the current patchset by this.

> >> - We get true synchronous printing when using boot consoles (which
> >>   should make peterz happy).
> >
> > Well, Peter's mode is really special because it is done without
> > the console_lock(). Every printk() is flushing its own message
> > to the console. Parallel printk()'s are busy waiting for each other.
> 
> This is also what I would like to see. For debugging purposes (which is
> the purpose of CON_BOOT) this mode of operation is probably preferred.

Makes sense. And it would be great when it was enough.

Well, I could also imagine that a non-serialized printk() might be
useful to debug some races in the code before the printk
kthreads are started.

Another scenario where a synchronized printk might be useful is
a sudden death. In this case, the "synchronous" printk would
be needed all the time. People might prefer the current
legacy mode where printk works synchronously most of the time
but it is not fully serialized.

Honestly, I do not know what people want. There always will be
usecase where some mode would be needed or work better.
We should be prepared for the situation when people would
want to keep a mode which has been used last 25+ years.

> >> Looking to the future, I think this would also provide an excellent
> >> foundation for the "sync" console option I would like. For nbcon
> >> consoles with the "sync" option specified, it would work the same
> >> way, flushing boot consoles and nbcon consoles directly in
> >> vprintk_emit().
> >
> > The sync mode would be nice.
> >
> > Just to be sure. I guess that you are talking about a sync mode
> > using some trylock mechanism where the current owner would be
> > responsible for flushing everything.
> >
> > Peter Zijlstra's mode (serialized printk()) is easy to implement
> > and might be needed in some situations. But I am not sure if
> > it would be good enough for most other users preferring the
> > current "synchronous" output.
> 
> I have always envisioned it being a true sync mode. Each console has its
> own nbcon state. So if it was set to sync mode, vprintk_emit() could
> local_irq_save() and then busy-wait until it acquires the nbcon state
> for that console. There would be no handovers and no relying on another
> context to print your message. It would be straight forward and truly
> synchronous (for that console). Back to the roots of printk().

I see this as yet another feature which might be introduced later.
In this patchset, I would keep the legacy behavior when boot
consoles are registered.

Best Regards,
Petr