[printk,v1,03/18] printk: Consolidate console deferred printing

Message ID 20230302195618.156940-4-john.ogness@linutronix.de
State New
Headers
Series threaded/atomic console support |

Commit Message

John Ogness March 2, 2023, 7:56 p.m. UTC
  Printig to consoles can be deferred for several reasons:

- explicitly with printk_deferred()
- printk() in NMI context
- recursive printk() calls

The current implementation is not consistent. For printk_deferred(),
irq work is scheduled twice. For NMI und recursive, panic CPU
suppression and caller delays are not properly enforced.

Correct these inconsistencies by consolidating the deferred printing
code so that vprintk_deferred() is the toplevel function for
deferred printing and vprintk_emit() will perform whichever irq_work
queueing is appropriate.

Also add kerneldoc for wake_up_klogd() and defer_console_output() to
clarify their differences and appropriate usage.

Signed-off-by: John Ogness <john.ogness@linutronix.de>
---
 kernel/printk/printk.c      | 31 ++++++++++++++++++++++++-------
 kernel/printk/printk_safe.c |  9 ++-------
 2 files changed, 26 insertions(+), 14 deletions(-)
  

Comments

Petr Mladek March 8, 2023, 1:15 p.m. UTC | #1
On Thu 2023-03-02 21:02:03, John Ogness wrote:
> Printig to consoles can be deferred for several reasons:
> 
> - explicitly with printk_deferred()
> - printk() in NMI context
> - recursive printk() calls
> 
> The current implementation is not consistent. For printk_deferred(),
> irq work is scheduled twice. For NMI und recursive, panic CPU
> suppression and caller delays are not properly enforced.
> 
> Correct these inconsistencies by consolidating the deferred printing
> code so that vprintk_deferred() is the toplevel function for
> deferred printing and vprintk_emit() will perform whichever irq_work
> queueing is appropriate.
> 
> Also add kerneldoc for wake_up_klogd() and defer_console_output() to
> clarify their differences and appropriate usage.

> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -2321,7 +2321,10 @@ asmlinkage int vprintk_emit(int facility, int level,
>  		preempt_enable();
>  	}
>  
> -	wake_up_klogd();
> +	if (in_sched)
> +		defer_console_output();
> +	else
> +		wake_up_klogd();

Nit: I would add an empty line here. Or I would move this up into the
     previous if (in_sched()) condition.

>  	return printed_len;
>  }
>  EXPORT_SYMBOL(vprintk_emit);
> @@ -3811,11 +3814,30 @@ static void __wake_up_klogd(int val)
>  	preempt_enable();
>  }
>  
> +/**
> + * wake_up_klogd - Wake kernel logging daemon
> + *
> + * Use this function when new records have been added to the ringbuffer
> + * and the console printing for those records is handled elsewhere. In

"elsewhere" is ambiguous. I would write:

"and the console printing for those records maybe handled in this context".

> + * this case only the logging daemon needs to be woken.
> + *
> + * Context: Any context.
> + */
>  void wake_up_klogd(void)
>  {
>  	__wake_up_klogd(PRINTK_PENDING_WAKEUP);
>  }
>  

Anyway, I like this change.

Best Regards,
Petr
  
John Ogness March 17, 2023, 1:05 p.m. UTC | #2
On 2023-03-08, Petr Mladek <pmladek@suse.com> wrote:
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -2321,7 +2321,10 @@ asmlinkage int vprintk_emit(int facility, int level,
>>  		preempt_enable();
>>  	}
>>  
>> -	wake_up_klogd();
>> +	if (in_sched)
>> +		defer_console_output();
>> +	else
>> +		wake_up_klogd();
>
> Nit: I would add an empty line here. Or I would move this up into the
>      previous if (in_sched()) condition.

Empty line is ok. I do not want to move it up because the above
condition gets more complicated later. IMHO a simple if/else for
specifying what the irq_work should do is the most straight forward
here.

>> @@ -3811,11 +3814,30 @@ static void __wake_up_klogd(int val)
>>  	preempt_enable();
>>  }
>>  
>> +/**
>> + * wake_up_klogd - Wake kernel logging daemon
>> + *
>> + * Use this function when new records have been added to the ringbuffer
>> + * and the console printing for those records is handled elsewhere. In
>
> "elsewhere" is ambiguous. I would write:
>
> "and the console printing for those records maybe handled in this context".

The reason for using the word "elsewhere" is because in later patches it
is also the printing threads that can handle it. I can change it to
"this context" for this patch, but then after adding threads I will need
to adjust the comment again. How about:

"and the console printing for those records should not be handled by the
irq_work context because another context will handle it."

> Anyway, I like this change.

Thanks.

John
  
Petr Mladek April 13, 2023, 3:15 p.m. UTC | #3
On Fri 2023-03-17 14:11:01, John Ogness wrote:
> On 2023-03-08, Petr Mladek <pmladek@suse.com> wrote:
> >> --- a/kernel/printk/printk.c
> >> +++ b/kernel/printk/printk.c
> >> @@ -2321,7 +2321,10 @@ asmlinkage int vprintk_emit(int facility, int level,
> >>  		preempt_enable();
> >>  	}
> >>  
> >> -	wake_up_klogd();
> >> +	if (in_sched)
> >> +		defer_console_output();
> >> +	else
> >> +		wake_up_klogd();
> >
> > Nit: I would add an empty line here. Or I would move this up into the
> >      previous if (in_sched()) condition.
> 
> Empty line is ok. I do not want to move it up because the above
> condition gets more complicated later. IMHO a simple if/else for
> specifying what the irq_work should do is the most straight forward
> here.
> 
> >> @@ -3811,11 +3814,30 @@ static void __wake_up_klogd(int val)
> >>  	preempt_enable();
> >>  }
> >>  
> >> +/**
> >> + * wake_up_klogd - Wake kernel logging daemon
> >> + *
> >> + * Use this function when new records have been added to the ringbuffer
> >> + * and the console printing for those records is handled elsewhere. In
> >
> > "elsewhere" is ambiguous. I would write:
> >
> > "and the console printing for those records maybe handled in this context".
> 
> The reason for using the word "elsewhere" is because in later patches it
> is also the printing threads that can handle it. I can change it to
> "this context" for this patch, but then after adding threads I will need
> to adjust the comment again. How about:
> 
> "and the console printing for those records should not be handled by the
> irq_work context because another context will handle it."

It is better but still a bit hard to follow. As a reader, I see three
contexts:

   + context that calls wake_up_klogd()
   + irq_work context
   + another context that would handle the console printing

The confusing part is that the "another context". It might be the
context calling wake_up_klogd(). If feels like scratching
right ear by left hand ;-)

In fact, also the next sentence "In this case only the logging
daemon needs to be woken." is misleading. Also the printk
kthreads need to be woken but it is done by another function.

OK, what about?

 * wake_up_klogd - Wake kernel logging daemon
 *
 * Use this function when new records have been added to the ringbuffer
 * and the console printing does not have to be deferred to irq_work
 * context. This function will only wake the logging daemons.


Heh, the "wake_up_klogd_work" has became confusing since it started
handling deferred console output. And it is even more confusing now
when it does not handle the kthreads which are yet another deferred
output. But I can't think of any reasonable solution at the moment.

Maybe, we should somehow distinguish the API that will handle only
the legacy consoles. For example, suspend_console() handles both
but console_flush_all() will handle only the legacy ones.

I think that we are going to use nbcon_ prefix for the API
handling the new consoles. Maybe we could use another prefix
for the legacy-consoles-specific API.

Hmm, what about?

    + "bcon_" like the opposite of "nbcon_" but it might be
      confused with boot console

    + "lcon_" like "legacy" or "locked" consoles

    + "scon" like synchronized or serialized consoles.


Honestly, I am not sure how much important this is. But it might
be pretty helpful for anyone who would try to understand the code
in the future. And this rework might be really challenging for
future archaeologists. Not to say, that legacy consoles will
likely stay with us many years, maybe decades.

Best Regards,
Petr
  

Patch

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 84af038292d9..bdeaf12e0bd2 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2321,7 +2321,10 @@  asmlinkage int vprintk_emit(int facility, int level,
 		preempt_enable();
 	}
 
-	wake_up_klogd();
+	if (in_sched)
+		defer_console_output();
+	else
+		wake_up_klogd();
 	return printed_len;
 }
 EXPORT_SYMBOL(vprintk_emit);
@@ -3811,11 +3814,30 @@  static void __wake_up_klogd(int val)
 	preempt_enable();
 }
 
+/**
+ * wake_up_klogd - Wake kernel logging daemon
+ *
+ * Use this function when new records have been added to the ringbuffer
+ * and the console printing for those records is handled elsewhere. In
+ * this case only the logging daemon needs to be woken.
+ *
+ * Context: Any context.
+ */
 void wake_up_klogd(void)
 {
 	__wake_up_klogd(PRINTK_PENDING_WAKEUP);
 }
 
+/**
+ * defer_console_output - Wake kernel logging daemon and trigger
+ *	console printing in a deferred context
+ *
+ * Use this function when new records have been added to the ringbuffer
+ * but the current context is unable to perform the console printing.
+ * This function also wakes the logging daemon.
+ *
+ * Context: Any context.
+ */
 void defer_console_output(void)
 {
 	/*
@@ -3832,12 +3854,7 @@  void printk_trigger_flush(void)
 
 int vprintk_deferred(const char *fmt, va_list args)
 {
-	int r;
-
-	r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, fmt, args);
-	defer_console_output();
-
-	return r;
+	return vprintk_emit(0, LOGLEVEL_SCHED, NULL, fmt, args);
 }
 
 int _printk_deferred(const char *fmt, ...)
diff --git a/kernel/printk/printk_safe.c b/kernel/printk/printk_safe.c
index ef0f9a2044da..6d10927a07d8 100644
--- a/kernel/printk/printk_safe.c
+++ b/kernel/printk/printk_safe.c
@@ -38,13 +38,8 @@  asmlinkage int vprintk(const char *fmt, va_list args)
 	 * Use the main logbuf even in NMI. But avoid calling console
 	 * drivers that might have their own locks.
 	 */
-	if (this_cpu_read(printk_context) || in_nmi()) {
-		int len;
-
-		len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
-		defer_console_output();
-		return len;
-	}
+	if (this_cpu_read(printk_context) || in_nmi())
+		return vprintk_deferred(fmt, args);
 
 	/* No obstacles. */
 	return vprintk_default(fmt, args);