Re: [PATCH 1/7] printk: Hand over printing to console if printing too long

From: Sergey Senozhatsky
Date: Wed Dec 30 2015 - 22:13:20 EST


On (12/31/15 11:44), Sergey Senozhatsky wrote:
> On (12/22/15 14:47), Jan Kara wrote:
> [..]
> > +int printk_deferred(const char *fmt, ...)
> > +{
> > + va_list args;
> > + int r;
> > +
> > + va_start(args, fmt);
> > + r = vprintk_emit(0, LOGLEVEL_SCHED, NULL, 0, fmt, args);
> > + va_end(args);
> > +
> > + return r;
> > +}
> [..]
> > @@ -1803,10 +1869,24 @@ asmlinkage int vprintk_emit(int facility, int level,
> > logbuf_cpu = UINT_MAX;
> > raw_spin_unlock(&logbuf_lock);
> > lockdep_on();
> > + /*
> > + * 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 oops is in progress, or when synchronous printing was
> > + * explicitely requested by kernel parameter.
> > + */
> > + if (keventd_up() && !oops_in_progress && !sync_print) {
> > + __this_cpu_or(printk_pending, PRINTK_PENDING_OUTPUT);
> > + irq_work_queue(this_cpu_ptr(&wake_up_klogd_work));
> > + } else
> > + sync_print = true;
> > local_irq_restore(flags);
>
> So this fixes printk() and printk_deferred(), but it doesn't address any of the
> direct and indirect console_lock/console_unlock callers.
>
> for example, direct:
> ~/_mmots$ git grep console_unlock | egrep -v "printk\.c|panic\.c|console\.h" | wc -l
> 199
>
> indirect (e.g. via console_devices()):
> ~/_mmots$ git grep console_device | egrep -v "printk\.c|panic\.c|console\.h|_console_device" | wc -l
> 4
>
> One of those indirect callers is tty_lookup_driver(), called from tty_open(). Which
> is quite big to ignore, I suspect.
>
>
> A user space process opening a tty can end up doing that while (1) call_console_drivers()
> loop, I suspect. At least nothing prevents it, at a glance.

d'oh... sorry. that cold that I have is affecting me... no more emails for today.


cond_resched() does its job there, of course. well, a user process still can
do a lot of call_console_drivers() calls. may be we can check who is calling
console_unlock() and if we have "!printk_sync && !oops_in_progress" (or just printk_sync
test) AND a user process then return from console_unlock() doing irq_work_queue()
and set PRINTK_PENDING_OUTPUT pending bit, the way vprintk_emit() does it.

-ss

> A side note, isn't it too often to cond_resched() from console_unlock()? What if
> we have 10000000 very short printk() messages (e.g. no more than 32 chars).
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/