From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S937028AbdLSCEC (ORCPT ); Mon, 18 Dec 2017 21:04:02 -0500 Received: from mail.kernel.org ([198.145.29.99]:40618 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S934582AbdLSCEB (ORCPT ); Mon, 18 Dec 2017 21:04:01 -0500 DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 9287921879 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=goodmis.org Authentication-Results: mail.kernel.org; spf=none smtp.mailfrom=rostedt@goodmis.org Date: Mon, 18 Dec 2017 21:03:56 -0500 From: Steven Rostedt To: Sergey Senozhatsky Cc: Petr Mladek , Tejun Heo , Sergey Senozhatsky , Jan Kara , Andrew Morton , Peter Zijlstra , Rafael Wysocki , Pavel Machek , Tetsuo Handa , linux-kernel@vger.kernel.org Subject: Re: [RFC][PATCHv6 00/12] printk: introduce printing kernel thread Message-ID: <20171218210356.71a1f60e@vmware.local.home> In-Reply-To: <20171219012455.GB17164@jagdpanzerIV> References: <20171215083151.cu3xbdgmxqkszwso@pathway.suse.cz> <20171215084236.GE468@jagdpanzerIV> <20171215090801.eulx4pg54p667ya5@pathway.suse.cz> <20171218093405.GA31274@jagdpanzerIV> <20171218133101.ri55uwivhc5xwg5y@pathway.suse.cz> <20171218133948.GD31274@jagdpanzerIV> <20171218141353.6shpvcwth34k6dsi@pathway.suse.cz> <20171218124613.1df152da@gandalf.local.home> <20171219010311.GB8892@jagdpanzerIV> <20171218200806.56a6507e@gandalf.local.home> <20171219012455.GB17164@jagdpanzerIV> X-Mailer: Claws Mail 3.15.1 (GTK+ 2.24.31; x86_64-pc-linux-gnu) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Tue, 19 Dec 2017 10:24:55 +0900 Sergey Senozhatsky wrote: > On (12/18/17 20:08), Steven Rostedt wrote: > > > ... do you guys read my emails? which part of the traces I have provided > > > suggests that there is any improvement? > > > > The traces I've seen from you were from non-realistic scenarios. > > But I have hit issues with printk()s happening that cause one CPU to do all > > the work, where my patch would fix that. Those are the scenarios I'm > > talking about. > > any hints about what makes your scenario more realistic than mine? > to begin with, what was the scenario? It was a while ago when I hit it. I think it was an OOM issue. And it wasn't contrived. It happened on a production system. > > [..] > > > But I have hit issues with printk()s happening that cause one CPU to do all > > the work, where my patch would fix that. Those are the scenarios I'm > > talking about. > > and this is exactly what I'm still observing. i_do_printks-1992 stops > printing, while console_sem is owned by another task. Since log_store() > much faster than call_console_drivers() AND console_sem owner is getting > preempted for unknown period of time, we end up having pending messages > in logbuf... and it's kworker/0:1-135 that prints them all. > > systemd-udevd-671 [003] d..3 66.334866: offloading: set console_owner > kworker/0:1-135 [000] d..2 66.335999: offloading: vprintk_emit()->trylock FAIL will spin? :1 > i_do_printks-1992 [002] d..2 66.345474: offloading: vprintk_emit()->trylock FAIL will spin? :0 x 1100 > ... > systemd-udevd-671 [003] d..3 66.345917: offloading: clear console_owner waiter != NULL :1 And kworker will still be bounded in what it can print. Yes it may end up being the entire buffer, but that should not take longer than a watchdog. If that proves to be an issue in the real world, then we could simply wake up an offloaded thread, if the current owner does more than one iteration (more than what it wrote). Then when the thread wakes up, it simply does a printk, and it will take over by the waiter logic. But that is only if it still appears to be an issue. -- Steve