PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Xianghua Xiao]

I would like to have printk output to my ttyS0 console all the time,
with 2.6.33-rt17, after kernel is booted up with all messages shown
normally on the serial port until I login in, from this point on, all
printk messages go to 'dmesg(log_buf)' fine, but I could never get
them shown up on serial console anymore. I tried adjust
/proc/sys/kernel/printk etc none helped.

Switch PREEMPT_RT to PREEMPT_VOLUNTARY and reboot, now everything
works, i.e. I can see printk on my console after I login.

Look at the RT patch itself, I do find some changes to printk itself,
however I'm unsure what is causing this(i.e printk not going to
console after login).

Thanks,
Xianghua

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Xianghua Xiao]

On Tue, May 18, 2010 at 8:13 AM, Xianghua Xiao <xiaoxianghua@gmail.com> wrote:
> I would like to have printk output to my ttyS0 console all the time,
> with 2.6.33-rt17, after kernel is booted up with all messages shown
> normally on the serial port until I login in, from this point on, all
> printk messages go to 'dmesg(log_buf)' fine, but I could never get
> them shown up on serial console anymore. I tried adjust
> /proc/sys/kernel/printk etc none helped.
>
> Switch PREEMPT_RT to PREEMPT_VOLUNTARY and reboot, now everything
> works, i.e. I can see printk on my console after I login.
>
> Look at the RT patch itself, I do find some changes to printk itself,
> however I'm unsure what is causing this(i.e printk not going to
> console after login).
>
> Thanks,
> Xianghua
>

Thomas,

I could not get dmesg output to console/serial and
klogd(/var/log/messages) anymore with 2.6.33-rt17 _after_ the kernel
boot is done(on non-RT kernel it works fine). I made below changes it
starts to work again, however I'm unsure how safe the change is.
Please advise.

During googling I found this: http://lkml.org/lkml/2008/1/24/390, fyi.

Thanks a lot!
Xianghua

diff --git a/kernel/printk.c b/kernel/printk.c
index 073d27f..48ef843 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -430,7 +430,6 @@ static void __call_console_drivers(unsigned start,
unsigned end)

 	for_each_console(con) {
 		if ((con->flags & CON_ENABLED) && con->write &&
-		    console_atomic_safe(con) &&
 		    (cpu_online(raw_smp_processor_id()) ||
 		     (con->flags & CON_ANYTIME))) {
 			set_printk_might_sleep(1);
@@ -1093,9 +1092,6 @@ void release_console_mutex(void)
 	 * printk from non-preemptible sections so this is for the emergency
 	 * case only.
 	 */
-#ifdef CONFIG_PREEMPT_RT
-	if (!in_atomic() && !irqs_disabled())
-#endif
 	if (wake_klogd)
 		wake_up_klogd();
 }

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Thomas Gleixner]

On Tue, 18 May 2010, Xianghua Xiao wrote:
> I could not get dmesg output to console/serial and
> klogd(/var/log/messages) anymore with 2.6.33-rt17 _after_ the kernel
> boot is done(on non-RT kernel it works fine). I made below changes it
> starts to work again, however I'm unsure how safe the change is.
> Please advise.

Well, obviously it's unsafe if you remove safety checks. And if you
care to look at the changelog of kernel/printk.c you'll find out why.

Short story: It's introducing nasty latencies.

Use "earlyprintk=serial,ttyS0,115200,keep" if you care, but do not
complain about the resulting latencies.

Thanks,

	tglx

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Xianghua Xiao]

On Tue, May 18, 2010 at 2:47 PM, Thomas Gleixner <tglx@linutronix.de> wrote:
> On Tue, 18 May 2010, Xianghua Xiao wrote:
>> I could not get dmesg output to console/serial and
>> klogd(/var/log/messages) anymore with 2.6.33-rt17 _after_ the kernel
>> boot is done(on non-RT kernel it works fine). I made below changes it
>> starts to work again, however I'm unsure how safe the change is.
>> Please advise.
>
> Well, obviously it's unsafe if you remove safety checks. And if you
> care to look at the changelog of kernel/printk.c you'll find out why.
>
> Short story: It's introducing nasty latencies.
>
> Use "earlyprintk=serial,ttyS0,115200,keep" if you care, but do not
> complain about the resulting latencies.
>
> Thanks,
>
>        tglx
>

The earlyprintk bootargs did not work...

will try http://lkml.org/lkml/2008/1/24/390 to see if helps on latencies.

While latency is key, we also need klogd to work at least(disabling
output to serial console may be fine), without that hack somehow klogd
did not get invoked and we have nothing logged from the kernel onto
storage device.

Thanks again,
Xianghua

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Nikita V. Youshchenko]

> > I could not get dmesg output to console/serial and
> > klogd(/var/log/messages) anymore with 2.6.33-rt17 _after_ the kernel
> > boot is done(on non-RT kernel it works fine). I made below changes it
> > starts to work again, however I'm unsure how safe the change is.
> > Please advise.
>
> Well, obviously it's unsafe if you remove safety checks. And if you
> care to look at the changelog of kernel/printk.c you'll find out why.

Hmm... did a quick look and could not find anything related there.
Could you please give a pointer?

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Sujit K M]

http://www.vanemery.com/Linux/Serial/serial-console.html

Could this be of help.

On Thu, May 20, 2010 at 2:03 PM, Nikita V. Youshchenko <yoush@cs.msu.su> wrote:
>> > I could not get dmesg output to console/serial and
>> > klogd(/var/log/messages) anymore with 2.6.33-rt17 _after_ the kernel
>> > boot is done(on non-RT kernel it works fine). I made below changes it
>> > starts to work again, however I'm unsure how safe the change is.
>> > Please advise.
>>
>> Well, obviously it's unsafe if you remove safety checks. And if you
>> care to look at the changelog of kernel/printk.c you'll find out why.
>
> Hmm... did a quick look and could not find anything related there.
> Could you please give a pointer?
> --
> To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>



-- 
-- Sujit K M

blog(http://kmsujit.blogspot.com/)

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Sujit K M]

Sorry does not help as it is very old and does not seem to provide
information regarding
Real Time Linux. But the section  for

setserial -g /dev/ttyS[01]

and

/etc/inittab modifications are pointer to the changes required for
Real Timliness.

The problem is that baud rate of the COM/TTY port may require some modification.
I Think you will need to have an Critical Section for the Driver to
timeout in sync with
the baud rate.

Hope what I have said makes sense.


On Thu, May 20, 2010 at 2:55 PM, Sujit K M <sjt.kar@gmail.com> wrote:
> http://www.vanemery.com/Linux/Serial/serial-console.html
>
> Could this be of help.
>
> On Thu, May 20, 2010 at 2:03 PM, Nikita V. Youshchenko <yoush@cs.msu.su> wrote:
>>> > I could not get dmesg output to console/serial and
>>> > klogd(/var/log/messages) anymore with 2.6.33-rt17 _after_ the kernel
>>> > boot is done(on non-RT kernel it works fine). I made below changes it
>>> > starts to work again, however I'm unsure how safe the change is.
>>> > Please advise.
>>>
>>> Well, obviously it's unsafe if you remove safety checks. And if you
>>> care to look at the changelog of kernel/printk.c you'll find out why.
>>
>> Hmm... did a quick look and could not find anything related there.
>> Could you please give a pointer?
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-rt-users" in
>> the body of a message to majordomo@vger.kernel.org
>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>
>
>
>
> --
> -- Sujit K M
>
> blog(http://kmsujit.blogspot.com/)
>



-- 
-- Sujit K M

blog(http://kmsujit.blogspot.com/)

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Thomas Gleixner]

Please stop top posting !

On Thu, 20 May 2010, Sujit K M wrote:

> >>> Well, obviously it's unsafe if you remove safety checks. And if you
> >>> care to look at the changelog of kernel/printk.c you'll find out why.
> >>
> >> Hmm... did a quick look and could not find anything related there.
> >> Could you please give a pointer?

Gah, yes. The changelog of the commit is not really helpful. Let me
explain:

The console drivers might take locks, which are converted to "sleeping
locks" in preempt-rt. As a result we cannot call into those drivers
from atomic contexts. And that's what the checks in the printk code
prevent.

Hope that helps.

Thanks,

	tglx

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Nikita V. Youshchenko]

> > >>> Well, obviously it's unsafe if you remove safety checks. And if
> > >>> you care to look at the changelog of kernel/printk.c you'll find
> > >>> out why.
> > >>
> > >> Hmm... did a quick look and could not find anything related there.
> > >> Could you please give a pointer?
>
> Gah, yes. The changelog of the commit is not really helpful. Let me
> explain:
>
> The console drivers might take locks, which are converted to "sleeping
> locks" in preempt-rt. As a result we cannot call into those drivers
> from atomic contexts. And that's what the checks in the printk code
> prevent.

I've already understood that when looking at that code some weeks ago.

Still questions:

1) why does that prevent klogd from working?

2) why does print not pass to non-CON_ATOMIC even if called from non-atomic 
context?

3) I believe that 8250 serial driver is aware of preempt-rt.
Could you please comment on my "2.6.33.2-rt13: RFC: fix serial console" 
post to linux-rt-users list 
(http://eeek.borgchat.net/lists/linux-rt-users/msg05569.html)

Nikita

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Thomas Gleixner]

On Thu, 20 May 2010, Nikita V. Youshchenko wrote:

> > > >>> Well, obviously it's unsafe if you remove safety checks. And if
> > > >>> you care to look at the changelog of kernel/printk.c you'll find
> > > >>> out why.
> > > >>
> > > >> Hmm... did a quick look and could not find anything related there.
> > > >> Could you please give a pointer?
> >
> > Gah, yes. The changelog of the commit is not really helpful. Let me
> > explain:
> >
> > The console drivers might take locks, which are converted to "sleeping
> > locks" in preempt-rt. As a result we cannot call into those drivers
> > from atomic contexts. And that's what the checks in the printk code
> > prevent.
> 
> I've already understood that when looking at that code some weeks ago.
> 
> Still questions:
> 
> 1) why does that prevent klogd from working?

Patch below.
 
> 2) why does print not pass to non-CON_ATOMIC even if called from non-atomic 
> context?

That's a good question. We call release_console_mutex() always with
interrupts disabled from printk(), so that atomic check triggers. Have
to look deeper to figure out whether we can enable interupts there,
probably not, but with the klogd fix this should not matter.
 
> 3) I believe that 8250 serial driver is aware of preempt-rt.
> Could you please comment on my "2.6.33.2-rt13: RFC: fix serial console" 
> post to linux-rt-users list 
> (http://eeek.borgchat.net/lists/linux-rt-users/msg05569.html)

While that can work due to the trylock, it can introduce massive
latencies just in case some driver reports a status change or what
ever.

Thanks,

	tglx
----
Subject: printk: Fix missing klogd wakeup
From: Thomas Gleixner <tglx@linutronix.de>
Date: Thu, 20 May 2010 12:33:00 +0200

The RT check for !in_atomic() && !irqs_disabled()) to prevent the
klogd wakeup is actually bogus as wake_up_klogd() is just setting the
needs print flag which is then evaluated from printk_tick() which does
the actual wakeup.

Remove the double raw_spin_unlock_irqrestore(&logbuf_lock, flags)
while at it.

Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
---
 kernel/printk.c |   10 ----------
 1 file changed, 10 deletions(-)

Index: linux-2.6-tip/kernel/printk.c
===================================================================
--- linux-2.6-tip.orig/kernel/printk.c
+++ linux-2.6-tip/kernel/printk.c
@@ -1084,18 +1084,8 @@ void release_console_mutex(void)
 #endif
 	}
 	console_locked = 0;
-	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
 	mutex_unlock(&console_mutex);
 
-	/*
-	 * On PREEMPT_RT kernels __wake_up may sleep, so wake syslogd
-	 * up only if we are in a preemptible section. We normally dont
-	 * printk from non-preemptible sections so this is for the emergency
-	 * case only.
-	 */
-#ifdef CONFIG_PREEMPT_RT
-	if (!in_atomic() && !irqs_disabled())
-#endif
 	if (wake_klogd)
 		wake_up_klogd();
 }

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Nikita V. Youshchenko]

> > Still questions:
> >
> > 1) why does that prevent klogd from working?
>
> Patch below.
> ...
> @@ -1084,18 +1084,8 @@ void release_console_mutex(void)
>  #endif
>  	}
>  	console_locked = 0;
> -	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
>  	mutex_unlock(&console_mutex);

Hmm... that lock is taken inside loop body, then control goes out of loop 
at 'break' statement, and then, if this line is deteled, lock is still 
held at function return. Looks wrong.

> > 2) why does print not pass to non-CON_ATOMIC even if called from
> > non-atomic context?
>
> That's a good question. We call release_console_mutex() always with
> interrupts disabled from printk(), so that atomic check triggers. Have
> to look deeper to figure out whether we can enable interupts there,
> probably not, but with the klogd fix this should not matter.

IMO it still matters, since printk-over-serial is almost only available 
debugging tool when [while driver debugging] system just hangs and one is 
trying to find out why and where.

> > 3) I believe that 8250 serial driver is aware of preempt-rt.
> > Could you please comment on my "2.6.33.2-rt13: RFC: fix serial
> > console" post to linux-rt-users list
> > (http://eeek.borgchat.net/lists/linux-rt-users/msg05569.html)
>
> While that can work due to the trylock, it can introduce massive
> latencies just in case some driver reports a status change or what
> ever.

Isn't it better just manually disable console (with 'quiet' kernel command 
line option) when running in production? This may be recommended in proper 
guidelines.
But while developing, serial console functionality is essential.

Nikita

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Thomas Gleixner]

On Thu, 20 May 2010, Nikita V. Youshchenko wrote:

> > > Still questions:
> > >
> > > 1) why does that prevent klogd from working?
> >
> > Patch below.
> > ...
> > @@ -1084,18 +1084,8 @@ void release_console_mutex(void)
> >  #endif
> >  	}
> >  	console_locked = 0;
> > -	raw_spin_unlock_irqrestore(&logbuf_lock, flags);
> >  	mutex_unlock(&console_mutex);
> 
> Hmm... that lock is taken inside loop body, then control goes out of loop 
> at 'break' statement, and then, if this line is deteled, lock is still 
> held at function return. Looks wrong.

Stupid me. Yes. Drop that line.
 
> > > 3) I believe that 8250 serial driver is aware of preempt-rt.
> > > Could you please comment on my "2.6.33.2-rt13: RFC: fix serial
> > > console" post to linux-rt-users list
> > > (http://eeek.borgchat.net/lists/linux-rt-users/msg05569.html)
> >
> > While that can work due to the trylock, it can introduce massive
> > latencies just in case some driver reports a status change or what
> > ever.
> 
> Isn't it better just manually disable console (with 'quiet' kernel command 
> line option) when running in production? This may be recommended in proper 
> guidelines.

No, anything which needs extra parameters for normal operation is
wrong as it affects users. 

Adding a "I'm debugging, I don't care" flag for developers is the
right thing to do.

Thanks,

	tglx

Re: PREEMPT_RT (2.6.33-rt17) disabled printk-to-console after console_init

[Nikita V. Youshchenko]

> > > > 3) I believe that 8250 serial driver is aware of preempt-rt.
> > > > Could you please comment on my "2.6.33.2-rt13: RFC: fix serial
> > > > console" post to linux-rt-users list
> > > > (http://eeek.borgchat.net/lists/linux-rt-users/msg05569.html)
> > >
> > > While that can work due to the trylock, it can introduce massive
> > > latencies just in case some driver reports a status change or what
> > > ever.
> >
> > Isn't it better just manually disable console (with 'quiet' kernel
> > command line option) when running in production? This may be
> > recommended in proper guidelines.
>
> No, anything which needs extra parameters for normal operation is
> wrong as it affects users.
>
> Adding a "I'm debugging, I don't care" flag for developers is the
> right thing to do.

Not sure.

We are not having 'good latency' vs 'bad latency' alternative here.
Alternative is 'better latency, broken console' vs 'worse latency, woring 
console'.

Since RT system has to be tuned anyway to get best possible latencies (e.g. 
prio of IRQ threads), having to tune console as well here looks like 
acceptable solution for me.

Nikita