wake_up_klogd(): was: Re: [PATCH printk v2 10/12] printk: add kthread console printers

[Petr Mladek <pmladek@suse.com>]

On Tue 2022-04-05 15:31:33, John Ogness wrote:
> Create a kthread for each console to perform console printing. During
> normal operation (@system_state == SYSTEM_RUNNING), the kthread
> printers are responsible for all printing on their respective
> consoles.
> 
> During non-normal operation, console printing is done as it has been:
> within the context of the printk caller or within irq work triggered
> by the printk caller.
> 
> Console printers synchronize against each other and against console
> lockers by taking the console lock for each message that is printed.
> 
> --- a/kernel/printk/printk.c
> +++ b/kernel/printk/printk.c
> @@ -3445,40 +3659,64 @@ static void wake_up_klogd_work_func(struct irq_work *irq_work)
>  	int pending = this_cpu_xchg(printk_pending, 0);
>  
>  	if (pending & PRINTK_PENDING_OUTPUT) {
> +		printk_prefer_direct_enter();

Please, rename PRINTK_PENDING_OUTPUT to PRINTK_PENDING_DIRECT_OUTPUT.

The change confused me a lot. I wrote many lines about why it is
(not) needed. Then I continued the review and found that it started making
sense after the change in defer_console_output(). ;-)

This patch changes the meaning of the flag. It would deserve renaming.

> +
>  		/* If trylock fails, someone else is doing the printing */
>  		if (console_trylock())
>  			console_unlock();
> +
> +		printk_prefer_direct_exit();
>  	}
>  
>  	if (pending & PRINTK_PENDING_WAKEUP)
> -		wake_up_interruptible(&log_wait);
> +		wake_up_interruptible_all(&log_wait);

This would deserve some explanation in the commit message.
I think that this actually was needed even before. IMHO, more
pending waiters had to wait for more new messages. It was
not guaranteed the the woken waiter woke another one.

It would be nice to put it into separate patch and do it first.

>  }
>  
>  static DEFINE_PER_CPU(struct irq_work, wake_up_klogd_work) =
>  	IRQ_WORK_INIT_LAZY(wake_up_klogd_work_func);
>  
> -void wake_up_klogd(void)
> +static void __wake_up_klogd(int val)
>  {
>  	if (!printk_percpu_data_ready())
>  		return;
>  
>  	preempt_disable();
> -	if (waitqueue_active(&log_wait)) {
> -		this_cpu_or(printk_pending, PRINTK_PENDING_WAKEUP);
> +	/*
> +	 * Guarantee any new records can be seen by printing threads before
> +	 * checking if the wait queue is empty.
> +	 *
> +	 * The full memory barrier within wq_has_sleeper() pairs with the full
> +	 * memory barrier within set_current_state() of
> +	 * prepare_to_wait_event(), which is called after ___wait_event() adds
> +	 * the waiter but before it has checked the wait condition.
> +	 *
> +	 * See printk_kthread_func:A for the pairing memory barrier.
> +	 */

I guess that this problem was there even before but it was less
visible. Do I get it correctly, please?


> +	if (wq_has_sleeper(&log_wait) || /* LMM(__wake_up_klogd:A) */
> +	    (val & PRINTK_PENDING_OUTPUT)) {
> +		this_cpu_or(printk_pending, val);
>  		irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
>  	}
>  	preempt_enable();
>  }
>  
> +void wake_up_klogd(void)
> +{
> +	__wake_up_klogd(PRINTK_PENDING_WAKEUP);
> +}
> +
>  void defer_console_output(void)
>  {
> -	if (!printk_percpu_data_ready())
> -		return;

	/* Always wakeup waiters because there are not only printk kthreads. */
> +	int val = PRINTK_PENDING_WAKEUP;

IMHO, this was actually needed even before. Otherwise, nobody woken
log waiters for deferred messages.

IMHO, it is a regression caused by moving wake_up_klogd() from
console_unlock() to vprintk_emit(). It was the commit
43a17111c2553925f6 ("printk: wake up klogd in vprintk_emit").

If I am right then we should fix it separately.


> -	preempt_disable();
> -	this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT);
> -	irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
> -	preempt_enable();
> +	/*
> +	 * If console deferring was called with preferred direct printing,
> +	 * make the irqwork perform the direct printing.
> +	 */
> +	if (atomic_read(&printk_prefer_direct))
> +		val |= PRINTK_PENDING_OUTPUT;
> +
> +	__wake_up_klogd(val);
>  }

And we should call defer_console_output() also in
printk_prefer_direct_enter() to make sure that a potential
pending messages are printed.

My understanding is that the kthreads stop processing the messages
when the direct output is preferred. I think that this was not
the case in v1 and I asked you do it this way so that kthreads
do not block entering the direct mode.

Best Regards,
Petr