Re: [RFC][PATCH v5 1/2] printk: Make printk() completely async

[Byungchul Park]

On Sun, Mar 20, 2016 at 11:13:10PM +0900, Sergey Senozhatsky wrote:
> @@ -1748,13 +1872,42 @@ asmlinkage int vprintk_emit(int facility, int level,
>  						 dict, dictlen, text, text_len);
>  	}
>  
> +	/*
> +	 * By default we print message to console asynchronously so that kernel
> +	 * doesn't get stalled due to slow serial console. That can lead to
> +	 * softlockups, lost interrupts, or userspace timing out under heavy
> +	 * printing load.
> +	 *
> +	 * However we resort to synchronous printing of messages during early
> +	 * boot, when synchronous printing was explicitly requested by
> +	 * kernel parameter, or when console_verbose() was called to print
> +	 * everything during panic / oops.
> +	 */
> +	if (!sync_print) {
> +		if (in_sched) {
> +			/*
> +			 * @in_sched messages may come too early, when we don't
> +			 * yet have @printk_kthread. We can't print deferred
> +			 * messages directly, because this may deadlock, route
> +			 * them via IRQ context.
> +			 */
> +			__this_cpu_or(printk_pending,
> +					PRINTK_PENDING_OUTPUT);
> +			irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
> +		} else if (printk_kthread && !in_panic) {
> +			/* Offload printing to a schedulable context. */
> +			wake_up_process(printk_kthread);

It will not print the "lockup suspected" message at all, for e.g. rq->lock,
p->pi_lock and any locks which are used within wake_up_process().
Furtheremore, any printk() within wake_up_process() cannot work at all, as
well. It's too bad to use any functions potentially including printk()
inside of this critical section.

> +		} else {
> +			sync_print = true;
> +		}
> +	}
> +
>  	logbuf_cpu = UINT_MAX;
>  	raw_spin_unlock(&logbuf_lock);
>  	lockdep_on();
>  	local_irq_restore(flags);