Re: Interrupts disabled for too long in printk

[Mathieu Desnoyers <compudj@krystal.dyndns.org>]

Hi Steven,

* Steven Rostedt (rostedt@goodmis.org) wrote:
> So what's the problem?
> 
> printk is more for debugging. If you don't like the latency then disable
> printks.

I have not seen many systems where printk is totally disabled : it is useful to
have a trace of the kernel messages somewhere. 

> But turning the spin_lock_irqsave into a spin_lock means you
> need to do a trylock every time in printk.  Since printk can be called
> from interrupt handlers.  So what do you do when you fail? just return?

Yes the idea is to return, leaving the data in the buffers and not transferring
it to the console driver. As there is already another execution thread in the
relase_console_sem loop, it will take care of the data in its next pass in the
loop.

> So you just lost your printk that you needed, which could be of
> importance.
> 
No, it is not lost.

> Actually, the spin_lock is not your problem, since it is not held when
> the console drivers are being called. But...
> 
irq disabling is the problem. And if this function stays with a standard
spin_lock (not a try lock), disabling interrupts is required.

> There may be console drivers that grab spin_locks without turning off
> interrupts, which mean that you can again deadlock if an interrupt that
> calls printk happens in one of those drivers.
> 
Wait.. the release_console_sem calls the console drivers with interrupts
already disabled. I do not understand your last statement.

> If latency is your worry, then try out Ingo Molnar's -rt patch
> http://people.redhat.com/mingo/realtime-preempt/
> It isn't affected by this problem.
> 

My main concern is more than just latency : missing 3 timer interrupts in a row
has an impact on the kernel time keeping. On systems where NTP is not available,
it can be important. Linux, if I remember well, deals with cases where one timer
interrupt is missed, but not 2. So, if we get one printk message on the console
each minute on a system at 100HZ, we will suffer of a 14.40s drift every day.


Mathieu


> -- Steve
> 
OpenPGP public key:              http://krystal.dyndns.org:8080/key/compudj.gpg
Key fingerprint:     8CD5 52C3 8E3C 4140 715F  BA06 3F25 A8FE 3BAE 9A68