From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754774AbbLaDMe (ORCPT ); Wed, 30 Dec 2015 22:12:34 -0500 Received: from mail-pa0-f41.google.com ([209.85.220.41]:34951 "EHLO mail-pa0-f41.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752168AbbLaDMb (ORCPT ); Wed, 30 Dec 2015 22:12:31 -0500 Date: Thu, 31 Dec 2015 12:13:37 +0900 From: Sergey Senozhatsky To: Sergey Senozhatsky Cc: Jan Kara , Sergey Senozhatsky , Andrew Morton , Petr Mladek , KY Sri nivasan , Steven Rostedt , linux-kernel@vger.kernel.org Subject: Re: [PATCH 1/7] printk: Hand over printing to console if printing too long Message-ID: <20151231031337.GB479@swordfish> References: <20151210145251.GA540@swordfish> <20151222134730.GD7266@quack.suse.cz> <20151231024459.GA479@swordfish> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20151231024459.GA479@swordfish> User-Agent: Mutt/1.5.24 (2015-08-30) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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).