Allow nbcon consoles to print messages in the legacy printk()
caller context (printing via unlock) by integrating them into
console_flush_all(). The write_atomic() callback is used for
printing.

Provide nbcon_legacy_emit_next_record(), which acts as the
nbcon variant of console_emit_next_record(). Call this variant
within console_flush_all() for nbcon consoles. Since nbcon
consoles use their own @nbcon_seq variable to track the next
record to print, this also must be appropriately handled.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/internal.h |  6 ++++
 kernel/printk/nbcon.c    | 77 ++++++++++++++++++++++++++++++++++++++++
 kernel/printk/printk.c   | 17 ++++++---
 3 files changed, 95 insertions(+), 5 deletions(-)

diff --git a/kernel/printk/internal.h b/kernel/printk/internal.h
index a8df764fd0c5..acf53c35b7a0 100644
--- a/kernel/printk/internal.h
+++ b/kernel/printk/internal.h
@@ -78,6 +78,8 @@ void defer_console_output(void);
 
 u16 printk_parse_prefix(const char *text, int *level,
 			enum printk_info_flags *flags);
+void console_lock_spinning_enable(void);
+int console_lock_spinning_disable_and_check(int cookie);
 
 u64 nbcon_seq_read(struct console *con);
 void nbcon_seq_force(struct console *con, u64 seq);
@@ -85,6 +87,8 @@ bool nbcon_alloc(struct console *con);
 void nbcon_init(struct console *con);
 void nbcon_free(struct console *con);
 void nbcon_atomic_flush_pending(void);
+bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
+				   int cookie);
 
 /*
  * Check if the given console is currently capable and allowed to print
@@ -140,6 +144,8 @@ static inline bool nbcon_alloc(struct console *con) { return false; }
 static inline void nbcon_init(struct console *con) { }
 static inline void nbcon_free(struct console *con) { }
 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; }
 
 static inline bool console_is_usable(struct console *con, short flags) { return false; }
 
diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index fcdab2eaaedb..599fff3c0ab3 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -541,6 +541,7 @@ static struct printk_buffers panic_nbcon_pbufs;
  * nbcon_context_try_acquire - Try to acquire nbcon console
  * @ctxt:	The context of the caller
  *
+ * Context:	Any context which could not be migrated to another CPU.
  * Return:	True if the console was acquired. False otherwise.
  *
  * If the caller allowed an unsafe hostile takeover, on success the
@@ -935,6 +936,82 @@ static bool nbcon_emit_next_record(struct nbcon_write_context *wctxt)
 	return nbcon_context_exit_unsafe(ctxt);
 }
 
+/**
+ * nbcon_atomic_emit_one - Print one record for an nbcon console using the
+ *				write_atomic() callback
+ * @wctxt:	An initialized write context struct to use for this context
+ *
+ * Return:	False if it is known there are no more records to print,
+ *		otherwise true.
+ *
+ * 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)
+{
+	struct nbcon_context *ctxt = &ACCESS_PRIVATE(wctxt, ctxt);
+
+	if (!nbcon_context_try_acquire(ctxt))
+		return true;
+
+	/*
+	 * nbcon_emit_next_record() returns false when the console was
+	 * handed over or taken over. In both cases the context is no
+	 * longer valid.
+	 */
+	if (!nbcon_emit_next_record(wctxt))
+		return true;
+
+	nbcon_context_release(ctxt);
+
+	return ctxt->backlog;
+}
+
+/**
+ * nbcon_legacy_emit_next_record - Print one record for an nbcon console
+ *					in legacy contexts
+ * @con:	The console to print on
+ * @handover:	Will be set to true if a printk waiter has taken over the
+ *		console_lock, in which case the caller is no longer holding
+ *		both the console_lock and the SRCU read lock. Otherwise it
+ *		is set to false.
+ * @cookie:	The cookie from the SRCU read lock.
+ *
+ * Context:	Any context except NMI.
+ * Return:	False if the given console has no next record to print,
+ *		otherwise true.
+ *
+ * This function is meant to be called by console_flush_all() to print records
+ * on nbcon consoles from legacy context (printing via console unlocking).
+ * Essentially it is the nbcon version of console_emit_next_record().
+ */
+bool nbcon_legacy_emit_next_record(struct console *con, bool *handover,
+				   int cookie)
+{
+	struct nbcon_write_context wctxt = { };
+	struct nbcon_context *ctxt = &ACCESS_PRIVATE(&wctxt, ctxt);
+	unsigned long flags;
+	bool progress;
+
+	*handover = false;
+
+	/* 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->prio	= NBCON_PRIO_NORMAL;
+
+	progress = nbcon_atomic_emit_one(&wctxt);
+
+	start_critical_timings();
+	*handover = console_lock_spinning_disable_and_check(cookie);
+	printk_safe_exit_irqrestore(flags);
+
+	return progress;
+}
+
 /**
  * __nbcon_atomic_flush_pending_con - Flush specified nbcon console using its
  *					write_atomic() callback
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index a1b3309e12c1..df84c6bfbb2d 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1860,7 +1860,7 @@ static bool console_waiter;
  * there may be a waiter spinning (like a spinlock). Also it must be
  * ready to hand over the lock at the end of the section.
  */
-static void console_lock_spinning_enable(void)
+void console_lock_spinning_enable(void)
 {
 	/*
 	 * Do not use spinning in panic(). The panic CPU wants to keep the lock.
@@ -1899,7 +1899,7 @@ static void console_lock_spinning_enable(void)
  *
  * Return: 1 if the lock rights were passed, 0 otherwise.
  */
-static int console_lock_spinning_disable_and_check(int cookie)
+int console_lock_spinning_disable_and_check(int cookie)
 {
 	int waiter;
 
@@ -2951,13 +2951,20 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
 		cookie = console_srcu_read_lock();
 		for_each_console_srcu(con) {
 			short flags = console_srcu_read_flags(con);
+			u64 printk_seq;
 			bool progress;
 
 			if (!console_is_usable(con, flags))
 				continue;
 			any_usable = true;
 
-			progress = console_emit_next_record(con, handover, cookie);
+			if (flags & CON_NBCON) {
+				progress = nbcon_legacy_emit_next_record(con, handover, cookie);
+				printk_seq = nbcon_seq_read(con);
+			} else {
+				progress = console_emit_next_record(con, handover, cookie);
+				printk_seq = con->seq;
+			}
 
 			/*
 			 * If a handover has occurred, the SRCU read lock
@@ -2967,8 +2974,8 @@ static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handove
 				return false;
 
 			/* Track the next of the highest seq flushed. */
-			if (con->seq > *next_seq)
-				*next_seq = con->seq;
+			if (printk_seq > *next_seq)
+				*next_seq = printk_seq;
 
 			if (!progress)
 				continue;
-- 
2.39.2

On Wed 2024-04-03 00:17:19, John Ogness wrote:
> Allow nbcon consoles to print messages in the legacy printk()
> caller context (printing via unlock) by integrating them into
> console_flush_all(). The write_atomic() callback is used for
> printing.

Hmm, this patch tries to flush nbcon console even in context
with NBCON_PRIO_NORMAL. Do we really want this, please?

I would expect that it would do so only when the kthread
is not working.

> Provide nbcon_legacy_emit_next_record(), which acts as the
> nbcon variant of console_emit_next_record(). Call this variant
> within console_flush_all() for nbcon consoles. Since nbcon
> consoles use their own @nbcon_seq variable to track the next
> record to print, this also must be appropriately handled.

I have been a bit confused by all the boolean return values
and what _exactly_ they mean. IMHO, we should make it more
clear how it works when it can't acquire the context.

IMHO, it is is importnat because console_flush_all() interprets
nbcon_legacy_emit_next_record() return value as @progress even when
there is no guaranteed progress. We just expect that
the other context is doing something.

It feels like it might get stuck forewer in some situatuon.
It would be good to understand if it is OK or not.


Later update:

Hmm, console_flush_all() is called from console_unlock().
It might be called in atomic context. But the current
owner might be theoretically scheduled out.

This is from documentation of nbcon_context_try_acquire()

/**
 * nbcon_context_try_acquire - Try to acquire nbcon console
 * @ctxt:	The context of the caller
 *
 * Context:	Any context which could not be migrated to another CPU.


I can't find any situation where nbcon_context_try_acquire() is
currently called in normal (schedulable) context. This is probably
why you did not see any problems with testing.

I see 3 possible solutions:

  1. Enforce that nbcon context can be acquired only with preemtion
     disabled.

  2. Enforce that nbcon context can be acquired only with
     interrupts. It would prevent deadlock when some future
     code interrupt flush in NBCON_PRIO_EMERGENCY context.
     And then a potential nested console_flush_all() won't be
     able to takeover the interrupted NBCON_PRIO_CONTEXT
     and there will be no progress.

  3. console_flush_all() should ignore nbcon console when
     it is not able to get the context, aka no progress.


I personally prefer the 3rd solution because I have spent
last 12 years on attempts to move printk into preemtible
context. And it looks wrong to move into atomic context.

Warning: console_flush_all() suddenly won't guarantee flushing
	 all messages.

	 I am not completely sure about all the consequences until
	 I see the rest of the patchset and the kthread intergration.
	 We will somehow need to guarantee that all messages
	 are flushed.


I propose the following changes to make console_flush_all()
safe. The patch is made on top of this patchset. Feel free
to squash them into your patch and remove my SoB.


From 8dd9c0be5ab693c6976a0f7f8b99de48ecebcbf6 Mon Sep 17 00:00:00 2001
From: Petr Mladek <pmladek@suse.com>
Date: Thu, 11 Apr 2024 15:45:53 +0200
Subject: [PATCH] printk: nbcon: Prevent deadlock when flushing nbcon consoles
 in the legacy loop

Ignore pending records in nbcon consoles in the legacy console_flush_all()
loop when the nbcon console context can't be acquired. They will be
flushed either by the current nbcon context owner or to-be-introduced
printk kthread.

Signed-off-by: Petr Mladek <pmladek@suse.com>
---
 kernel/printk/nbcon.c | 21 +++++++++++++++------
 1 file changed, 15 insertions(+), 6 deletions(-)

diff --git a/kernel/printk/nbcon.c b/kernel/printk/nbcon.c
index c57ad34a8d56..88c40f165be4 100644
--- a/kernel/printk/nbcon.c
+++ b/kernel/printk/nbcon.c
@@ -964,8 +964,12 @@ static __ref unsigned int *nbcon_get_cpu_emergency_nesting(void)
  *				write_atomic() callback
  * @wctxt:	An initialized write context struct to use for this context
  *
- * Return:	False if it is known there are no more records to print,
- *		otherwise true.
+ * Return:	True, when a record has been printed and there are still
+ *		pending records. The caller might want to continue flushing.
+ *
+ *		False, when there is no pending record, or when the console
+ *		context can't be acquired, or the ownership has been lost.
+ *		The caller should give up. Either the job is or	can't be done.
  *
  * This is an internal helper to handle the locking of the console before
  * calling nbcon_emit_next_record().
@@ -975,7 +979,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
 	struct nbcon_context *ctxt = &ACCESS_PRIVATE(wctxt, ctxt);
 
 	if (!nbcon_context_try_acquire(ctxt))
-		return true;
+		return false;
 
 	/*
 	 * nbcon_emit_next_record() returns false when the console was
@@ -983,7 +987,7 @@ static bool nbcon_atomic_emit_one(struct nbcon_write_context *wctxt)
 	 * longer valid.
 	 */
 	if (!nbcon_emit_next_record(wctxt))
-		return true;
+		return false;
 
 	nbcon_context_release(ctxt);
 
@@ -1023,8 +1027,13 @@ enum nbcon_prio nbcon_get_default_prio(void)
  * @cookie:	The cookie from the SRCU read lock.
  *
  * Context:	Any context except NMI.
- * Return:	False if the given console has no next record to print,
- *		otherwise true.
+ *
+ * Return:	True, when a record has been printed and there are still
+ *		pending records. The caller might want to continue flushing.
+ *
+ *		False, when there is no pending record, or when the console
+ *		context can't be acquired, or the ownership has been lost.
+ *		The caller should give up. Either the job is or	can't be done.
  *
  * This function is meant to be called by console_flush_all() to print records
  * on nbcon consoles from legacy context (printing via console unlocking).
-- 
2.44.0


Best Regards,
Petr

On 2024-04-11, Petr Mladek <pmladek@suse.com> wrote:
> console_flush_all() is called from console_unlock().
> It might be called in atomic context. But the current
> owner might be theoretically scheduled out.

Nice catch. This problem was introduced in this series after you pointed
out that return value of nbcon_legacy_emit_next_record() did not match
the semantics of console_emit_next_record().

> I see 3 possible solutions:
>
>   1. Enforce that nbcon context can be acquired only with preemtion
>      disabled.

Not acceptable.

>   2. Enforce that nbcon context can be acquired only with
>      interrupts. It would prevent deadlock when some future
>      code interrupt flush in NBCON_PRIO_EMERGENCY context.
>      And then a potential nested console_flush_all() won't be
>      able to takeover the interrupted NBCON_PRIO_CONTEXT
>      and there will be no progress.

Not acceptable.

>   3. console_flush_all() should ignore nbcon console when
>      it is not able to get the context, aka no progress.

This was the previous implementation, but as you point out, it is an
issue that console_flush_all() is no longer reliable.

I will continue this topic by responding to your follow-up message.

John

On Thu 2024-04-11 16:14:58, Petr Mladek wrote:
> On Wed 2024-04-03 00:17:19, John Ogness wrote:
> > Allow nbcon consoles to print messages in the legacy printk()
> > caller context (printing via unlock) by integrating them into
> > console_flush_all(). The write_atomic() callback is used for
> > printing.
> 
> Hmm, this patch tries to flush nbcon console even in context
> with NBCON_PRIO_NORMAL. Do we really want this, please?
> 
> I would expect that it would do so only when the kthread
> is not working.
> 
> > Provide nbcon_legacy_emit_next_record(), which acts as the
> > nbcon variant of console_emit_next_record(). Call this variant
> > within console_flush_all() for nbcon consoles. Since nbcon
> > consoles use their own @nbcon_seq variable to track the next
> > record to print, this also must be appropriately handled.
> 
> I have been a bit confused by all the boolean return values
> and what _exactly_ they mean. IMHO, we should make it more
> clear how it works when it can't acquire the context.
> 
> IMHO, it is is importnat because console_flush_all() interprets
> nbcon_legacy_emit_next_record() return value as @progress even when
> there is no guaranteed progress. We just expect that
> the other context is doing something.
> 
> It feels like it might get stuck forewer in some situatuon.
> It would be good to understand if it is OK or not.
> 
> 
> Later update:
> 
> Hmm, console_flush_all() is called from console_unlock().
> It might be called in atomic context. But the current
> owner might be theoretically scheduled out.
> 
> This is from documentation of nbcon_context_try_acquire()
> 
> /**
>  * nbcon_context_try_acquire - Try to acquire nbcon console
>  * @ctxt:	The context of the caller
>  *
>  * Context:	Any context which could not be migrated to another CPU.
> 
> 
> I can't find any situation where nbcon_context_try_acquire() is
> currently called in normal (schedulable) context. This is probably
> why you did not see any problems with testing.

> I see 3 possible solutions:
> 
>   1. Enforce that nbcon context can be acquired only with preemtion
>      disabled.

We actually have to make sure that preemtion is disabled because
nbcon_owner_matches() is not reliable after a wakeup.

The context might be taken by a higher priority context then
released and then taken by another task on the same CPU as
the original sleeping owner. I mean this:


CPU0				CPU1

 [ task A ]

 nbcon_context_try_acquire()
   # success with NORMAL prio
   # .unsafe == false;  // safe for takeover

 [ schedule: task A -> B ]


				WARN_ON()
				  nbcon_atomic_flush_pending()
				    nbcon_context_try_acquire()
				      # success with EMERGENCY prio
				      # .unsafe == false;  // safe for takeover

				      # flushing
				      nbcon_context_release()


 nbcon_context_try_acquire()
   # success with NORMAL prio [ task B ]
   # .unsafe == false;  // safe for takeover

 [ schedule: task B -> A ]

 nbcon_enter_unsafe()
   nbcon_context_can_proceed()

BUG: nbcon_context_can_proceed() returns "true" because
     the console is owned by a context on CPU0 with
     NBCON_PRIO_NORMAL.

     But it should return "false". The console is owned
     by a context from task B and we do the check
     in a context from task A.


I guess that most of the current code is safe because, for example:

  + __nbcon_atomic_flush_pending() disables interrupts before
    acquiring the context

  + nbcon_driver_acquire() is called under spin_lock in
    the uart_port_*lock() API.

  + Even the nbcon_kthread_func() in the current RT tree
    acquires the context under con->device_lock(). Where
    the device_lock() is a spin_lock in the only supported
    uart serial console.


To be done:

1. We should make this clear:

    + Add either preempt_disable() or cant_sleep() into
      nbcon_context_try_acquire().

    + Replace cant_migrate() with cant_sleep everywhere

    + Fix/update the documentation


2. We should make sure that the context is acquired for each
   emitted record separately at least when using the normal
   priority.

   For example,  __nbcon_atomic_flush_pending() is wrong from
   this POV. It is used also from console_unlock(). It should
   allow to schedule in between the records in this case.


Best Regards,
Petr

PS: I am still shaking my head around this. Sigh, I haven't expected
    such a big "aha moment" at this stage.

On Thu 2024-04-11 16:14:58, Petr Mladek wrote:
> On Wed 2024-04-03 00:17:19, John Ogness wrote:
> > Allow nbcon consoles to print messages in the legacy printk()
> > caller context (printing via unlock) by integrating them into
> > console_flush_all(). The write_atomic() callback is used for
> > printing.
> 
> Hmm, this patch tries to flush nbcon console even in context
> with NBCON_PRIO_NORMAL. Do we really want this, please?
> 
> I would expect that it would do so only when the kthread
> is not working.
> 
> > Provide nbcon_legacy_emit_next_record(), which acts as the
> > nbcon variant of console_emit_next_record(). Call this variant
> > within console_flush_all() for nbcon consoles. Since nbcon
> > consoles use their own @nbcon_seq variable to track the next
> > record to print, this also must be appropriately handled.
> 
> I have been a bit confused by all the boolean return values
> and what _exactly_ they mean. IMHO, we should make it more
> clear how it works when it can't acquire the context.
> 
> IMHO, it is is importnat because console_flush_all() interprets
> nbcon_legacy_emit_next_record() return value as @progress even when
> there is no guaranteed progress. We just expect that
> the other context is doing something.
>
> It feels like it might get stuck forewer in some situatuon.
> It would be good to understand if it is OK or not.
> 
> 
> Later update:
> 
> Hmm, console_flush_all() is called from console_unlock().
> It might be called in atomic context. But the current
> owner might be theoretically scheduled out.
> 
> This is from documentation of nbcon_context_try_acquire()
> 
> /**
>  * nbcon_context_try_acquire - Try to acquire nbcon console
>  * @ctxt:	The context of the caller
>  *
>  * Context:	Any context which could not be migrated to another CPU.
> 
> 
> I can't find any situation where nbcon_context_try_acquire() is
> currently called in normal (schedulable) context. This is probably
> why you did not see any problems with testing.
> 
> I see 3 possible solutions:
> 
>   1. Enforce that nbcon context can be acquired only with preemtion
>      disabled.
> 
>   2. Enforce that nbcon context can be acquired only with
>      interrupts. It would prevent deadlock when some future
>      code interrupt flush in NBCON_PRIO_EMERGENCY context.
>      And then a potential nested console_flush_all() won't be
>      able to takeover the interrupted NBCON_PRIO_CONTEXT
>      and there will be no progress.
> 
>   3. console_flush_all() should ignore nbcon console when
>      it is not able to get the context, aka no progress.
> 
> 
> I personally prefer the 3rd solution because I have spent
> last 12 years on attempts to move printk into preemtible
> context. And it looks wrong to move into atomic context.
> 
> Warning: console_flush_all() suddenly won't guarantee flushing
> 	 all messages.
> 
> 	 I am not completely sure about all the consequences until
> 	 I see the rest of the patchset and the kthread intergration.
> 	 We will somehow need to guarantee that all messages
> 	 are flushed.

I am trying to make a full picture when and how the nbcon consoles
will get flushed. My current understanding and view is the following,
starting from the easiest priority:


  1. NBCON_PRIO_PANIC messages will be flushed by calling
     nbcon_atomic_flush_pending() directly in vprintk_emit()

     This will take care of any previously added messages.

     Non-panic CPUs are not allowed to add messages anymore
     when there is a panic in progress.

     [ALL OK]


  2. NBCON_PRIO_EMERGENCY messages will be flushed by calling
     nbcon_atomic_flush_pending() directly in nbcon_cpu_emergency_exit().

     This would cover all previously added messages, including
     the ones printed by the code between
     nbcon_cpu_emergency_enter()/exit().

     This won't cover later added messages which might be
     a problem. Let's look at this closer. Later added
     messages with:

	+ NBCON_PRIO_PANIC will be handled in vprintk_emit()
	  as explained above [OK]

	+ NBCON_PRIO_EMERGENCY() will be handled in the
	  related nbcon_cpu_emergency_exit() as described here.
	  [OK]

	+ NBCON_PRIO_NORMAL will be handled, see below. [?]

     [ PROBLEM: later added NBCON_PRIO_NORMAL messages, see below. ]


  3. NBCON_PRIO_NORMAL messages will be flushed by:

       + the printk kthread when it is available

       + the legacy loop via

	 + console_unlock()
	    + console_flush_all()
	      + console nbcon_legacy_emit_next_record() [PROBLEM]


PROBLEM: console_flush_all() does not guarantee progress with
	 nbcon consoles as explained above (previous mail).


My proposal:

	1. console_flush_all() will flush nbcon consoles only
	   in NBCON_PRIO_NORMAL and when the kthreads are not
	   available.

	   It will make it clear that this is the flusher in
	   this situation.


	2. Allow to skip nbcon consoles in console_flush_all() when
	   it can't take the context (as suggested in my previous
	   reply).

	   This won't guarantee flushing NORMAL messages added
	   while nbcon_cpu_emergency_exit() calls
	   nbcon_atomic_flush_pending().

	   Solve this problem by introducing[*] nbcon_atomic_flush_all()
	   which would flush even newly added messages and
	   call this in nbcon_cpu_emergency_exit() when the printk
	   kthread does not work. It should bail out when there
	   is a panic in progress.

	   Motivation: It does not matter which "atomic" context
		flushes NORMAL/EMERGENCY messages when
		the printk kthread is not available.

	  [*] Alternatively we could modify nbcon_atomic_flush_pending()
	      to flush even newly added messages when the kthread is
	      not working. But it might create another mess.

How does it sound, please?
Or do I miss anything?

Best Regards,
Petr

On 2024-04-11, Petr Mladek <pmladek@suse.com> wrote:
> I am trying to make a full picture when and how the nbcon consoles
> will get flushed. My current understanding and view is the following,
> starting from the easiest priority:
>
>
>   1. NBCON_PRIO_PANIC messages will be flushed by calling
>      nbcon_atomic_flush_pending() directly in vprintk_emit()
>
>      This will take care of any previously added messages.
>
>      Non-panic CPUs are not allowed to add messages anymore
>      when there is a panic in progress.
>
>      [ALL OK]

OK, because the end of panic will perform unsafe takeovers if necessary.

>   2. NBCON_PRIO_EMERGENCY messages will be flushed by calling
>      nbcon_atomic_flush_pending() directly in nbcon_cpu_emergency_exit().
>
>      This would cover all previously added messages, including
>      the ones printed by the code between
>      nbcon_cpu_emergency_enter()/exit().

This is best effort. If the console is owned by another context and is
marked unsafe, nbcon_atomic_flush_pending() will do nothing.

[ PROBLEM: In this case, who will flush the emergency messages? ]

>      This won't cover later added messages which might be
>      a problem. Let's look at this closer. Later added
>      messages with:
>
> 	+ NBCON_PRIO_PANIC will be handled in vprintk_emit()
> 	  as explained above [OK]
>
> 	+ NBCON_PRIO_EMERGENCY() will be handled in the
> 	  related nbcon_cpu_emergency_exit() as described here.
> 	  [OK]
>
> 	+ NBCON_PRIO_NORMAL will be handled, see below. [?]
>
>      [ PROBLEM: later added NBCON_PRIO_NORMAL messages, see below. ]

Yes, this is also an issue, although the solution may be the same for
this and the above problem.

>   3. NBCON_PRIO_NORMAL messages will be flushed by:
>
>        + the printk kthread when it is available
>
>        + the legacy loop via
>
> 	 + console_unlock()
> 	    + console_flush_all()
> 	      + console nbcon_legacy_emit_next_record() [PROBLEM]
>
> PROBLEM: console_flush_all() does not guarantee progress with
> 	 nbcon consoles as explained above (previous mail).

Not only this. If there is no kthread available, no printing will occur
until the _next_ printk(), whenever that is.


Above we have listed 3 problems:

- emergency messages will not flush if owned by another context and
  unsafe

- normal messages will not flush if owned by another context

- for the above 2 problems, if there is no kthread, nobody will flush
  the messages


My question: Is this really a problem?

The main idea behind the rework is that printing is deferred. The
kthreads exist for this. If the kthreads are not available (early boot
or shutdown) or the kthreads are not reliable enough (emergency
messages), a best-safe-effort is made to print in the caller
context. Only the panic situation is designed to force output (unsafely,
if necessary). Is that not enough?

> My proposal:
>
> 	1. console_flush_all() will flush nbcon consoles only
> 	   in NBCON_PRIO_NORMAL and when the kthreads are not
> 	   available.
>
> 	   It will make it clear that this is the flusher in
> 	   this situation.

This is the current PREEMPT_RT implementation.

> 	2. Allow to skip nbcon consoles in console_flush_all() when
> 	   it can't take the context (as suggested in my previous
> 	   reply).
>
> 	   This won't guarantee flushing NORMAL messages added
> 	   while nbcon_cpu_emergency_exit() calls
> 	   nbcon_atomic_flush_pending().

This was the previous version. And I agree that we need to go back to
that.

> 	   Solve this problem by introducing[*] nbcon_atomic_flush_all()
> 	   which would flush even newly added messages and
> 	   call this in nbcon_cpu_emergency_exit() when the printk
> 	   kthread does not work. It should bail out when there
> 	   is a panic in progress.
>
> 	   Motivation: It does not matter which "atomic" context
> 		flushes NORMAL/EMERGENCY messages when
> 		the printk kthread is not available.

I do not think that solves the problem. If the console is in an unsafe
section, nothing can be printed.

> 	  [*] Alternatively we could modify nbcon_atomic_flush_pending()
> 	      to flush even newly added messages when the kthread is
> 	      not working. But it might create another mess.

This discussion is about when kthreads are not available. If this is a
concern, I wonder if maybe in this situation an irq_work should be
triggered upon release of the console.

For example, something like:

static bool flush_pending(struct console *con)
{
	/* If there is a kthread, let it do the work. */
	if (con->kthread)
		return false;

	/* Make sure a record is pending. */
	if (!prb_read_valid(prb, nbcon_seq_read(con), NULL))
		return false;

	return true;
}

static void nbcon_context_release(struct nbcon_context *ctxt)
{
	...

	/* Trigger irq_work to flush if necessary. */
	if (flush_pending(con))
		defer_console_output();
}

John

On Thu 2024-04-18 01:11:59, John Ogness wrote:
> On 2024-04-11, Petr Mladek <pmladek@suse.com> wrote:
> > I am trying to make a full picture when and how the nbcon consoles
> > will get flushed. My current understanding and view is the following,
> > starting from the easiest priority:
> >
> >
> >   1. NBCON_PRIO_PANIC messages will be flushed by calling
> >      nbcon_atomic_flush_pending() directly in vprintk_emit()
> >
> >      This will take care of any previously added messages.
> >
> >      Non-panic CPUs are not allowed to add messages anymore
> >      when there is a panic in progress.
> >
> >      [ALL OK]
> 
> OK, because the end of panic will perform unsafe takeovers if necessary.
> 
> >   2. NBCON_PRIO_EMERGENCY messages will be flushed by calling
> >      nbcon_atomic_flush_pending() directly in nbcon_cpu_emergency_exit().
> >
> >      This would cover all previously added messages, including
> >      the ones printed by the code between
> >      nbcon_cpu_emergency_enter()/exit().
> 
> This is best effort. If the console is owned by another context and is
> marked unsafe, nbcon_atomic_flush_pending() will do nothing.
> 
> [ PROBLEM: In this case, who will flush the emergency messages? ]

They should get flushed by the current owner when the system is still
living. Or the system is ready for panic() and the messages would
be emitted bu the final unsafe flush.

IMPORTANT: The optimistic scenario would work only when the current
	   owner really flushes everything. More on this below.


> >      This won't cover later added messages which might be
> >      a problem. Let's look at this closer. Later added
> >      messages with:
> >
> > 	+ NBCON_PRIO_PANIC will be handled in vprintk_emit()
> > 	  as explained above [OK]
> >
> > 	+ NBCON_PRIO_EMERGENCY() will be handled in the
> > 	  related nbcon_cpu_emergency_exit() as described here.
> > 	  [OK]
> >
> > 	+ NBCON_PRIO_NORMAL will be handled, see below. [?]
> >
> >      [ PROBLEM: later added NBCON_PRIO_NORMAL messages, see below. ]
> 
> Yes, this is also an issue, although the solution may be the same for
> this and the above problem.

This is a bit different. There was an existing console owner in the
above scenario. In this case, the code relies on the printk kthread.
But we need a solution for situations when the kthread is not working,
e.g. early boot.


> >   3. NBCON_PRIO_NORMAL messages will be flushed by:
> >
> >        + the printk kthread when it is available
> >
> >        + the legacy loop via
> >
> > 	 + console_unlock()
> > 	    + console_flush_all()
> > 	      + console nbcon_legacy_emit_next_record() [PROBLEM]
> >
> > PROBLEM: console_flush_all() does not guarantee progress with
> > 	 nbcon consoles as explained above (previous mail).
> 
> Not only this. If there is no kthread available, no printing will occur
> until the _next_ printk(), whenever that is.

> Above we have listed 3 problems:
> 
> - emergency messages will not flush if owned by another context and
>   unsafe
>
> - normal messages will not flush if owned by another context
> 
> - for the above 2 problems, if there is no kthread, nobody will flush
>   the messages

All this goes down to the problem who is would flush "ignored"
messages when the system continues working in "normal" mode.


> My question: Is this really a problem?

IMHO, it is. For example, early boot consoles exists for a reason.
People want to debug early boot problems using printk.
We should not break the reliability too much by introducing kthreads.

Later update: It is basically only about early boot debugging.

	The kthreads should always be created later. And
	we assume that they work, except for the emergency
	and panic context.

	So, this is not a problem as long as the boot consoles
	are using the legacy code paths.

	Well, I guess that they might use the "atomic_write()"
	callback in the future. And then this "bug" might hurt.


> The main idea behind the rework is that printing is deferred. The
> kthreads exist for this. If the kthreads are not available (early boot
> or shutdown) or the kthreads are not reliable enough (emergency
> messages), a best-safe-effort is made to print in the caller
> context. Only the panic situation is designed to force output (unsafely,
> if necessary). Is that not enough?

Simple answer: No, primary because the early boot behavior.

Longer answer: I tried to separate all the variants and point out
	a particular problem. The above paragraph mixes everything
	into "Wave this away" proposal.


> > My proposal:
> >
> > 	1. console_flush_all() will flush nbcon consoles only
> > 	   in NBCON_PRIO_NORMAL and when the kthreads are not
> > 	   available.
> >
> > 	   It will make it clear that this is the flusher in
> > 	   this situation.
> 
> This is the current PREEMPT_RT implementation.
> 
> > 	2. Allow to skip nbcon consoles in console_flush_all() when
> > 	   it can't take the context (as suggested in my previous
> > 	   reply).
> >
> > 	   This won't guarantee flushing NORMAL messages added
> > 	   while nbcon_cpu_emergency_exit() calls
> > 	   nbcon_atomic_flush_pending().
> 
> This was the previous version. And I agree that we need to go back to
> that.
> 
> > 	   Solve this problem by introducing[*] nbcon_atomic_flush_all()
> > 	   which would flush even newly added messages and
> > 	   call this in nbcon_cpu_emergency_exit() when the printk
> > 	   kthread does not work. It should bail out when there
> > 	   is a panic in progress.
> >
> > 	   Motivation: It does not matter which "atomic" context
> > 		flushes NORMAL/EMERGENCY messages when
> > 		the printk kthread is not available.
> 
> I do not think that solves the problem. If the console is in an unsafe
> section, nothing can be printed.

IMHO, it solves the problem.

The idea is simple:

  "The current nbcon console owner will be responsible for flushing
   all messages when the printk kthread does not exist."

The prove is more complicated:

   1. Let's put aside panic. We already do the best effort there.

   2. Emergency mode currently violates the rule because
      nbcon_atomic_flush_pending() ignores the simple rule.

      => FIX: improve nbcon_cpu_emergency_exit() to flush
	      all messages when kthreads are not ready.


   3. Normal mode flushes nbcon consoles via
      nbcon_legacy_emit_next_record() from console_unlock()
      before the kthreads are started.

      It is not reliable when nbcon_try_acquire() fails.
      But it would fail only when there is another user.
      The other owner might be:

	+ panic: will handle everything

	+ emergency: should flush everything [*]

	+ normal: can't happen because of con->device() lock.

=> The only remaining problem is to fix nbcon_atomic_flush_pending()
   to flush everything when the kthreads are not started yet.


> > 	  [*] Alternatively we could modify nbcon_atomic_flush_pending()
> > 	      to flush even newly added messages when the kthread is
> > 	      not working. But it might create another mess.
> 
> This discussion is about when kthreads are not available. If this is a
> concern, I wonder if maybe in this situation an irq_work should be
> triggered upon release of the console.

Calling irq_work() would solve the problem as well. It would move
flushing to context with "normal" priority which is serialized
by con->device_lock(). It works for me.

Does this make any sense?

It is possible that you already knew all this. And it is possible
that you did not see it as a problem because there was no plan
to convert boot consoles to nbcon variant. Maybe, it does
not even make sense because boot consoles could not use
kthreads. The only motivation would be code sharing and
simplification of the legacy loop but this is far away dream.

Sigh, all this is so complicated. I wonder how to document
this so that other people do not have to discover these
dependencies again and again. Is it even possible?

Well, I still think that it makes sense to improve
nbcon_cpu_emergency_exit() to fill the potential hole.
And ideally mention all these details somewhere
(commit message, comments, Documentation/...)

Best Regards,
Petr

On 2024-04-18, Petr Mladek <pmladek@suse.com> wrote:
>> > 	   Solve this problem by introducing[*] nbcon_atomic_flush_all()
>> > 	   which would flush even newly added messages and
>> > 	   call this in nbcon_cpu_emergency_exit() when the printk
>> > 	   kthread does not work. It should bail out when there
>> > 	   is a panic in progress.
>> >
>> > 	   Motivation: It does not matter which "atomic" context
>> > 		flushes NORMAL/EMERGENCY messages when
>> > 		the printk kthread is not available.
>> 
>> I do not think that solves the problem. If the console is in an unsafe
>> section, nothing can be printed.
>
> IMHO, it solves the problem.
>
> The idea is simple:
>
>   "The current nbcon console owner will be responsible for flushing
>    all messages when the printk kthread does not exist."

Currently this is not valid. It assumes owners are printers. That is not
always true. The owner might be some task modifying the baud rate and
has nothing to do with printing.

> The prove is more complicated:
>
>    1. Let's put aside panic. We already do the best effort there.
>
>    2. Emergency mode currently violates the rule because
>       nbcon_atomic_flush_pending() ignores the simple rule.
>
>       => FIX: improve nbcon_cpu_emergency_exit() to flush
> 	      all messages when kthreads are not ready.

Emergency mode cannot flush _anything_ if there is an owner in an unsafe
region. (And that owner may not be a printer.)

>    3. Normal mode flushes nbcon consoles via
>       nbcon_legacy_emit_next_record() from console_unlock()
>       before the kthreads are started.
>
>       It is not reliable when nbcon_try_acquire() fails.
>       But it would fail only when there is another user.
>       The other owner might be:
>
> 	+ panic: will handle everything
>
> 	+ emergency: should flush everything [*]
>
> 	+ normal: can't happen because of con->device() lock.

As the code is now, "normal" does not imply con->device() lock. When
using con->write_atomic(), we do not (and can not) use the con->device()
lock. So normal _can_ fail in nbcon_legacy_emit_next_record() if another
CPU is adjusting the baud rate. This is why I said the problem with
"emergency" is basically the same problem as "normal" (WRT using
write_atomic()).

> => The only remaining problem is to fix nbcon_atomic_flush_pending()
>    to flush everything when the kthreads are not started yet.

I think my proposed change handles it better. I have been doing various
tests and also adjusted it a bit.

The reason the flushing fails is because another context owns the
console. So I think it makes sense for that owner to handle flushing
responsibility when releasing ownership (even if that context was just
changing the baud rate).

[ Keep in mind we are only talking about printing via write_atomic()
when the kthread is not available. ]

If the current owner is a normal printing context, it will print to
completion anyway (via console_flush_all()).

If the current owner is an emergency printing context, it will only
print the emergency messages (as PRIO_EMERGENCY). However, when it
releases ownership, it could flush the remaining records (as
PRIO_NORMAL) in the same fashion as console_flush_all() does it.

If the current owner is a non-printing context, when it releases
ownership, it could flush the remaining records (as PRIO_NORMAL) in the
same fashion as console_flush_all() does it.

So what I am proposing is that we add two new normal-flushing sites that
are only used when the kthread is not available:

1. after exiting emergency mode: in nbcon_cpu_emergency_exit()

2. after releasing ownership for non-printing: in nbcon_driver_release()

I think this will close the gap and it does not require irq_work.

> Sigh, all this is so complicated. I wonder how to document
> this so that other people do not have to discover these
> dependencies again and again. Is it even possible?

In the end we will have the following 5 scenarios (assuming my
proposal):

1. PRIO_NORMAL non-printing activity, always under con->device() lock,
   upon release flushes[*] full backlog

2. PRIO_NORMAL printing using write_thread(), always called from task
   context and under con->device() lock, always flushes full backlog

3. PRIO_NORMAL printing using write_atomic(), called with hardware
   interrupts disabled, always flushes full backlog, (only used when the
   kthread is not available)

4. PRIO_EMERGENCY printing using write_atomic(), called with hardware
   interrupts disabled, flushes through emergency, upon exit flushes[*]
   full backlog

5. PRIO_PANIC printing using write_atomic(), called with hardware
   interrupts disabled, flushes full backlog

[*] Only when the kthread is not available. And in that case #3 is the
    scenario used for the trailing full flushing by #1 and #4.


Full flushing is attempted in all 5 scenarios. A failed attempt means
there is a new owner, but that owner is also one of the 5 scenarios.

Am I missing something?

IMHO #3 is the only bizarre scenario. It exists only to cover when the
kthread is not available.

John

On Thu 2024-04-18 23:51:01, John Ogness wrote:
> On 2024-04-18, Petr Mladek <pmladek@suse.com> wrote:
> >> > 	   Solve this problem by introducing[*] nbcon_atomic_flush_all()
> >> > 	   which would flush even newly added messages and
> >> > 	   call this in nbcon_cpu_emergency_exit() when the printk
> >> > 	   kthread does not work. It should bail out when there
> >> > 	   is a panic in progress.
> >> >
> >> > 	   Motivation: It does not matter which "atomic" context
> >> > 		flushes NORMAL/EMERGENCY messages when
> >> > 		the printk kthread is not available.
> >> 
> >> I do not think that solves the problem. If the console is in an unsafe
> >> section, nothing can be printed.
> >
> > IMHO, it solves the problem.
> >
> > The idea is simple:
> >
> >   "The current nbcon console owner will be responsible for flushing
> >    all messages when the printk kthread does not exist."
> 
> Currently this is not valid. It assumes owners are printers. That is not
> always true. The owner might be some task modifying the baud rate and
> has nothing to do with printing.

Ah, I have missed this scenario.

> So what I am proposing is that we add two new normal-flushing sites that
> are only used when the kthread is not available:
> 
> 1. after exiting emergency mode: in nbcon_cpu_emergency_exit()
> 
> 2. after releasing ownership for non-printing: in nbcon_driver_release()
> 
> I think this will close the gap and it does not require irq_work.
> 
> > Sigh, all this is so complicated. I wonder how to document
> > this so that other people do not have to discover these
> > dependencies again and again. Is it even possible?
> 
> In the end we will have the following 5 scenarios (assuming my
> proposal):
> 
> 1. PRIO_NORMAL non-printing activity, always under con->device() lock,
>    upon release flushes[*] full backlog
> 
> 2. PRIO_NORMAL printing using write_thread(), always called from task
>    context and under con->device() lock, always flushes full backlog
> 
> 3. PRIO_NORMAL printing using write_atomic(), called with hardware
>    interrupts disabled, always flushes full backlog, (only used when the
>    kthread is not available)
> 
> 4. PRIO_EMERGENCY printing using write_atomic(), called with hardware
>    interrupts disabled, flushes through emergency, upon exit flushes[*]
>    full backlog
>
> 5. PRIO_PANIC printing using write_atomic(), called with hardware
>    interrupts disabled, flushes full backlog
> 
> [*] Only when the kthread is not available. And in that case #3 is the
>     scenario used for the trailing full flushing by #1 and #4.
> 
> 
> Full flushing is attempted in all 5 scenarios. A failed attempt means
> there is a new owner, but that owner is also one of the 5 scenarios.
> 
> Am I missing something?
> 
> IMHO #3 is the only bizarre scenario. It exists only to cover when the
> kthread is not available.

Great summary! I like it.

Let me try another summary:

We basically repeat the same trick as was used in the legacy
console_unlock(). When the kthread is not avaialale then
the current owner is responsible for flushing everything.

The game changer is the kthread. When it is available then
it takes care of "everything" as long as the system is
working normaly.

The system is working normally until suspend, shutdown, or panic().
It might also be sick. In which case, we try to flush the doctor
report immediately (emergency when safe). But we wait for
the entire doctor report before flushing (publishing).


Or another look. We have the following rules:

1. kthread is not avaialbe => owner flushes everything

2. kthread is available:

    a) Normal messages are off loaded to kthread (store + kick)

    b) Emergency messages (doctor examination) are first stored and then
       tried to be flushed immediately (when possible/safe), including
       all previous messages (other up-to-date notes).

       The emergency messages might also be split in more
       parts when the report is too long, for example,
       backtraces or lock depedencies of all tasks.
       (Reports from more doctor specialists). In this case,
       each part (report) is flushed immediately (when possible/safe),
       including all previous messages (other up-to-date notes).

       When the system tries to continue normaly (no dying)
       then any later messages (post doctor exam notes) are
       let the kthread (secretary) to flush them.

     c) Panic messages are flushed immediately (when possible/safe),
	including all previous messages (other up-to-date notes).

     d) The final flush in panic() will be done even when not safe
	(patient will try to read the diary even when feeling
	 dizzy and it might be a complete fiasco but it is
	 the very last chance).


In shorrt, go ahead with your proposal.

Best Regards,
Petr