1. Patchew
  2. linux
  3. [PATCH v3 0/3] printk: Release console_lock between printing records in legacy thread
  4. View patch

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

Andrew Murray posted 3 patches 1 month, 3 weeks ago
[PATCH v3 3/3] printk: Use console_flush_one_record for legacy printer kthread
Posted by Andrew Murray 1 month, 3 weeks ago 
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
Posted by John Ogness 1 month, 3 weeks ago 
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
Posted by Petr Mladek 1 month, 3 weeks ago 
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
Posted by Andrew Murray 1 month, 3 weeks ago 
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

Patchew 2.1-devel-b67e4c2

© 2016 - 2025 Red Hat, Inc.