Re: + printk-do-cond_resched-between-lines-while-outputting-to-consoles.patch added to -mm tree

[Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>]

On (12/03/15 10:11), Sergey Senozhatsky wrote:
> On (12/02/15 15:57), akpm@linux-foundation.org wrote:
> [..]
> > @console_may_schedule tracks whether console_sem was acquired through lock
> > or trylock.  If the former, we're inside a sleepable context and
> > console_conditional_schedule() performs cond_resched().  This allows
> > console drivers which use console_lock for synchronization to yield while
> > performing time-consuming operations such as scrolling.
> > 
> > However, the actual console outputting is performed while holding irq-safe
> > logbuf_lock, so console_unlock() clears @console_may_schedule before
> > starting outputting lines.  Also, only a few drivers call
> > console_conditional_schedule() to begin with.  This means that when a lot
> > of lines need to be output by console_unlock(), for example on a console
> > registration, the task doing console_unlock() may not yield for a long
> > time on a non-preemptible kernel.
> > 
> > If this happens with a slow console devices, for example a serial console,
> > the outputting task may occupy the cpu for a very long time.  Long enough
> > to trigger softlockup and/or RCU stall warnings, which in turn pile more
> > messages, sometimes enough to trigger the next cycle of warnings
> > incapacitating the system.
> > 
> > Fix it by making console_unlock() insert cond_resched() between lines if
> > @console_may_schedule.
> 
> CPU2 still can cause lots of troubles. consider
> 
> CPU0		CPU1			CPU2
> printk		
> ...		printk_deferred		
> printk					wake_up_klogd
> 						wake_up_klogd_work_func
> 							console_trylock
> 								console_unlock
> 
> printk_deferred() may be issued by scheduler, for example.

IOW, may be we can start limiting the number of bytes printed in console_unlock()
from irq contexts. Which is quite ugly, yes. We basically don't know how much time
we spend in call_console_drivers(); some of the consoles can do 'internal' spin_lock
loops in ->write() handlers, etc. So something like this (below) probably will not
really help, but still it's not always OK to do `while (1)' loop in console_unlock()
for irqs.

	-ss

(not even compile tested)

---

 kernel/printk/printk.c | 6 +++++-
 1 file changed, 5 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 9da39e7..221a230 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2235,6 +2235,7 @@ void console_unlock(void)
 	unsigned long flags;
 	bool wake_klogd = false;
 	bool do_cond_resched, retry;
+	int printed, irq_count = irq_count();
 
 	if (console_suspended) {
 		up_console_sem();
@@ -2257,6 +2258,7 @@ void console_unlock(void)
 	/* flush buffered message fragment immediately to console */
 	console_cont_flush(text, sizeof(text));
 again:
+	printed = 0;
 	for (;;) {
 		struct printk_log *msg;
 		size_t ext_len = 0;
@@ -2326,6 +2328,8 @@ skip:
 
 		if (do_cond_resched)
 			cond_resched();
+		if (irq_count && printed > LOG_LINE_MAX)
+			break;
 	}
 	console_locked = 0;
 
@@ -2344,7 +2348,7 @@ skip:
 	 * flush, no worries.
 	 */
 	raw_spin_lock(&logbuf_lock);
-	retry = console_seq != log_next_seq;
+	retry = (console_seq != log_next_seq) && !!irq_count;
 	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
 
 	if (retry && console_trylock())