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

[PATCH v3 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 v3:
- Rebased on v6.18-rc2
- Reordering of variables and minor tweak to comments in console_flush_one_record
  in first patch
- Improve semantics of console_flush_one_record in the second patch through different
  use of return value and by replacing any_usable with try_again.
- Update third patch to use newer version of console_flush_one_record
- Link to v2: https://lore.kernel.org/r/20250927-printk_legacy_thread_console_lock-v2-0-cff9f063071a@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: 211ddde0823f1442e4ad052a2f30f050145ccada
change-id: 20250914-printk_legacy_thread_console_lock-1c27f59bf990

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

[PATCH v3 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 | 158 +++++++++++++++++++++++++++++++------------------
 1 file changed, 99 insertions(+), 59 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 5aee9ffb16b9a5e7bfadb0266a77bfa569e50e51..1c048c66d09919967e57326e1732bd17c10f3c76 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3134,6 +3134,99 @@ 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 there is at least one usable console and all
+ * usable consoles were flushed.
+ *
+ * @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;
+	bool any_progress = false;
+	struct console *con;
+	int cookie;
+
+	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 (panic_on_other_cpu())
+			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.
  *
@@ -3159,77 +3252,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;
+		any_progress = console_flush_one_record(do_cond_resched, next_seq, handover,
+							&any_usable);
 
-		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;
+		if (*handover)
+			return false;
 
-			/*
-			 * 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 (panic_on_other_cpu())
-				goto abandon;
-
-			if (do_cond_resched)
-				cond_resched();
-		}
-		console_srcu_read_unlock(cookie);
+		if (panic_on_other_cpu())
+			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 v3 1/3] printk: Introduce console_flush_one_record

[John Ogness]

On 2025-10-20, Andrew Murray <amurray@thegoodpenguin.co.uk> 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>

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

[PATCH v3 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.

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().

Reviewed-by: John Ogness <john.ogness@linutronix.de>
Signed-off-by: Petr Mladek <pmladek@suse.com>
---
 kernel/printk/printk.c | 59 ++++++++++++++++++++++++++------------------------
 1 file changed, 31 insertions(+), 28 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1c048c66d09919967e57326e1732bd17c10f3c76..6c846d2d37d9d20bad58c6e3a7caada3be9552ca 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3142,31 +3142,33 @@ 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 there is at least one usable console and all
- * usable consoles were flushed.
+ * 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;
-	bool any_progress = false;
+	int any_usable = false;
 	struct console *con;
 	int cookie;
 
+	*try_again = false;
+
 	printk_get_console_flush_type(&ft);
 
 	cookie = console_srcu_read_lock();
@@ -3185,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,
@@ -3201,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)
@@ -3209,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;
 }
 
@@ -3252,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.34.1

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

[John Ogness]

On 2025-10-20, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 1c048c66d09919967e57326e1732bd17c10f3c76..6c846d2d37d9d20bad58c6e3a7caada3be9552ca 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3142,31 +3142,33 @@ 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 there is at least one usable console and all
> - * usable consoles were flushed.
> + * 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;
> -	bool any_progress = false;
> +	int any_usable = false;

Nit: This should be a bool.

With the change:

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

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

[Petr Mladek]

On Thu 2025-10-23 15:24:14, John Ogness wrote:
> On 2025-10-20, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index 1c048c66d09919967e57326e1732bd17c10f3c76..6c846d2d37d9d20bad58c6e3a7caada3be9552ca 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -3142,31 +3142,33 @@ 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 there is at least one usable console and all
> > - * usable consoles were flushed.
> > + * 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;
> > -	bool any_progress = false;
> > +	int any_usable = false;
> 
> Nit: This should be a bool.

Great catch! No need to resend the patch. I could fix this when committing.

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

Thanks for the review. 

Best Regards,
Petr

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

[Andrew Murray]

On Thu, 23 Oct 2025 at 15:54, Petr Mladek <pmladek@suse.com> wrote:
>
> On Thu 2025-10-23 15:24:14, John Ogness wrote:
> > On 2025-10-20, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > index 1c048c66d09919967e57326e1732bd17c10f3c76..6c846d2d37d9d20bad58c6e3a7caada3be9552ca 100644
> > > --- a/kernel/printk/printk.c
> > > +++ b/kernel/printk/printk.c
> > > @@ -3142,31 +3142,33 @@ 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 there is at least one usable console and all
> > > - * usable consoles were flushed.
> > > + * 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;
> > > -   bool any_progress = false;
> > > +   int any_usable = false;
> >
> > Nit: This should be a bool.
>
> Great catch! No need to resend the patch. I could fix this when committing.
>
> > With the change:
> >
> > Reviewed-by: John Ogness <john.ogness@linutronix.de>
>
> Thanks for the review.

You can also add my reviewed-by with this change:

Reviewed-by: Andrew Murray <amurray@thegoodpenguin.co.uk>

Thanks,

Andrew Murray

>
> Best Regards,
> Petr

[PATCH v3 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 | 21 +++++++++++++++------
 1 file changed, 15 insertions(+), 6 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 6c846d2d37d9d20bad58c6e3a7caada3be9552ca..2665a7a59f03b3a357b3346de1735606e77c3496 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -3644,17 +3644,26 @@ 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 {
+		u64 next_seq = 0;
+		bool handover = false;
 
 		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.34.1

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

[John Ogness]

On 2025-10-20, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> index 6c846d2d37d9d20bad58c6e3a7caada3be9552ca..2665a7a59f03b3a357b3346de1735606e77c3496 100644
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3644,17 +3644,26 @@ 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 {
> +		u64 next_seq = 0;
> +		bool handover = false;

Nit: I prefer to sort by line length:

		bool handover = false;
		u64 next_seq = 0;

With change:

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

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

[Petr Mladek]

On Thu 2025-10-23 15:25:34, John Ogness wrote:
> On 2025-10-20, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > index 6c846d2d37d9d20bad58c6e3a7caada3be9552ca..2665a7a59f03b3a357b3346de1735606e77c3496 100644
> > --- a/kernel/printk/printk.c
> > +++ b/kernel/printk/printk.c
> > @@ -3644,17 +3644,26 @@ 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 {
> > +		u64 next_seq = 0;
> > +		bool handover = false;
> 
> Nit: I prefer to sort by line length:
> 
> 		bool handover = false;
> 		u64 next_seq = 0;

OK, no need to resend the patch. I'll change this when pushing it.

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

The patch looks good to me as well:

Reviewed-by: Petr Mladek <pmladek@suse.com>

Best Regards,
Petr

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

[Andrew Murray]

On Thu, 23 Oct 2025 at 15:56, Petr Mladek <pmladek@suse.com> wrote:
>
> On Thu 2025-10-23 15:25:34, John Ogness wrote:
> > On 2025-10-20, Andrew Murray <amurray@thegoodpenguin.co.uk> wrote:
> > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> > > index 6c846d2d37d9d20bad58c6e3a7caada3be9552ca..2665a7a59f03b3a357b3346de1735606e77c3496 100644
> > > --- a/kernel/printk/printk.c
> > > +++ b/kernel/printk/printk.c
> > > @@ -3644,17 +3644,26 @@ 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 {
> > > +           u64 next_seq = 0;
> > > +           bool handover = false;
> >
> > Nit: I prefer to sort by line length:
> >
> >               bool handover = false;
> >               u64 next_seq = 0;
>
> OK, no need to resend the patch. I'll change this when pushing it.

Sounds good to me.

Andrew Murray

>
> > With change:
> >
> > Reviewed-by: John Ogness <john.ogness@linutronix.de>
>
> The patch looks good to me as well:
>
> Reviewed-by: Petr Mladek <pmladek@suse.com>
>
> Best Regards,
> Petr

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

[Petr Mladek]

On Mon 2025-10-20 16:38:04, Andrew Murray wrote:
> 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 v3:
> - Rebased on v6.18-rc2
> - Reordering of variables and minor tweak to comments in console_flush_one_record
>   in first patch
> - Improve semantics of console_flush_one_record in the second patch through different
>   use of return value and by replacing any_usable with try_again.
> - Update third patch to use newer version of console_flush_one_record
> - Link to v2: https://lore.kernel.org/r/20250927-printk_legacy_thread_console_lock-v2-0-cff9f063071a@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: 211ddde0823f1442e4ad052a2f30f050145ccada
> change-id: 20250914-printk_legacy_thread_console_lock-1c27f59bf990

JFYI, the patchset has been committed into printk/linux.git,
branch rework/preempt-legacy-kthread. It is intended for 6.19.

Best Regards,
Petr