[PATCH v2 0/3] printk: Release console_lock between printing records in legacy thread

[PATCH v2 0/3] printk: Release console_lock between printing records in legacy thread

[Andrew Murray]

The legacy printer kthread uses console_lock and
__console_flush_and_unlock to flush records to the console which
holds the console_lock being held for the entire flush. This
results in large waiting times for console_lock waiters
especially where there is a large volume of records or where the
console is slow (e.g. serial). During boot, this contention causes
delays in the filp_open call in console_on_rootfs.
   
Let's instead release and reacquire console_lock in between
printing individual records.

Signed-off-by: Andrew Murray <amurray@thegoodpenguin.co.uk>
---
Changes in v2:
- Move any_usable=false to console_flush_all in the 'introduce
  console_flush_one_record' patch to match original implementation.
- Add Petr's console_flush_one_record() code cleanup patch
- Open code flushing implementation in legacy_kthread_func instead
  of introducing new console_flush functions.
- Link to v1: https://lore.kernel.org/r/20250915-printk_legacy_thread_console_lock-v1-0-f34d42a9bcb3@thegoodpenguin.co.uk

---
Andrew Murray (2):
      printk: Introduce console_flush_one_record
      printk: Use console_flush_one_record for legacy printer kthread

Petr Mladek (1):
      printk: console_flush_one_record() code cleanup

 kernel/printk/printk.c | 186 +++++++++++++++++++++++++++++++------------------
 1 file changed, 119 insertions(+), 67 deletions(-)
---
base-commit: f83ec76bf285bea5727f478a68b894f5543ca76e
change-id: 20250914-printk_legacy_thread_console_lock-1c27f59bf990

Best regards,
-- 
Andrew Murray <amurray@thegoodpenguin.co.uk>

[PATCH v2 1/3] printk: Introduce console_flush_one_record

[Andrew Murray]

console_flush_all prints all remaining records to all usable consoles
whilst its caller holds console_lock. This can result in large waiting
times for those waiting for console_lock especially where there is a
large volume of records or where the console is slow (e.g. serial).

Let's extract the parts of this function which print a single record
into a new function named console_flush_one_record. This can later
be used for functions that will release and reacquire console_lock
between records.

This commit should not change existing functionality.

Reviewed-by: Petr Mladek <pmladek@suse.com>
Signed-off-by: Andrew Murray <amurray@thegoodpenguin.co.uk>
---
 kernel/printk/printk.c | 159 +++++++++++++++++++++++++++++++------------------
 1 file changed, 100 insertions(+), 59 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 0efbcdda9aaba9d8d877df5e4f1db002d3a596bc..060d4919de320fe21fd7aca73ba497e27c4ff334 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3161,6 +3161,100 @@ static inline void printk_kthreads_check_locked(void) { }
 
 #endif /* CONFIG_PRINTK */
 
+
+/*
+ * Print out one record for each console.
+ *
+ * @do_cond_resched is set by the caller. It can be true only in schedulable
+ * context.
+ *
+ * @next_seq is set to the sequence number after the last available record.
+ * The value is valid only when this function returns true.
+ *
+ * @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 the
+ * console_lock. Otherwise it is set to false.
+ *
+ * @any_usable will be set to true if there are any usable consoles.
+ *
+ * Returns true when there was at least one usable console and a record was
+ * flushed. A returned false indicates there were no records to flush for any
+ * of the consoles. It may also indicate that there were no usable consoles,
+ * the context has been lost or there is a panic suitation. Regardless the
+ * reason, the caller should assume it is not useful to immediately try again.
+ *
+ * Requires the console_lock.
+ */
+static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *handover,
+				     bool *any_usable)
+{
+	struct console_flush_type ft;
+	struct console *con;
+	bool any_progress;
+	int cookie;
+
+	any_progress = false;
+
+	printk_get_console_flush_type(&ft);
+
+	cookie = console_srcu_read_lock();
+	for_each_console_srcu(con) {
+		short flags = console_srcu_read_flags(con);
+		u64 printk_seq;
+		bool progress;
+
+		/*
+		 * console_flush_one_record() is only responsible for
+		 * nbcon consoles when the nbcon consoles cannot print via
+		 * their atomic or threaded flushing.
+		 */
+		if ((flags & CON_NBCON) && (ft.nbcon_atomic || ft.nbcon_offload))
+			continue;
+
+		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,
+								 !do_cond_resched);
+			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
+		 * is already released.
+		 */
+		if (*handover)
+			return false;
+
+		/* Track the next of the highest seq flushed. */
+		if (printk_seq > *next_seq)
+			*next_seq = printk_seq;
+
+		if (!progress)
+			continue;
+		any_progress = true;
+
+		/* Allow panic_cpu to take over the consoles safely. */
+		if (other_cpu_in_panic())
+			goto abandon;
+
+		if (do_cond_resched)
+			cond_resched();
+	}
+	console_srcu_read_unlock(cookie);
+
+	return any_progress;
+
+abandon:
+	console_srcu_read_unlock(cookie);
+	return false;
+}
+
 /*
  * Print out all remaining records to all consoles.
  *
@@ -3186,77 +3280,24 @@ static inline void printk_kthreads_check_locked(void) { }
  */
 static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
 {
-	struct console_flush_type ft;
 	bool any_usable = false;
-	struct console *con;
 	bool any_progress;
-	int cookie;
 
 	*next_seq = 0;
 	*handover = false;
 
 	do {
-		any_progress = false;
-
-		printk_get_console_flush_type(&ft);
-
-		cookie = console_srcu_read_lock();
-		for_each_console_srcu(con) {
-			short flags = console_srcu_read_flags(con);
-			u64 printk_seq;
-			bool progress;
+		any_progress = console_flush_one_record(do_cond_resched, next_seq, handover,
+							&any_usable);
 
-			/*
-			 * console_flush_all() is only responsible for nbcon
-			 * consoles when the nbcon consoles cannot print via
-			 * their atomic or threaded flushing.
-			 */
-			if ((flags & CON_NBCON) && (ft.nbcon_atomic || ft.nbcon_offload))
-				continue;
-
-			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,
-									 !do_cond_resched);
-				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
-			 * is already released.
-			 */
-			if (*handover)
-				return false;
-
-			/* Track the next of the highest seq flushed. */
-			if (printk_seq > *next_seq)
-				*next_seq = printk_seq;
-
-			if (!progress)
-				continue;
-			any_progress = true;
-
-			/* Allow panic_cpu to take over the consoles safely. */
-			if (other_cpu_in_panic())
-				goto abandon;
+		if (*handover)
+			return false;
 
-			if (do_cond_resched)
-				cond_resched();
-		}
-		console_srcu_read_unlock(cookie);
+		if (other_cpu_in_panic())
+			return false;
 	} while (any_progress);
 
 	return any_usable;
-
-abandon:
-	console_srcu_read_unlock(cookie);
-	return false;
 }
 
 static void __console_flush_and_unlock(void)

-- 
2.34.1

[PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[Andrew Murray]

From: Petr Mladek <pmladek@suse.com>

console_flush_one_record() and console_flush_all() duplicate several
checks. They both want to tell the caller that consoles are not
longer usable in this context because it has lost the lock or
the lock has to be reserved for the panic CPU.

Pass this information by clearing the @any_usable parameter value
which has the same effect.

Reviewed-by: Andrew Murray <amurray@thegoodpenguin.co.uk>
Signed-off-by: Petr Mladek <pmladek@suse.com>
---
 kernel/printk/printk.c | 23 +++++++++++------------
 1 file changed, 11 insertions(+), 12 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 060d4919de320fe21fd7aca73ba497e27c4ff334..e2c1cacdb4164489c60fe38f1e2837eb838107d6 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3175,7 +3175,8 @@ static inline void printk_kthreads_check_locked(void) { }
  * console_lock, in which case the caller is no longer holding the
  * console_lock. Otherwise it is set to false.
  *
- * @any_usable will be set to true if there are any usable consoles.
+ * @any_usable will be set to true if there are any usable consoles
+ * in this context.
  *
  * Returns true when there was at least one usable console and a record was
  * flushed. A returned false indicates there were no records to flush for any
@@ -3193,6 +3194,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
 	bool any_progress;
 	int cookie;
 
+	*any_usable = false;
 	any_progress = false;
 
 	printk_get_console_flush_type(&ft);
@@ -3229,7 +3231,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
 		 * is already released.
 		 */
 		if (*handover)
-			return false;
+			goto unusable;
 
 		/* Track the next of the highest seq flushed. */
 		if (printk_seq > *next_seq)
@@ -3241,7 +3243,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
 
 		/* Allow panic_cpu to take over the consoles safely. */
 		if (other_cpu_in_panic())
-			goto abandon;
+			goto unusable_srcu;
 
 		if (do_cond_resched)
 			cond_resched();
@@ -3250,8 +3252,10 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
 
 	return any_progress;
 
-abandon:
+unusable_srcu:
 	console_srcu_read_unlock(cookie);
+unusable:
+	*any_usable = false;
 	return false;
 }
 
@@ -3280,21 +3284,16 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
  */
 static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
 {
-	bool any_usable = false;
+	bool any_usable;
 	bool any_progress;
 
 	*next_seq = 0;
 	*handover = false;
 
 	do {
-		any_progress = console_flush_one_record(do_cond_resched, next_seq, handover,
-							&any_usable);
+		any_progress = console_flush_one_record(do_cond_resched, next_seq,
+							handover, &any_usable);
 
-		if (*handover)
-			return false;
-
-		if (other_cpu_in_panic())
-			return false;
 	} while (any_progress);
 
 	return any_usable;

-- 
2.34.1

[PATCH v2 3/3] printk: Use console_flush_one_record for legacy printer kthread

[Andrew Murray]

The legacy printer kthread uses console_lock and
__console_flush_and_unlock to flush records to the console. This
approach results in the console_lock being held for the entire
duration of a flush. This can result in large waiting times for
those waiting for console_lock especially where there is a large
volume of records or where the console is slow (e.g. serial). This
contention is observed during boot, as the call to filp_open in
console_on_rootfs will delay progression to userspace until any
in-flight flush is completed.

Let's instead use console_flush_one_record and release/reacquire
the console_lock between records.

On a PocketBeagle 2, with the following boot args:
"console=ttyS2,9600 initcall_debug=1 loglevel=10"

Without this patch:

[    5.613166] +console_on_rootfs/filp_open
[    5.643473] mmc1: SDHCI controller on fa00000.mmc [fa00000.mmc] using ADMA 64-bit
[    5.643823] probe of fa00000.mmc returned 0 after 258244 usecs
[    5.710520] mmc1: new UHS-I speed SDR104 SDHC card at address 5048
[    5.721976] mmcblk1: mmc1:5048 SD32G 29.7 GiB
[    5.747258]  mmcblk1: p1 p2
[    5.753324] probe of mmc1:5048 returned 0 after 40002 usecs
[   15.595240] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30040000.pruss
[   15.595282] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e010000.watchdog
[   15.595297] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e000000.watchdog
[   15.595437] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30300000.crc
[  146.275961] -console_on_rootfs/filp_open ...

and with:

[    5.477122] +console_on_rootfs/filp_open
[    5.595814] mmc1: SDHCI controller on fa00000.mmc [fa00000.mmc] using ADMA 64-bit
[    5.596181] probe of fa00000.mmc returned 0 after 312757 usecs
[    5.662813] mmc1: new UHS-I speed SDR104 SDHC card at address 5048
[    5.674367] mmcblk1: mmc1:5048 SD32G 29.7 GiB
[    5.699320]  mmcblk1: p1 p2
[    5.705494] probe of mmc1:5048 returned 0 after 39987 usecs
[    6.418682] -console_on_rootfs/filp_open ...
...
[   15.593509] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30040000.pruss
[   15.593551] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e010000.watchdog
[   15.593566] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e000000.watchdog
[   15.593704] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30300000.crc

Where I've added a printk surrounding the call in console_on_rootfs to filp_open.

Suggested-by: Petr Mladek <pmladek@suse.com>
Signed-off-by: Andrew Murray <amurray@thegoodpenguin.co.uk>
---
 kernel/printk/printk.c | 24 ++++++++++++++++++------
 1 file changed, 18 insertions(+), 6 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index e2c1cacdb4164489c60fe38f1e2837eb838107d6..2c9b9383df76de956a05211537264fd6e06366da 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3668,17 +3668,29 @@ static bool legacy_kthread_should_wakeup(void)
 
 static int legacy_kthread_func(void *unused)
 {
-	for (;;) {
-		wait_event_interruptible(legacy_wait, legacy_kthread_should_wakeup());
+	bool any_progress;
+
+wait_for_event:
+	wait_event_interruptible(legacy_wait,
+				 legacy_kthread_should_wakeup());
+
+	do {
+		bool any_usable;
+		bool handover = false;
+		u64 next_seq;
 
 		if (kthread_should_stop())
-			break;
+			return 0;
 
 		console_lock();
-		__console_flush_and_unlock();
-	}
+		any_progress = console_flush_one_record(true, &next_seq,
+						&handover, &any_usable);
+		if (!handover)
+			__console_unlock();
 
-	return 0;
+	} while (any_progress);
+
+	goto wait_for_event;
 }
 
 static bool legacy_kthread_create(void)

-- 
2.34.1

Re: [PATCH v2 1/3] printk: Introduce console_flush_one_record

[John Ogness]

On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 0efbcdda9aaba9d8d877df5e4f1db002d3a596bc..060d4919de320fe21fd7aca73ba497e27c4ff334 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3161,6 +3161,100 @@ static inline void printk_kthreads_check_locked(void) { }
>  
>  #endif /* CONFIG_PRINTK */
>  
> +
> +/*
> + * Print out one record for each console.
> + *
> + * @do_cond_resched is set by the caller. It can be true only in schedulable
> + * context.
> + *
> + * @next_seq is set to the sequence number after the last available record.
> + * The value is valid only when this function returns true.
> + *
> + * @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 the
> + * console_lock. Otherwise it is set to false.
> + *
> + * @any_usable will be set to true if there are any usable consoles.
> + *
> + * Returns true when there was at least one usable console and a record was
> + * flushed. A returned false indicates there were no records to flush for any
> + * of the consoles. It may also indicate that there were no usable consoles,
> + * the context has been lost or there is a panic suitation. Regardless the
> + * reason, the caller should assume it is not useful to immediately try again.
> + *
> + * Requires the console_lock.
> + */
> +static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *handover,
> +				     bool *any_usable)
> +{
> +	struct console_flush_type ft;
> +	struct console *con;
> +	bool any_progress;
> +	int cookie;
> +
> +	any_progress = false;

I would let this be a definition initializer. And then place it sorted
by length:

	struct console_flush_type ft;
	bool any_progress = false;
	struct console *con;
	int cookie;

John

Re: [PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[John Ogness]

On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 060d4919de320fe21fd7aca73ba497e27c4ff334..e2c1cacdb4164489c60fe38f1e2837eb838107d6 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3193,6 +3194,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
>  	bool any_progress;
>  	int cookie;
>  
> +	*any_usable = false;

Since it is expected that @next_seq and @handover are initialized by
their callers (if their callers are interested in the values), then I
would expect @any_usable to be initialized by the
caller. console_flush_one_record() never reads this variable.

> @@ -3280,21 +3284,16 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
>   */
>  static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
>  {
> -	bool any_usable = false;
> +	bool any_usable;

Since console_flush_all() does read @any_usable, I would expect it to
initialize @any_usable. So I would not remove this definition initialization.

>  	bool any_progress;
>  
>  	*next_seq = 0;
>  	*handover = false;
>  
>  	do {
> -		any_progress = console_flush_one_record(do_cond_resched, next_seq, handover,
> -							&any_usable);
> +		any_progress = console_flush_one_record(do_cond_resched, next_seq,
> +							handover, &any_usable);
>  

Since the second line of the call to console_flush_one_record() already
has a ton of whitespace, I would remove the above blank line.

John

Re: [PATCH v2 3/3] printk: Use console_flush_one_record for legacy printer kthread

[John Ogness]

On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index e2c1cacdb4164489c60fe38f1e2837eb838107d6..2c9b9383df76de956a05211537264fd6e06366da 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3668,17 +3668,29 @@ static bool legacy_kthread_should_wakeup(void)
>  
>  static int legacy_kthread_func(void *unused)
>  {
> -	for (;;) {
> -		wait_event_interruptible(legacy_wait, legacy_kthread_should_wakeup());
> +	bool any_progress;
> +
> +wait_for_event:
> +	wait_event_interruptible(legacy_wait,
> +				 legacy_kthread_should_wakeup());
> +
> +	do {
> +		bool any_usable;
> +		bool handover = false;
> +		u64 next_seq;

Please sort by length. It looks nicer. ;-)

		bool handover = false;
		bool any_usable;
		u64 next_seq;

Note that it is fine that @any_usable is not initialized here because
legacy_kthread_func() does not actually care about this variable.

John

Re: [PATCH v2 3/3] printk: Use console_flush_one_record for legacy printer kthread

[Andrew Murray]

On Tue, 30 Sept 2025 at 14:03, John Ogness <john.ogness@linutronix.de> wrote:
>
> On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index e2c1cacdb4164489c60fe38f1e2837eb838107d6..2c9b9383df76de956a05211537264fd6e06366da 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -3668,17 +3668,29 @@ static bool legacy_kthread_should_wakeup(void)
> >
> >  static int legacy_kthread_func(void *unused)
> >  {
> > -     for (;;) {
> > -             wait_event_interruptible(legacy_wait, legacy_kthread_should_wakeup());
> > +     bool any_progress;
> > +
> > +wait_for_event:
> > +     wait_event_interruptible(legacy_wait,
> > +                              legacy_kthread_should_wakeup());
> > +
> > +     do {
> > +             bool any_usable;
> > +             bool handover = false;
> > +             u64 next_seq;
>
> Please sort by length. It looks nicer. ;-)
>
>                 bool handover = false;
>                 bool any_usable;
>                 u64 next_seq;

I agree :)


>
> Note that it is fine that @any_usable is not initialized here because
> legacy_kthread_func() does not actually care about this variable.

Yes, that's correct. I wasn't sure whether to set it to something
which would likely get optimised away, or if there was some way I
could mark it as not used (didn't see anything beneficial).

Thanks,

Andrew Murray

>
> John

Re: [PATCH v2 1/3] printk: Introduce console_flush_one_record

[Andrew Murray]

On Tue, 30 Sept 2025 at 13:54, John Ogness <john.ogness@linutronix.de> wrote:
>
> On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index 0efbcdda9aaba9d8d877df5e4f1db002d3a596bc..060d4919de320fe21fd7aca73ba497e27c4ff334 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -3161,6 +3161,100 @@ static inline void printk_kthreads_check_locked(void) { }
> >
> >  #endif /* CONFIG_PRINTK */
> >
> > +
> > +/*
> > + * Print out one record for each console.
> > + *
> > + * @do_cond_resched is set by the caller. It can be true only in schedulable
> > + * context.
> > + *
> > + * @next_seq is set to the sequence number after the last available record.
> > + * The value is valid only when this function returns true.
> > + *
> > + * @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 the
> > + * console_lock. Otherwise it is set to false.
> > + *
> > + * @any_usable will be set to true if there are any usable consoles.
> > + *
> > + * Returns true when there was at least one usable console and a record was
> > + * flushed. A returned false indicates there were no records to flush for any
> > + * of the consoles. It may also indicate that there were no usable consoles,
> > + * the context has been lost or there is a panic suitation. Regardless the
> > + * reason, the caller should assume it is not useful to immediately try again.
> > + *
> > + * Requires the console_lock.
> > + */
> > +static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *handover,
> > +                                  bool *any_usable)
> > +{
> > +     struct console_flush_type ft;
> > +     struct console *con;
> > +     bool any_progress;
> > +     int cookie;
> > +
> > +     any_progress = false;
>
> I would let this be a definition initializer. And then place it sorted
> by length:
>
>         struct console_flush_type ft;
>         bool any_progress = false;
>         struct console *con;
>         int cookie;
>
> John

Sure, I'll update it on the next iteration.

Thanks,

Andrew Murray

Re: [PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[Andrew Murray]

On Tue, 30 Sept 2025 at 13:59, John Ogness <john.ogness@linutronix.de> wrote:
>
> On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index 060d4919de320fe21fd7aca73ba497e27c4ff334..e2c1cacdb4164489c60fe38f1e2837eb838107d6 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -3193,6 +3194,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
> >       bool any_progress;
> >       int cookie;
> >
> > +     *any_usable = false;
>
> Since it is expected that @next_seq and @handover are initialized by
> their callers (if their callers are interested in the values), then I
> would expect @any_usable to be initialized by the
> caller. console_flush_one_record() never reads this variable.

Yes, that's correct. Perhaps the comments for the parameters should
indicate otherwise?


>
> > @@ -3280,21 +3284,16 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
> >   */
> >  static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
> >  {
> > -     bool any_usable = false;
> > +     bool any_usable;
>
> Since console_flush_all() does read @any_usable, I would expect it to
> initialize @any_usable. So I would not remove this definition initialization.

Prior to this series, console_flush_all would set any_usable to false.
It would be set to true if at any point a usable console is found,
that value would be returned, or otherwise false if handover or panic.
When the first patch split out this function, any_usable was kept as
it was, leading to any_usable being true, even if a handover or panic
had happened (hence additional checks needed, which are removed in
this patch).

By setting any_usable at the start of flush_one_record, it allows for
any_usable to revert back to false, in the case where a once usable
console is no longer usable. Thus representing the situation for the
last record printed. It also makes console_flush_one_record easier to
understand, as the any_usable flag will always be set, rather than
only changing from false to true.

At least that was the intent discussed here [1].

Alternatively, it may be possible for console_flush_one_record to
return any_usable, thus dropping it as an argument and removing the
return of any_progress. Instead the caller could keep calling
console_flush_one_record until it returns false or until next_seq
stops increasing? Thus semantically, the return value of
console_flush_one_record tells you that nothing bad happened and you
can call it again, and the benefit of calling it again depends on if
progress is being made (as determined by the caller through the
existing seq argument).

>
> >       bool any_progress;
> >
> >       *next_seq = 0;
> >       *handover = false;
> >
> >       do {
> > -             any_progress = console_flush_one_record(do_cond_resched, next_seq, handover,
> > -                                                     &any_usable);
> > +             any_progress = console_flush_one_record(do_cond_resched, next_seq,
> > +                                                     handover, &any_usable);
> >
>
> Since the second line of the call to console_flush_one_record() already
> has a ton of whitespace, I would remove the above blank line.

Sure.


>
> John


[1] https://lkml.org/lkml/2025/9/27/200

Andrew Murray

Re: [PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[John Ogness]

On 2025-09-30, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
>> On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
>> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> > index 060d4919de320fe21fd7aca73ba497e27c4ff334..e2c1cacdb4164489c60fe38f1e2837eb838107d6 100644
>> > --- a/kernel/printk/printk.c
>> > +++ b/kernel/printk/printk.c
>> > @@ -3193,6 +3194,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
>> >       bool any_progress;
>> >       int cookie;
>> >
>> > +     *any_usable = false;
>>
>> Since it is expected that @next_seq and @handover are initialized by
>> their callers (if their callers are interested in the values), then I
>> would expect @any_usable to be initialized by the
>> caller. console_flush_one_record() never reads this variable.
>
> Yes, that's correct. Perhaps the comments for the parameters should
> indicate otherwise?

They should clarify. For example, @next_seq is "valid only when this
function returns true" but @handover validitiy is not specified and is
also not related to the return value.

I would like to see the helper function provide clear usage. If the
caller is expected to initialize the parameters (which IMHO it should be
the case for all of the pointer parameters), then that should be
specified.

>> > @@ -3280,21 +3284,16 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
>> >   */
>> >  static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
>> >  {
>> > -     bool any_usable = false;
>> > +     bool any_usable;
>>
>> Since console_flush_all() does read @any_usable, I would expect it to
>> initialize @any_usable. So I would not remove this definition initialization.
>
> Prior to this series, console_flush_all would set any_usable to false.
> It would be set to true if at any point a usable console is found,
> that value would be returned, or otherwise false if handover or panic.
> When the first patch split out this function, any_usable was kept as
> it was, leading to any_usable being true, even if a handover or panic
> had happened (hence additional checks needed, which are removed in
> this patch).
>
> By setting any_usable at the start of flush_one_record, it allows for
> any_usable to revert back to false, in the case where a once usable
> console is no longer usable. Thus representing the situation for the
> last record printed. It also makes console_flush_one_record easier to
> understand, as the any_usable flag will always be set, rather than
> only changing from false to true.

OK. But then just have console_flush_all() set @any_usable in the loop:

static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
{
	bool any_progress;
	bool any_usable;

	*next_seq = 0;
	*handover = false;

	do {
		any_usable = false;
		any_progress = console_flush_one_record(do_cond_resched, next_seq,
							handover, &any_usable);
	} while (any_progress);

	return any_usable;
}

> Alternatively, it may be possible for console_flush_one_record to
> return any_usable, thus dropping it as an argument and removing the
> return of any_progress. Instead the caller could keep calling
> console_flush_one_record until it returns false or until next_seq
> stops increasing? Thus semantically, the return value of
> console_flush_one_record tells you that nothing bad happened and you
> can call it again, and the benefit of calling it again depends on if
> progress is being made (as determined by the caller through the
> existing seq argument).

Sorry, I could not follow how this would work. It sounds like a
simplification. If you can make it work, go for it.

John

Re: [PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[Andrew Murray]

On Wed, 1 Oct 2025 at 10:53, John Ogness <john.ogness@linutronix.de> wrote:
>
> On 2025-09-30, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> >> On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> >> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> >> > index 060d4919de320fe21fd7aca73ba497e27c4ff334..e2c1cacdb4164489c60fe38f1e2837eb838107d6 100644
> >> > --- a/kernel/printk/printk.c
> >> > +++ b/kernel/printk/printk.c
> >> > @@ -3193,6 +3194,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
> >> >       bool any_progress;
> >> >       int cookie;
> >> >
> >> > +     *any_usable = false;
> >>
> >> Since it is expected that @next_seq and @handover are initialized by
> >> their callers (if their callers are interested in the values), then I
> >> would expect @any_usable to be initialized by the
> >> caller. console_flush_one_record() never reads this variable.
> >
> > Yes, that's correct. Perhaps the comments for the parameters should
> > indicate otherwise?
>
> They should clarify. For example, @next_seq is "valid only when this
> function returns true" but @handover validitiy is not specified and is
> also not related to the return value.
>
> I would like to see the helper function provide clear usage. If the
> caller is expected to initialize the parameters (which IMHO it should be
> the case for all of the pointer parameters), then that should be
> specified.

OK.


>
> >> > @@ -3280,21 +3284,16 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
> >> >   */
> >> >  static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
> >> >  {
> >> > -     bool any_usable = false;
> >> > +     bool any_usable;
> >>
> >> Since console_flush_all() does read @any_usable, I would expect it to
> >> initialize @any_usable. So I would not remove this definition initialization.
> >
> > Prior to this series, console_flush_all would set any_usable to false.
> > It would be set to true if at any point a usable console is found,
> > that value would be returned, or otherwise false if handover or panic.
> > When the first patch split out this function, any_usable was kept as
> > it was, leading to any_usable being true, even if a handover or panic
> > had happened (hence additional checks needed, which are removed in
> > this patch).
> >
> > By setting any_usable at the start of flush_one_record, it allows for
> > any_usable to revert back to false, in the case where a once usable
> > console is no longer usable. Thus representing the situation for the
> > last record printed. It also makes console_flush_one_record easier to
> > understand, as the any_usable flag will always be set, rather than
> > only changing from false to true.
>
> OK. But then just have console_flush_all() set @any_usable in the loop:
>
> static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
> {
>         bool any_progress;
>         bool any_usable;
>
>         *next_seq = 0;
>         *handover = false;
>
>         do {
>                 any_usable = false;
>                 any_progress = console_flush_one_record(do_cond_resched, next_seq,
>                                                         handover, &any_usable);
>         } while (any_progress);
>
>         return any_usable;
> }

Yes, that seems like common sense, I have no idea why I didn't think of that :|


>
> > Alternatively, it may be possible for console_flush_one_record to
> > return any_usable, thus dropping it as an argument and removing the
> > return of any_progress. Instead the caller could keep calling
> > console_flush_one_record until it returns false or until next_seq
> > stops increasing? Thus semantically, the return value of
> > console_flush_one_record tells you that nothing bad happened and you
> > can call it again, and the benefit of calling it again depends on if
> > progress is being made (as determined by the caller through the
> > existing seq argument).
>
> Sorry, I could not follow how this would work. It sounds like a
> simplification. If you can make it work, go for it.

Against my patches, something like this:

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 2c9b9383df76..f38295cc3645 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3186,16 +3186,13 @@ static inline void
printk_kthreads_check_locked(void) { }
  *
  * Requires the console_lock.
  */
-static bool console_flush_one_record(bool do_cond_resched, u64
*next_seq, bool *handover,
-                                    bool *any_usable)
+static bool console_flush_one_record(bool do_cond_resched, u64
*next_seq, bool *handover)
 {
        struct console_flush_type ft;
        struct console *con;
-       bool any_progress;
        int cookie;

-       *any_usable = false;
-       any_progress = false;
+       bool any_usable = false;

        printk_get_console_flush_type(&ft);

@@ -3215,7 +3212,7 @@ static bool console_flush_one_record(bool
do_cond_resched, u64 *next_seq, bool *

                if (!console_is_usable(con, flags, !do_cond_resched))
                        continue;
-               *any_usable = true;
+               any_usable = true;

                if (flags & CON_NBCON) {
                        progress = nbcon_legacy_emit_next_record(con,
handover, cookie,
@@ -3239,7 +3236,6 @@ static bool console_flush_one_record(bool
do_cond_resched, u64 *next_seq, bool *

                if (!progress)
                        continue;
-               any_progress = true;

                /* Allow panic_cpu to take over the consoles safely. */
                if (other_cpu_in_panic())
@@ -3250,12 +3246,11 @@ static bool console_flush_one_record(bool
do_cond_resched, u64 *next_seq, bool *
        }
        console_srcu_read_unlock(cookie);

-       return any_progress;
+       return any_usable;

 unusable_srcu:
        console_srcu_read_unlock(cookie);
 unusable:
-       *any_usable = false;
        return false;
 }

@@ -3286,15 +3281,15 @@ static bool console_flush_all(bool
do_cond_resched, u64 *next_seq, bool *handove
 {
        bool any_usable;
        bool any_progress;
+       u64 last_seq;

        *next_seq = 0;
        *handover = false;

        do {
-               any_progress =
console_flush_one_record(do_cond_resched, next_seq,
-                                                       handover, &any_usable);
-
-       } while (any_progress);
+               last_seq = *next_seq;
+               any_usable = console_flush_one_record(do_cond_resched,
next_seq, handover);
+       } while (*next_seq > last_seq);

        return any_usable;
 }
@@ -3674,21 +3669,20 @@ static int legacy_kthread_func(void *unused)
        wait_event_interruptible(legacy_wait,
                                 legacy_kthread_should_wakeup());

+       u64 last_seq, next_seq = 0;
        do {
-               bool any_usable;
                bool handover = false;
-               u64 next_seq;

                if (kthread_should_stop())
                        return 0;

                console_lock();
-               any_progress = console_flush_one_record(true, &next_seq,
-                                               &handover, &any_usable);
+               last_seq = next_seq;
+               console_flush_one_record(true, &next_seq, &handover);
                if (!handover)
                        __console_unlock();

-       } while (any_progress);
+       } while (next_seq > last_seq);

        goto wait_for_event;
 }
-- 
2.34.1

This also has the benefit of removing code (and more could be removed
if the progress variable in console_flush_one_record is removed - i.e.
we could unconditionally bail on panic and resched each time).

Thanks,

Andrew Murray

Re: [PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[Petr Mladek]

On Wed 2025-10-01 17:26:27, Andrew Murray wrote:
> On Wed, 1 Oct 2025 at 10:53, John Ogness <john.ogness@linutronix.de> wrote:
> >
> > On 2025-09-30, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > >> On 2025-09-27, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > >> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > >> > index 060d4919de320fe21fd7aca73ba497e27c4ff334..e2c1cacdb4164489c60fe38f1e2837eb838107d6 100644
> > >> > --- a/kernel/printk/printk.c
> > >> > +++ b/kernel/printk/printk.c
> > >> > @@ -3280,21 +3284,16 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
> > >> >   */
> > >> >  static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
> > >> >  {
> > >> > -     bool any_usable = false;
> > >> > +     bool any_usable;
> > >>
> > >> Since console_flush_all() does read @any_usable, I would expect it to
> > >> initialize @any_usable. So I would not remove this definition initialization.
> > >
> > > Prior to this series, console_flush_all would set any_usable to false.
> > > It would be set to true if at any point a usable console is found,
> > > that value would be returned, or otherwise false if handover or panic.
> > > When the first patch split out this function, any_usable was kept as
> > > it was, leading to any_usable being true, even if a handover or panic
> > > had happened (hence additional checks needed, which are removed in
> > > this patch).
> > >
> > > By setting any_usable at the start of flush_one_record, it allows for
> > > any_usable to revert back to false, in the case where a once usable
> > > console is no longer usable. Thus representing the situation for the
> > > last record printed. It also makes console_flush_one_record easier to
> > > understand, as the any_usable flag will always be set, rather than
> > > only changing from false to true.
> >
> > OK. But then just have console_flush_all() set @any_usable in the loop:
> >
> > static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
> > {
> >         bool any_progress;
> >         bool any_usable;
> >
> >         *next_seq = 0;
> >         *handover = false;
> >
> >         do {
> >                 any_usable = false;
> >                 any_progress = console_flush_one_record(do_cond_resched, next_seq,
> >                                                         handover, &any_usable);
> >         } while (any_progress);
> >
> >         return any_usable;
> > }
> 
> Yes, that seems like common sense, I have no idea why I didn't think of that :|

Looks good to me.

> 
> >
> > > Alternatively, it may be possible for console_flush_one_record to
> > > return any_usable, thus dropping it as an argument and removing the
> > > return of any_progress. Instead the caller could keep calling
> > > console_flush_one_record until it returns false or until next_seq
> > > stops increasing?

No, this won't work. @next_seq shows the highest value from all
consoles. It is no longer increased when at least one console
flushed all pending messages. But other consoles might be
behind, still having pending messages, and still making progress.

Honestly, I do not know how to make it better. We need to pass
both information: @next_seq and if some console flushed something.

Note that @next_seq is valid only when all consoles are flushed
and returning the same @next_seq. But it does not help to remove
the @any_progress parameter.

Best Regards,
Petr

Re: [PATCH v2 1/3] printk: Introduce console_flush_one_record

[Petr Mladek]

On Sat 2025-09-27 23:05:35, Andrew Murray wrote:
> console_flush_all prints all remaining records to all usable consoles
> whilst its caller holds console_lock. This can result in large waiting
> times for those waiting for console_lock especially where there is a
> large volume of records or where the console is slow (e.g. serial).
> 
> Let's extract the parts of this function which print a single record
> into a new function named console_flush_one_record. This can later
> be used for functions that will release and reacquire console_lock
> between records.
> 
> This commit should not change existing functionality.
> 
> Reviewed-by: Petr Mladek <pmladek@suse.com>
> Signed-off-by: Andrew Murray <amurray@thegoodpenguin.co.uk>
> ---
>  kernel/printk/printk.c | 159 +++++++++++++++++++++++++++++++------------------
>  1 file changed, 100 insertions(+), 59 deletions(-)
> 
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 0efbcdda9aaba9d8d877df5e4f1db002d3a596bc..060d4919de320fe21fd7aca73ba497e27c4ff334 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3161,6 +3161,100 @@ static inline void printk_kthreads_check_locked(void) { }
>  
>  #endif /* CONFIG_PRINTK */
>  
> +
> +/*
> + * Print out one record for each console.
> + *
> + * @do_cond_resched is set by the caller. It can be true only in schedulable
> + * context.
> + *
> + * @next_seq is set to the sequence number after the last available record.
> + * The value is valid only when this function returns true.

This actually is not true. This function tries to flush one record on all usable
consoles. And @next_seq is set to the highest already emitted sequence
number. But some consoles might be (far) behind.

A more precise description would be something like:

 * @next_seq is set to the sequence number after the last available record.
 * The value is valid only when there is at least one usable console
 * (@any_usable == true) and all usable consoles were flushed
 * (function returns false && @handover == false &&
 * other_cpu_in_panic() == false)

Huh, it is complicated. This is why I suggested to change the semantic
of @any_usable in the 2nd patch. It would be cleared when the emit
was interrupted (handover or other_cpu_in_panic()).

Best Regards,
Petr

> + * @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 the
> + * console_lock. Otherwise it is set to false.
> + *
> + * @any_usable will be set to true if there are any usable consoles.
> + *
> + * Returns true when there was at least one usable console and a record was
> + * flushed. A returned false indicates there were no records to flush for any
> + * of the consoles. It may also indicate that there were no usable consoles,
> + * the context has been lost or there is a panic suitation. Regardless the
> + * reason, the caller should assume it is not useful to immediately try again.
> + *
> + * Requires the console_lock.
> + */
> +static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *handover,
> +				     bool *any_usable)
> +{
> +	struct console_flush_type ft;
> +	struct console *con;
> +	bool any_progress;
> +	int cookie;
> +
> +	any_progress = false;
> +
> +	printk_get_console_flush_type(&ft);
> +
> +	cookie = console_srcu_read_lock();
> +	for_each_console_srcu(con) {
> +		short flags = console_srcu_read_flags(con);
> +		u64 printk_seq;
> +		bool progress;
> +
> +		/*
> +		 * console_flush_one_record() is only responsible for
> +		 * nbcon consoles when the nbcon consoles cannot print via
> +		 * their atomic or threaded flushing.
> +		 */
> +		if ((flags & CON_NBCON) && (ft.nbcon_atomic || ft.nbcon_offload))
> +			continue;
> +
> +		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,
> +								 !do_cond_resched);
> +			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
> +		 * is already released.
> +		 */
> +		if (*handover)
> +			return false;
> +
> +		/* Track the next of the highest seq flushed. */
> +		if (printk_seq > *next_seq)
> +			*next_seq = printk_seq;
> +
> +		if (!progress)
> +			continue;
> +		any_progress = true;
> +
> +		/* Allow panic_cpu to take over the consoles safely. */
> +		if (other_cpu_in_panic())
> +			goto abandon;
> +
> +		if (do_cond_resched)
> +			cond_resched();
> +	}
> +	console_srcu_read_unlock(cookie);
> +
> +	return any_progress;
> +
> +abandon:
> +	console_srcu_read_unlock(cookie);
> +	return false;
> +}
> +
>  /*
>   * Print out all remaining records to all consoles.
>   *
> @@ -3186,77 +3280,24 @@ static inline void printk_kthreads_check_locked(void) { }
>   */
>  static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
>  {
> -	struct console_flush_type ft;
>  	bool any_usable = false;
> -	struct console *con;
>  	bool any_progress;
> -	int cookie;
>  
>  	*next_seq = 0;
>  	*handover = false;
>  
>  	do {
> -		any_progress = false;
> -
> -		printk_get_console_flush_type(&ft);
> -
> -		cookie = console_srcu_read_lock();
> -		for_each_console_srcu(con) {
> -			short flags = console_srcu_read_flags(con);
> -			u64 printk_seq;
> -			bool progress;
> +		any_progress = console_flush_one_record(do_cond_resched, next_seq, handover,
> +							&any_usable);
>  
> -			/*
> -			 * console_flush_all() is only responsible for nbcon
> -			 * consoles when the nbcon consoles cannot print via
> -			 * their atomic or threaded flushing.
> -			 */
> -			if ((flags & CON_NBCON) && (ft.nbcon_atomic || ft.nbcon_offload))
> -				continue;
> -
> -			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,
> -									 !do_cond_resched);
> -				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
> -			 * is already released.
> -			 */
> -			if (*handover)
> -				return false;
> -
> -			/* Track the next of the highest seq flushed. */
> -			if (printk_seq > *next_seq)
> -				*next_seq = printk_seq;
> -
> -			if (!progress)
> -				continue;
> -			any_progress = true;
> -
> -			/* Allow panic_cpu to take over the consoles safely. */
> -			if (other_cpu_in_panic())
> -				goto abandon;
> +		if (*handover)
> +			return false;
>  
> -			if (do_cond_resched)
> -				cond_resched();
> -		}
> -		console_srcu_read_unlock(cookie);
> +		if (other_cpu_in_panic())
> +			return false;
>  	} while (any_progress);
>  
>  	return any_usable;
> -
> -abandon:
> -	console_srcu_read_unlock(cookie);
> -	return false;
>  }
>  
>  static void __console_flush_and_unlock(void)
> 
> -- 
> 2.34.1

Re: [PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[Petr Mladek]

On Thu 2025-10-02 12:10:50, Petr Mladek wrote:
> On Wed 2025-10-01 17:26:27, Andrew Murray wrote:
> > On Wed, 1 Oct 2025 at 10:53, John Ogness <john.ogness@linutronix.de> wrote:
> > >
> > > On 2025-09-30, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > > > Alternatively, it may be possible for console_flush_one_record to
> > > > return any_usable, thus dropping it as an argument and removing the
> > > > return of any_progress. Instead the caller could keep calling
> > > > console_flush_one_record until it returns false or until next_seq
> > > > stops increasing?
> 
> No, this won't work. @next_seq shows the highest value from all
> consoles. It is no longer increased when at least one console
> flushed all pending messages. But other consoles might be
> behind, still having pending messages, and still making progress.
> 
> Honestly, I do not know how to make it better. We need to pass
> both information: @next_seq and if some console flushed something.
> 
> Note that @next_seq is valid only when all consoles are flushed
> and returning the same @next_seq. But it does not help to remove
> the @any_progress parameter.

I thought more about how to improve the semantic and came up with
the following patch. It is supposed to replace this one.

Note: I created this patch on top of Linus' tree as of today.
      It already includes the patchset (-mm tree) which consolidated
      the panic state API.

      Namely, this patchset is affected by the commit d4a36db5639db03
      ("panic/printk: replace other_cpu_in_panic() with
      panic_on_other_cpu()").

      It is enough to do:

	  s/other_cpu_in_panic/panic_on_other_cpu/

      I am sorry for any inconvenience.


Here is the new proposal:

From 30f5302b11962f8ec961ca85419ed097a5b76502 Mon Sep 17 00:00:00 2001
From: Petr Mladek <pmladek@suse.com>
Date: Sat, 27 Sep 2025 23:05:36 +0100
Subject: [PATCH 2/3] printk: console_flush_one_record() code cleanup

console_flush_one_record() and console_flush_all() duplicate several
checks. They both want to tell the caller that consoles are not
longer usable in this context because it has lost the lock or
the lock has to be reserved for the panic CPU.

Remove the duplication by changing the semantic of the function
console_flush_one_record() return value and parameters.

The function will return true when it is able to do the job. It means
that there is at least one usable console. And the flushing was
not interrupted by a takeover or panic_on_other_cpu().

Also replace the @any_usable parameter with @try_again. The @try_again
parameter will be set to true when the function could do the job
and at least one console made a progress.

Motivation:

The callers need to know when

  + they should continue flushing => @try_again
  + when the console is flushed => can_do_the_job(return) && !@try_again
  + when @next_seq is valid => same as flushed
  + when lost console_lock => @takeover

The proposed change makes it clear when the function can do
the job. It simplifies the answer for the other questions.

Also the return value from console_flush_one_record() can
be used as return value from console_flush_all().

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

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fa9bd511a1fb..6c846d2d37d9 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3142,31 +3142,32 @@ static inline void printk_kthreads_check_locked(void) { }
  * context.
  *
  * @next_seq is set to the sequence number after the last available record.
- * The value is valid only when this function returns true.
+ * The value is valid only when all usable consoles were flushed. It is
+ * when the function returns true (can do the job) and @try_again parameter
+ * is set to false, see below.
  *
  * @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 the
  * console_lock. Otherwise it is set to false.
  *
- * @any_usable will be set to true if there are any usable consoles.
+ * @try_again will be set to true when it still makes sense to call this
+ * function again. The function could do the job, see the return value.
+ * And some consoles still make progress.
  *
- * Returns true when there was at least one usable console and a record was
- * flushed. A returned false indicates there were no records to flush for any
- * of the consoles. It may also indicate that there were no usable consoles,
- * the context has been lost or there is a panic suitation. Regardless the
- * reason, the caller should assume it is not useful to immediately try again.
+ * Returns true when the function could do the job. Some consoles are usable,
+ * and there was no takeover and no panic_on_other_cpu().
  *
  * Requires the console_lock.
  */
 static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *handover,
-				     bool *any_usable)
+				     bool *try_again)
 {
 	struct console_flush_type ft;
+	int any_usable = false;
 	struct console *con;
-	bool any_progress;
 	int cookie;
 
-	any_progress = false;
+	*try_again = false;
 
 	printk_get_console_flush_type(&ft);
 
@@ -3186,7 +3187,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
 
 		if (!console_is_usable(con, flags, !do_cond_resched))
 			continue;
-		*any_usable = true;
+		any_usable = true;
 
 		if (flags & CON_NBCON) {
 			progress = nbcon_legacy_emit_next_record(con, handover, cookie,
@@ -3202,7 +3203,7 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
 		 * is already released.
 		 */
 		if (*handover)
-			return false;
+			goto fail;
 
 		/* Track the next of the highest seq flushed. */
 		if (printk_seq > *next_seq)
@@ -3210,21 +3211,28 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
 
 		if (!progress)
 			continue;
-		any_progress = true;
+
+		/*
+		 * An usable console made a progress. There might still be
+		 * pending messages.
+		 */
+		*try_again = true;
 
 		/* Allow panic_cpu to take over the consoles safely. */
 		if (panic_on_other_cpu())
-			goto abandon;
+			goto fail_srcu;
 
 		if (do_cond_resched)
 			cond_resched();
 	}
 	console_srcu_read_unlock(cookie);
 
-	return any_progress;
+	return any_usable;
 
-abandon:
+fail_srcu:
 	console_srcu_read_unlock(cookie);
+fail:
+	*try_again = false;
 	return false;
 }
 
@@ -3253,24 +3261,18 @@ static bool console_flush_one_record(bool do_cond_resched, u64 *next_seq, bool *
  */
 static bool console_flush_all(bool do_cond_resched, u64 *next_seq, bool *handover)
 {
-	bool any_usable = false;
-	bool any_progress;
+	bool try_again;
+	bool ret;
 
 	*next_seq = 0;
 	*handover = false;
 
 	do {
-		any_progress = console_flush_one_record(do_cond_resched, next_seq, handover,
-							&any_usable);
+		ret = console_flush_one_record(do_cond_resched, next_seq,
+					       handover, &try_again);
+	} while (try_again);
 
-		if (*handover)
-			return false;
-
-		if (panic_on_other_cpu())
-			return false;
-	} while (any_progress);
-
-	return any_usable;
+	return ret;
 }
 
 static void __console_flush_and_unlock(void)
-- 
2.51.0

Re: [PATCH v2 3/3] printk: Use console_flush_one_record for legacy printer kthread

[Petr Mladek]

Here is the same patch with the alternative semantic of
console_flush_one_record() as proposed at
https://lore.kernel.org/all/aN_3id2CF7ivC42R@pathway.suse.cz/

The return value from console_flush_all() can be ignored.
It is enough to check whether @try_again is true.

I hope that this semantic is more straightforward.

Here to go:

From 51667c506c13f662d222c7907e6a055ae77639a0 Mon Sep 17 00:00:00 2001
From: Andrew Murray <amurray@thegoodpenguin.co.uk>
Date: Sat, 27 Sep 2025 23:05:37 +0100
Subject: [PATCH 3/3] printk: Use console_flush_one_record for legacy printer
 kthread

The legacy printer kthread uses console_lock and
__console_flush_and_unlock to flush records to the console. This
approach results in the console_lock being held for the entire
duration of a flush. This can result in large waiting times for
those waiting for console_lock especially where there is a large
volume of records or where the console is slow (e.g. serial). This
contention is observed during boot, as the call to filp_open in
console_on_rootfs will delay progression to userspace until any
in-flight flush is completed.

Let's instead use console_flush_one_record and release/reacquire
the console_lock between records.

On a PocketBeagle 2, with the following boot args:
"console=ttyS2,9600 initcall_debug=1 loglevel=10"

Without this patch:

[    5.613166] +console_on_rootfs/filp_open
[    5.643473] mmc1: SDHCI controller on fa00000.mmc [fa00000.mmc] using ADMA 64-bit
[    5.643823] probe of fa00000.mmc returned 0 after 258244 usecs
[    5.710520] mmc1: new UHS-I speed SDR104 SDHC card at address 5048
[    5.721976] mmcblk1: mmc1:5048 SD32G 29.7 GiB
[    5.747258]  mmcblk1: p1 p2
[    5.753324] probe of mmc1:5048 returned 0 after 40002 usecs
[   15.595240] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30040000.pruss
[   15.595282] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e010000.watchdog
[   15.595297] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e000000.watchdog
[   15.595437] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30300000.crc
[  146.275961] -console_on_rootfs/filp_open ...

and with:

[    5.477122] +console_on_rootfs/filp_open
[    5.595814] mmc1: SDHCI controller on fa00000.mmc [fa00000.mmc] using ADMA 64-bit
[    5.596181] probe of fa00000.mmc returned 0 after 312757 usecs
[    5.662813] mmc1: new UHS-I speed SDR104 SDHC card at address 5048
[    5.674367] mmcblk1: mmc1:5048 SD32G 29.7 GiB
[    5.699320]  mmcblk1: p1 p2
[    5.705494] probe of mmc1:5048 returned 0 after 39987 usecs
[    6.418682] -console_on_rootfs/filp_open ...
...
[   15.593509] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30040000.pruss
[   15.593551] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e010000.watchdog
[   15.593566] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to e000000.watchdog
[   15.593704] ti_sci_pm_domains 44043000.system-controller:power-controller: sync_state() pending due to 30300000.crc

Where I've added a printk surrounding the call in console_on_rootfs to filp_open.

Suggested-by: Petr Mladek <pmladek@suse.com>
Signed-off-by: Andrew Murray <amurray@thegoodpenguin.co.uk>
---
 kernel/printk/printk.c | 22 ++++++++++++++++------
 1 file changed, 16 insertions(+), 6 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 6c846d2d37d9..885506fa0178 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3644,17 +3644,27 @@ static bool legacy_kthread_should_wakeup(void)
 
 static int legacy_kthread_func(void *unused)
 {
-	for (;;) {
-		wait_event_interruptible(legacy_wait, legacy_kthread_should_wakeup());
+	bool try_again;
+
+wait_for_event:
+	wait_event_interruptible(legacy_wait,
+				 legacy_kthread_should_wakeup());
+
+	do {
+		bool handover = false;
+		u64 next_seq;
 
 		if (kthread_should_stop())
-			break;
+			return 0;
 
 		console_lock();
-		__console_flush_and_unlock();
-	}
+		console_flush_one_record(true, &next_seq, &handover, &try_again);
+		if (!handover)
+			__console_unlock();
 
-	return 0;
+	} while (try_again);
+
+	goto wait_for_event;
 }
 
 static bool legacy_kthread_create(void)
-- 
2.51.0

Re: [PATCH v2 2/3] printk: console_flush_one_record() code cleanup

[John Ogness]

On 2025-10-03, Petr Mladek <pmladek@suse.com> wrote:
> From 30f5302b11962f8ec961ca85419ed097a5b76502 Mon Sep 17 00:00:00 2001
> From: Petr Mladek <pmladek@suse.com>
> Date: Sat, 27 Sep 2025 23:05:36 +0100
> Subject: [PATCH 2/3] printk: console_flush_one_record() code cleanup
>
> console_flush_one_record() and console_flush_all() duplicate several
> checks. They both want to tell the caller that consoles are not
> longer usable in this context because it has lost the lock or
> the lock has to be reserved for the panic CPU.
>
> Remove the duplication by changing the semantic of the function
> console_flush_one_record() return value and parameters.
>
> The function will return true when it is able to do the job. It means
> that there is at least one usable console. And the flushing was
> not interrupted by a takeover or panic_on_other_cpu().
>
> Also replace the @any_usable parameter with @try_again. The @try_again
> parameter will be set to true when the function could do the job
> and at least one console made a progress.
>
> Motivation:
>
> The callers need to know when
>
>   + they should continue flushing => @try_again
>   + when the console is flushed => can_do_the_job(return) && !@try_again
>   + when @next_seq is valid => same as flushed
>   + when lost console_lock => @takeover
>
> The proposed change makes it clear when the function can do
> the job. It simplifies the answer for the other questions.
>
> Also the return value from console_flush_one_record() can
> be used as return value from console_flush_all().
>
> Signed-off-by: Petr Mladek <pmladek@suse.com>

Reviewed-by: John Ogness <john.ogness@linutronix.de>

Re: [PATCH v2 3/3] printk: Use console_flush_one_record for legacy printer kthread

[John Ogness]

On 2025-10-03, Petr Mladek <pmladek@suse.com> wrote:
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 6c846d2d37d9..885506fa0178 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3644,17 +3644,27 @@ static bool legacy_kthread_should_wakeup(void)
>  
>  static int legacy_kthread_func(void *unused)
>  {
> -	for (;;) {
> -		wait_event_interruptible(legacy_wait, legacy_kthread_should_wakeup());
> +	bool try_again;
> +
> +wait_for_event:
> +	wait_event_interruptible(legacy_wait,
> +				 legacy_kthread_should_wakeup());

This should be on one line. Even with an 80-character limit it would
fit. ;-)

> +
> +	do {
> +		bool handover = false;
> +		u64 next_seq;

Even though legacy_kthread_func() does not care, @next_seq should be
initialized to something since console_flush_one_record() reads this
value to decide if it should be increased. It really doesn't matter what
it is initialized to, but I guess 0 makes the most sense.

John