Message-ID: <55CBFDFE.4040208@intel.com>
Date: Thu, 13 Aug 2015 10:16:30 +0800
From: Pan Xinhui <xinhuix.pan@intel.com>
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.5.0
MIME-Version: 1.0
To: Peter Hurley <peter@hurleysoftware.com>,
        Greg Kroah-Hartman <gregkh@linuxfoundation.org>
CC: "linux-kernel@vger.kernel.org" <linux-kernel@vger.kernel.org>,
        Andrew Morton <akpm@linux-foundation.org>, pmladek@suse.cz,
        rostedt@goodmis.org, Tejun Heo <tj@kernel.org>,
        Joe Perches <joe@perches.com>, hch@lst.de, viro@zeniv.linux.org.uk,
        Vasily Averin <vvs@virtuozzo.com>
Subject: Re: [PATCH] printk: rebalance printk
References: <55C9DB15.2070800@intel.com> <20150811181608.GA29819@kroah.com> <55CB3CAC.6000003@hurleysoftware.com>
In-Reply-To: <55CB3CAC.6000003@hurleysoftware.com>
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 8bit
Sender: linux-kernel-owner@vger.kernel.org
Content-Length: 2590
Lines: 66


On 2015年08月12日 20:31, Peter Hurley wrote:
> On 08/11/2015 02:16 PM, Greg Kroah-Hartman wrote:
>> On Tue, Aug 11, 2015 at 07:23:01PM +0800, Pan Xinhui wrote:
>>> From: Pan Xinhui <xinhuix.pan@intel.com>
>>>
>>> printk can be called in any context, It's very useful to output debug
>>> info.
>>>
>>> But it might cause very bad issues on some special cases. For example,
>>> some driver hit errors, and it dumps many messages like reg values, etc. 
>>>
>>> Sometimes, printk is called when irqs disabled. This is OKay if there is
>>> a few messages. But What would happen if many messages outputted by other
>>> drivers at same time.
>>>
>>> Here is the scenario.
>>> CPUA					CPUB
>>> 					local_irq_save(flags);
>>> 					printk()
>>> while(..) {					--> console_unlock
>>> 	printk(...);			
>>> 	//hundreds or thousands loops
>>> }				//all messages flushed out to consoles
>>> 					local_irq_restore(flags);
>>>
>>
>> Where are you seeing this type of scenario "in the wild"?  Or is this
>> just a "debug/bringup hardware" issue?
> 
> There have been problem reports of big machines getting soft-lockup/RCU stall
> warnings with serial console attached. I think SLES is carrying patches
> from Jan Kara to try to workaround this issue.
> 
> 
commit 5874af2003b1aaaa053128d655710140e3187226 ("printk: enable interrupts before calling console_trylock_for_printk()")
does help much in most cases. Thanks Jan Kara for that patch!

However there are still some corner cases like that I mentioned above.
As preempt is disabled in console_unlock(), Even applying my patch, softlockup/RCU warning still goes out.

I am very looking forward to Jan Kara's new patch to walk around it. Of course I will also try to work out a pre-review patch with my new idea
to fix these softlockpup/RCU warning.

Thanks
xinhui

>> We shouldn't be ever stuck in a
>> printk that prints hundreds or thousands of loops, if so, we need to fix
>> the kernel code that does that, as we do have control over this.
> 
> The loop referred to here is the loop in console_unlock(). Essentially
> what happens is one cpu can get trapped in the console_unlock() output
> loop; printk()'s from other cpus are only appending to the logbuf since
> they can't acquire the console_lock (which is owned by the one cpu trapped
> in the output loop).
> 
> Regards,
> Peter Hurley
> 
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/