Re: [PATCH v3] printk: Have printk() never buffer its data

From: Michael Neuling <mikey@neuling.org>
To: Kay Sievers <kay@vrfy.org>
Cc: linuxppc-dev@ozlabs.org,
	Linus Torvalds <torvalds@linux-foundation.org>,
	Greg Kroah-Hartman <gregkh@linuxfoundation.org>,
	Andrew Morton <akpm@linux-foundation.org>,
	Steven Rostedt <rostedt@goodmis.org>,
	LKML <linux-kernel@vger.kernel.org>, Ingo Molnar <mingo@elte.hu>,
	Wu Fengguang <fengguang.wu@intel.com>,
	Joe Perches <joe@perches.com>,
	"Paul E. McKenney" <paulmck@us.ibm.com>
Subject: Re: [PATCH v3] printk: Have printk() never buffer its data
Date: Fri, 06 Jul 2012 13:47:49 +1000	[thread overview]
Message-ID: <30343.1341546469@neuling.org> (raw)
In-Reply-To: <29711.1341545979@neuling.org>

Michael Neuling <mikey@neuling.org> wrote:

> Kay Sievers <kay@vrfy.org> wrote:
> 
> > On Fri, Jul 6, 2012 at 2:41 AM, Michael Neuling <mikey@neuling.org> wrote:
> > 
> > >> > Does this happen only very early during bootup, or also later when the
> > >> > box fully initialized?
> > >
> > > I'm seeing during boot but not later (xmon (ppc kernel debugger) doesn't
> > > see it if I do 'echo x > /proc/sysrq-trigger') .  I wouldn't say
> > > it's "very early boot".  It's a secondary CPU coming up and the primary
> > > is waiting for it.  We've already configured the console when this
> > > happens.
> > 
> > Sounds like an early boot console.
> > 
> > >> > The output of 'dmesg' later looks always correct, right?
> > >
> > > No, dmesg also has the extra new lines: eg
> > >
> > > <4>NIP: c00000000004e234 LR: c00000000004e230 CTR: 0000000000000000
> > > <4>REGS: c00000007c3b7b50 TRAP: 0700   Tainted: G        W     (3.5.0-rc4-mikey)
> > > <4>MSR: 9000000000021032
> > > <4><
> > > <4>SF
> > > <4>,HV
> > > <4>,ME
> > > <4>,IR
> > > <4>,DR
> > > <4>,RI
> > > <4>>
> > > <4>  CR: 28000042  XER: 22000000
> > 
> > Can you please paste the output of /dev/kmsg of this section? So we
> > can see the timestamps and what really went into the record buffer.
> 
> Sure.
> 
> 4,89,24561;NIP: c000000000048164 LR: c000000000048160 CTR: 0000000000000000
> 4,90,24576;REGS: c00000007e59fb50 TRAP: 0700   Tainted: G        W     (3.5.0-rc4-mikey)
> 4,91,24583;MSR: 9000000000021032 
> 4,92,24586;<
> 4,93,24591;SF
> 4,94,24596;,HV
> 4,95,24601;,ME
> 4,96,24606;,IR
> 4,97,24611;,DR
> 4,98,24616;,RI
> 4,99,24619;>
> 4,100,24628;  CR: 28000042  XER: 22000000

FWIW, compiling with the parent commit gives this:

4,89,1712;NIP: c000000000048164 LR: c000000000048160 CTR: 0000000000000000
4,90,1713;REGS: c00000007e59fb50 TRAP: 0700   Tainted: G        W     (3.5.0-rc4-mikey)
4,91,1716;MSR: 9000000000021032 <SF,HV,ME,IR,DR,RI>  CR: 22000082  XER: 02000000

Mikey

> 
> > 
> > >> Could you possibly try this patch?
> > >
> > > Sorry, doesn't help.  It also reprints the entire boot log to the
> > > console once the console get inited.
> > 
> > Which is the normal behaviour to do that, right? We should not have
> > touched any of that logic.
> 
> Not until this patch you asked me to try.  Hence why I noted it.  
> 
> Mikey