[PATCH 0/2] touch_nmi_watchdog semantic changes

[PATCH 0/2] touch_nmi_watchdog semantic changes

[Don Zickus]

I was trying to change the semantics of how touch_nmi_watchdog worked
to cover a corner case where endless console writing would block the
watchdog from going off.

Ingo recommended that I add ratelimiting to the panic code to in case we
get a slew of locked up cpus, hence my first patch in the series.

Cheers,
Don

--
Crap forgot to cc lkml, sorry for the spam...


Don Zickus (2):
  panic:  ratelimit panic messages
  watchdog:  touch_nmi_watchdog should only touch local cpu not every
    one

 Documentation/kernel-parameters.txt |    6 ++++++
 kernel/panic.c                      |   30 ++++++++++++++++++++++++++++++
 kernel/watchdog.c                   |   17 +++++++++--------
 3 files changed, 45 insertions(+), 8 deletions(-)

-- 
1.7.3.4

[PATCH 1/2] panic: ratelimit panic messages

[Don Zickus]

Sometimes when things go bad, so much spew is coming on the console it is hard
to figure out what happened.  This patch allows you to ratelimit the panic
messages with the intent that the first panic message will provide the info
we need to figure out what happened.

Adds new kernel param 'panic_ratelimit=on/<integer in seconds>'

Signed-off-by: Don Zickus <dzickus@redhat.com>
---
 Documentation/kernel-parameters.txt |    6 ++++++
 kernel/panic.c                      |   30 ++++++++++++++++++++++++++++++
 2 files changed, 36 insertions(+), 0 deletions(-)

diff --git a/Documentation/kernel-parameters.txt b/Documentation/kernel-parameters.txt
index 316c723..1416964 100644
--- a/Documentation/kernel-parameters.txt
+++ b/Documentation/kernel-parameters.txt
@@ -1807,6 +1807,12 @@ and is between 256 and 4096 characters. It is defined in the file
 	panic=		[KNL] Kernel behaviour on panic
 			Format: <timeout>
 
+	panic_ratelimit=	[KNL] ratelimit the panic messages
+			Useful for slowing down multiple panics to capture
+			the first one before it scrolls off the screen
+			Format: "on" or some integer in seconds
+			"on" defaults to 10 minutes
+
 	parkbd.port=	[HW] Parallel port number the keyboard adapter is
 			connected to, default is 0.
 			Format: <parport#>
diff --git a/kernel/panic.c b/kernel/panic.c
index 4c13b1a..fe89e04 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -23,6 +23,7 @@
 #include <linux/init.h>
 #include <linux/nmi.h>
 #include <linux/dmi.h>
+#include <linux/ratelimit.h>
 
 #define PANIC_TIMER_STEP 100
 #define PANIC_BLINK_SPD 18
@@ -48,6 +49,31 @@ static long no_blink(int state)
 long (*panic_blink)(int state);
 EXPORT_SYMBOL(panic_blink);
 
+/* setting default to 0 effectively disables it */
+DEFINE_RATELIMIT_STATE(panic_ratelimit_state, 0, 1);
+
+static int __init panic_ratelimit_setup(char *str)
+{
+	int interval;
+
+	if (!strncmp(str, "on", 2))
+		/* default to 10 minutes */
+		interval = 600 * HZ;
+	else
+		interval = simple_strtoul(str, NULL, 0) * HZ;
+
+	panic_ratelimit_state.interval = interval;
+	return 1;
+}
+__setup("panic_ratelimit=", panic_ratelimit_setup);
+
+static int __panic_ratelimit(const char *func)
+{
+	return ___ratelimit(&panic_ratelimit_state, func);
+}
+
+#define panic_ratelimit() __panic_ratelimit(__func__)
+
 /**
  *	panic - halt the system
  *	@fmt: The text string to print
@@ -63,6 +89,10 @@ NORET_TYPE void panic(const char * fmt, ...)
 	long i, i_next = 0;
 	int state = 0;
 
+	if (!panic_ratelimit())
+		for(;;)
+			cpu_relax();
+
 	/*
 	 * It's possible to come here directly from a panic-assertion and
 	 * not have preempt disabled. Some functions called from here want
-- 
1.7.3.4

[PATCH 2/2] watchdog: touch_nmi_watchdog should only touch local cpu not every one

[Don Zickus]

I ran into a scenario where while one cpu was stuck and should have panic'd
because of the NMI watchdog, it didn't.  The reason was another cpu was spewing
stack dumps on to the console.  Upon investigation, I noticed that when writing
to the console and also when dumping the stack, the watchdog is touched.

This causes all the cpus to reset their NMI watchdog flags and the 'stuck' cpu
just spins forever.

This change causes the semantics of touch_nmi_watchdog to be changed slightly.
Previously, I accidentally changed the semantics and we noticed there was a
codepath in which touch_nmi_watchdog could be touched from a preemtible area.
That caused a BUG() to happen when CONFIG_DEBUG_PREEMPT was enabled.  I believe
it was the acpi code.

My attempt here re-introduces the change to have the touch_nmi_watchdog() code
only touch the local cpu instead of all of the cpus.  But instead of using
__get_cpu_var(), I use the __raw_get_cpu_var() version.

This avoids the preemption problem.  However my reasoning wasn't because I was
trying to be lazy.  Instead I rationalized it as, well if preemption is enabled
then interrupts should be enabled to and the NMI watchdog will have no reason
to trigger.  So it won't matter if the wrong cpu is touched because the percpu
interrupt counters the NMI watchdog uses should still be incrementing.

Signed-off-by: Don Zickus <dzickus@redhat.com>
---
 kernel/watchdog.c |   17 +++++++++--------
 1 files changed, 9 insertions(+), 8 deletions(-)

diff --git a/kernel/watchdog.c b/kernel/watchdog.c
index eb17e14..d96aa59 100644
--- a/kernel/watchdog.c
+++ b/kernel/watchdog.c
@@ -143,14 +143,15 @@ void touch_all_softlockup_watchdogs(void)
 #ifdef CONFIG_HARDLOCKUP_DETECTOR
 void touch_nmi_watchdog(void)
 {
-	if (watchdog_enabled) {
-		unsigned cpu;
+	/*
+	 * Using __raw here because some code paths have
+	 * preemption enabled.  If preemption is enabled
+	 * then interrupts should be enabled too, in which
+	 * case we shouldn't have to worry about the watchdog
+	 * going off.
+	 */
+	__raw_get_cpu_var(watchdog_nmi_touch) = true;
 
-		for_each_present_cpu(cpu) {
-			if (per_cpu(watchdog_nmi_touch, cpu) != true)
-				per_cpu(watchdog_nmi_touch, cpu) = true;
-		}
-	}
 	touch_softlockup_watchdog();
 }
 EXPORT_SYMBOL(touch_nmi_watchdog);
-- 
1.7.3.4

Re: [PATCH 1/2] panic: ratelimit panic messages

[Ingo Molnar]

* Don Zickus <dzickus@redhat.com> wrote:

> Sometimes when things go bad, so much spew is coming on the console it is hard
> to figure out what happened.  This patch allows you to ratelimit the panic
> messages with the intent that the first panic message will provide the info
> we need to figure out what happened.
> 
> Adds new kernel param 'panic_ratelimit=on/<integer in seconds>'
> 
> Signed-off-by: Don Zickus <dzickus@redhat.com>
> ---
>  Documentation/kernel-parameters.txt |    6 ++++++
>  kernel/panic.c                      |   30 ++++++++++++++++++++++++++++++
>  2 files changed, 36 insertions(+), 0 deletions(-)

Well, but it's not just panics that can occur repeatedly (in fact panics tend to 
trigger once), but recursive/repeated oopses.

So if we try to do some sort of 'show first crash, rate-limit afterwards' thing (i'm 
still not 100% sure about the wiseness of it) then we should cover all common 
occurances of system panics/crashes.

btw., while printk-delay exists and can serve a similar purpose, it's pretty 
cumbersome for panic ratelimit: it slows down bootups extremely, and it also slows 
down regular, harmless printks.

So having some sort of rate-limit for emitting crash screens may make sense, while 
also preserving the oops counter or at least some other notification that we 'lost' 
messages.

	Ingo

Re: [PATCH 1/2] panic: ratelimit panic messages

[Don Zickus]

On Wed, Jan 05, 2011 at 02:21:08PM +0100, Ingo Molnar wrote:
> 
> * Don Zickus <dzickus@redhat.com> wrote:
> 
> > Sometimes when things go bad, so much spew is coming on the console it is hard
> > to figure out what happened.  This patch allows you to ratelimit the panic
> > messages with the intent that the first panic message will provide the info
> > we need to figure out what happened.
> > 
> > Adds new kernel param 'panic_ratelimit=on/<integer in seconds>'
> > 
> > Signed-off-by: Don Zickus <dzickus@redhat.com>
> > ---
> >  Documentation/kernel-parameters.txt |    6 ++++++
> >  kernel/panic.c                      |   30 ++++++++++++++++++++++++++++++
> >  2 files changed, 36 insertions(+), 0 deletions(-)
> 
> Well, but it's not just panics that can occur repeatedly (in fact panics tend to 
> trigger once), but recursive/repeated oopses.
> 
> So if we try to do some sort of 'show first crash, rate-limit afterwards' thing (i'm 
> still not 100% sure about the wiseness of it) then we should cover all common 
> occurances of system panics/crashes.
> 
> btw., while printk-delay exists and can serve a similar purpose, it's pretty 
> cumbersome for panic ratelimit: it slows down bootups extremely, and it also slows 
> down regular, harmless printks.
> 
> So having some sort of rate-limit for emitting crash screens may make sense, while 
> also preserving the oops counter or at least some other notification that we 'lost' 
> messages.

Ok.  I guess I am feeling a little slow today.  So would moving this to
the kmsg_dump() function be the right place then?

Cheers,
Don

> 
> 	Ingo

Re: [PATCH 1/2] panic: ratelimit panic messages

[Andrew Morton]

On Tue,  4 Jan 2011 22:38:30 -0500
Don Zickus <dzickus@redhat.com> wrote:

> Sometimes when things go bad, so much spew is coming on the console it is hard
> to figure out what happened.  This patch allows you to ratelimit the panic
> messages with the intent that the first panic message will provide the info
> we need to figure out what happened.
> 
> Adds new kernel param 'panic_ratelimit=on/<integer in seconds>'
> 

Terminological whinge: panic() is a specific kernel API which ends up
doing a sort-of-oops thing.  So the graph is

	panic		-> oops
	other-things	-> oops

Your patch doesn't affect only panics - it also affects oops, BUG(),
etc.  So I'd suggest that this patch should do s/panic/oops/g.

> ---
>  Documentation/kernel-parameters.txt |    6 ++++++
>  kernel/panic.c                      |   30 ++++++++++++++++++++++++++++++
>  2 files changed, 36 insertions(+), 0 deletions(-)
> 
> diff --git a/Documentation/kernel-parameters.txt b/Documentation/kernel-parameters.txt
> index 316c723..1416964 100644
> --- a/Documentation/kernel-parameters.txt
> +++ b/Documentation/kernel-parameters.txt
> @@ -1807,6 +1807,12 @@ and is between 256 and 4096 characters. It is defined in the file
>  	panic=		[KNL] Kernel behaviour on panic
>  			Format: <timeout>
>  
> +	panic_ratelimit=	[KNL] ratelimit the panic messages
> +			Useful for slowing down multiple panics to capture
> +			the first one before it scrolls off the screen
> +			Format: "on" or some integer in seconds
> +			"on" defaults to 10 minutes
> +

We keep on hacking away at this and things never seem to get much
better.  It's still the case that a large number of our oops reports
are damaged because the important parts of the oops trace scrolled off
the screen.

I therefore propose

	oops_lines_delay=N,M

which will cause the kernel to pause for M milliseconds after emitting
N lines of oops output.  Bonus marks for handling linewrap!

Start the line counter at oops_begin() or thereabouts and then do the
delay after N lines have been emitted.  I guess that counter should
_not_ be invalidated in oops_end(): if the oops generates 12 lines and
then another 100 lines of random printk crap are printed, we still want
to put a pause after the 13th line of that random crap, so we can view
the oops.

The oops_lines_delay implemetnation should count lines from all CPUs
and should block all CPUs during the delay.

I think this would solve the problem which you're seeing, as well as
the much larger my-oops-scrolled-off problem?

Re: [PATCH 1/2] panic: ratelimit panic messages

[Don Zickus]

On Wed, Jan 05, 2011 at 02:51:28PM -0800, Andrew Morton wrote:
> On Tue,  4 Jan 2011 22:38:30 -0500
> Don Zickus <dzickus@redhat.com> wrote:
> 
> > Sometimes when things go bad, so much spew is coming on the console it is hard
> > to figure out what happened.  This patch allows you to ratelimit the panic
> > messages with the intent that the first panic message will provide the info
> > we need to figure out what happened.
> > 
> > Adds new kernel param 'panic_ratelimit=on/<integer in seconds>'
> > 
> 
> Terminological whinge: panic() is a specific kernel API which ends up
> doing a sort-of-oops thing.  So the graph is
> 
> 	panic		-> oops
> 	other-things	-> oops
> 
> Your patch doesn't affect only panics - it also affects oops, BUG(),
> etc.  So I'd suggest that this patch should do s/panic/oops/g.

Ok.  Sorry about that.

<snip>
> 
> We keep on hacking away at this and things never seem to get much
> better.  It's still the case that a large number of our oops reports
> are damaged because the important parts of the oops trace scrolled off
> the screen.
> 
> I therefore propose
> 
> 	oops_lines_delay=N,M
> 
> which will cause the kernel to pause for M milliseconds after emitting
> N lines of oops output.  Bonus marks for handling linewrap!
> 
> Start the line counter at oops_begin() or thereabouts and then do the
> delay after N lines have been emitted.  I guess that counter should
> _not_ be invalidated in oops_end(): if the oops generates 12 lines and
> then another 100 lines of random printk crap are printed, we still want
> to put a pause after the 13th line of that random crap, so we can view
> the oops.
> 
> The oops_lines_delay implemetnation should count lines from all CPUs
> and should block all CPUs during the delay.
> 
> I think this would solve the problem which you're seeing, as well as
> the much larger my-oops-scrolled-off problem?

Ok.  Forgive me for being thick.  I seem to be lost in the lower layer of
the oops code for some reason.  I understand your idea and am willing to
take a crack at implementing it, I just can't figure out what function to
stick it in.  I grep'd for oops_begin() and it seemed to be an x86-only
thing.  Is there a more generic place to put this stuff?

Cheers,
Don

> 

Re: [PATCH 1/2] panic: ratelimit panic messages

[Andrew Morton]

On Wed, 5 Jan 2011 21:05:12 -0500 Don Zickus <dzickus@redhat.com> wrote:

> > We keep on hacking away at this and things never seem to get much
> > better.  It's still the case that a large number of our oops reports
> > are damaged because the important parts of the oops trace scrolled off
> > the screen.
> > 
> > I therefore propose
> > 
> > 	oops_lines_delay=N,M
> > 
> > which will cause the kernel to pause for M milliseconds after emitting
> > N lines of oops output.  Bonus marks for handling linewrap!
> > 
> > Start the line counter at oops_begin() or thereabouts and then do the
> > delay after N lines have been emitted.  I guess that counter should
> > _not_ be invalidated in oops_end(): if the oops generates 12 lines and
> > then another 100 lines of random printk crap are printed, we still want
> > to put a pause after the 13th line of that random crap, so we can view
> > the oops.
> > 
> > The oops_lines_delay implemetnation should count lines from all CPUs
> > and should block all CPUs during the delay.
> > 
> > I think this would solve the problem which you're seeing, as well as
> > the much larger my-oops-scrolled-off problem?
> 
> Ok.  Forgive me for being thick.  I seem to be lost in the lower layer of
> the oops code for some reason.  I understand your idea and am willing to
> take a crack at implementing it,

ooh, goody.  I'd finally have an answer to all those useless cellphone
jpegs of scrolled-off oops traces.

> I just can't figure out what function to
> stick it in.  I grep'd for oops_begin() and it seemed to be an x86-only
> thing.  Is there a more generic place to put this stuff?

Sorry, braino.  oops_enter() and oops_exit().  All architectures
_should_ be calling oops_enter() right at the start of the oops
handling and oops_exit() right at the end.  They're suitable sites for
adding new stuff.

Re: [PATCH 1/2] panic: ratelimit panic messages

[Dave Young]

On Thu, Jan 6, 2011 at 6:51 AM, Andrew Morton <akpm@linux-foundation.org> wrote:
> On Tue,  4 Jan 2011 22:38:30 -0500
> Don Zickus <dzickus@redhat.com> wrote:
>
>> Sometimes when things go bad, so much spew is coming on the console it is hard
>> to figure out what happened.  This patch allows you to ratelimit the panic
>> messages with the intent that the first panic message will provide the info
>> we need to figure out what happened.
>>
>> Adds new kernel param 'panic_ratelimit=on/<integer in seconds>'
>>
>
> Terminological whinge: panic() is a specific kernel API which ends up
> doing a sort-of-oops thing.  So the graph is
>
>        panic           -> oops
>        other-things    -> oops
>
> Your patch doesn't affect only panics - it also affects oops, BUG(),
> etc.  So I'd suggest that this patch should do s/panic/oops/g.
>
>> ---
>>  Documentation/kernel-parameters.txt |    6 ++++++
>>  kernel/panic.c                      |   30 ++++++++++++++++++++++++++++++
>>  2 files changed, 36 insertions(+), 0 deletions(-)
>>
>> diff --git a/Documentation/kernel-parameters.txt b/Documentation/kernel-parameters.txt
>> index 316c723..1416964 100644
>> --- a/Documentation/kernel-parameters.txt
>> +++ b/Documentation/kernel-parameters.txt
>> @@ -1807,6 +1807,12 @@ and is between 256 and 4096 characters. It is defined in the file
>>       panic=          [KNL] Kernel behaviour on panic
>>                       Format: <timeout>
>>
>> +     panic_ratelimit=        [KNL] ratelimit the panic messages
>> +                     Useful for slowing down multiple panics to capture
>> +                     the first one before it scrolls off the screen
>> +                     Format: "on" or some integer in seconds
>> +                     "on" defaults to 10 minutes
>> +
>
> We keep on hacking away at this and things never seem to get much
> better.  It's still the case that a large number of our oops reports
> are damaged because the important parts of the oops trace scrolled off
> the screen.
>
> I therefore propose
>
>        oops_lines_delay=N,M
>
> which will cause the kernel to pause for M milliseconds after emitting
> N lines of oops output.  Bonus marks for handling linewrap!

I ever try to do similar things to printk_delay, something like
printk_lines_delay,
or give printk_delay one more parameter of lines.

What do you think about this approach?

>
> Start the line counter at oops_begin() or thereabouts and then do the
> delay after N lines have been emitted.  I guess that counter should
> _not_ be invalidated in oops_end(): if the oops generates 12 lines and
> then another 100 lines of random printk crap are printed, we still want
> to put a pause after the 13th line of that random crap, so we can view
> the oops.
>
> The oops_lines_delay implemetnation should count lines from all CPUs
> and should block all CPUs during the delay.
>
> I think this would solve the problem which you're seeing, as well as
> the much larger my-oops-scrolled-off problem?
>
> --
> 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/
>



-- 
Regards
dave

Re: [PATCH 1/2] panic: ratelimit panic messages

[Dave Young]

On Sat, Jan 15, 2011 at 04:29:13PM +0800, Dave Young wrote:
> On Thu, Jan 6, 2011 at 6:51 AM, Andrew Morton <akpm@linux-foundation.org> wrote:
> > On Tue,  4 Jan 2011 22:38:30 -0500
> > Don Zickus <dzickus@redhat.com> wrote:
> >
> >> Sometimes when things go bad, so much spew is coming on the console it is hard
> >> to figure out what happened.  This patch allows you to ratelimit the panic
> >> messages with the intent that the first panic message will provide the info
> >> we need to figure out what happened.
> >>
> >> Adds new kernel param 'panic_ratelimit=on/<integer in seconds>'
> >>
> >
> > Terminological whinge: panic() is a specific kernel API which ends up
> > doing a sort-of-oops thing.  So the graph is
> >
> >        panic           -> oops
> >        other-things    -> oops
> >
> > Your patch doesn't affect only panics - it also affects oops, BUG(),
> > etc.  So I'd suggest that this patch should do s/panic/oops/g.
> >
> >> ---
> >>  Documentation/kernel-parameters.txt |    6 ++++++
> >>  kernel/panic.c                      |   30 ++++++++++++++++++++++++++++++
> >>  2 files changed, 36 insertions(+), 0 deletions(-)
> >>
> >> diff --git a/Documentation/kernel-parameters.txt b/Documentation/kernel-parameters.txt
> >> index 316c723..1416964 100644
> >> --- a/Documentation/kernel-parameters.txt
> >> +++ b/Documentation/kernel-parameters.txt
> >> @@ -1807,6 +1807,12 @@ and is between 256 and 4096 characters. It is defined in the file
> >>       panic=          [KNL] Kernel behaviour on panic
> >>                       Format: <timeout>
> >>
> >> +     panic_ratelimit=        [KNL] ratelimit the panic messages
> >> +                     Useful for slowing down multiple panics to capture
> >> +                     the first one before it scrolls off the screen
> >> +                     Format: "on" or some integer in seconds
> >> +                     "on" defaults to 10 minutes
> >> +
> >
> > We keep on hacking away at this and things never seem to get much
> > better.  It's still the case that a large number of our oops reports
> > are damaged because the important parts of the oops trace scrolled off
> > the screen.
> >
> > I therefore propose
> >
> >        oops_lines_delay=N,M
> >
> > which will cause the kernel to pause for M milliseconds after emitting
> > N lines of oops output.  Bonus marks for handling linewrap!
> 
> I ever try to do similar things to printk_delay, something like
> printk_lines_delay,
> or give printk_delay one more parameter of lines.
> 
> What do you think about this approach?
> 

I refreshed my old patch about this, please see following patch:
---

printk_delay helps us to capture printk messages on some unconvenient
senarios, ie.  on halt phase.  But the messages is still not easy to read.

So this patch add another sysctl variable printk_delay_lines to make the
messages can be delayed after multi printks.  Thus we can take pictures by
camera easily and the messages will be more readable.

kmesg will delay printk_delay_msecs milliseconds after every
printk_delay_lines printks when printk_delay > 0.

Additional, merge boot_delay into printk_delay function.  remove
boot_delay boot param, add printk_delay and printk_delay_lines instead.

Now, we can set the value by:

1. sysctl interface:
/proc/sys/kernel/printk_delay
/proc/sys/kernel/printk_delay_lines

2. boot params:
printk_delay
printk_delay_lines

printk_delay_lines range from 1 - 10000, default value is 1

Signed-off-by: Dave Young <hidave.darkstar@gmail.com>
---
 Documentation/kernel-parameters.txt |   20 +++++++++-
 Documentation/sysctl/kernel.txt     |    9 ++++
 include/linux/printk.h              |    1 
 kernel/printk.c                     |   70 +++++++++++++++++++-----------------
 kernel/sysctl.c                     |    9 ++++
 lib/Kconfig.debug                   |   18 ---------
 6 files changed, 74 insertions(+), 53 deletions(-)

--- linux-2.6.orig/Documentation/kernel-parameters.txt	2011-01-15 17:40:02.137333554 +0800
+++ linux-2.6/Documentation/kernel-parameters.txt	2011-01-15 17:46:04.235371899 +0800
@@ -385,9 +385,25 @@ and is between 256 and 4096 characters. 
 			Format: <io>,<irq>,<mode>
 			See header of drivers/net/hamradio/baycom_ser_hdx.c.
 
-	boot_delay=	Milliseconds to delay each printk during boot.
+	printk_delay=	Milliseconds to delay each printk.
 			Values larger than 10 seconds (10000) are changed to
-			no delay (0).
+			no delay (0). It can be set via sysctl after boot,
+			the proc file is: /proc/sys/kernel/printk_delay
+			For boot phase printk delay, It is likely that you
+			would also need to use "lpj=M" to preset the
+			"loops per jiffie" value. See a previous boot log for
+			the "lpj" value to use for your system, and then set
+			"lpj=M" before setting "printk_delay=N".
+			NOTE:  Using this option may adversely affect
+			SMP systems. I.e., processors other than the first one
+			may not boot up. It also may cause DETECT_SOFTLOCKUP
+			to detect what it believes to be lockup conditions.
+			Format: integer
+
+	printk_delay_lines=	Delay after every printk_delay_lines printk.
+			Values larger than 10000 are changed to 1.
+			It can be set via sysctl after boot,
+			the proc file is: /proc/sys/kernel/printk_delay_lines
 			Format: integer
 
 	bootmem_debug	[KNL] Enable bootmem allocator debug messages.
--- linux-2.6.orig/Documentation/sysctl/kernel.txt	2011-01-15 17:40:02.137333554 +0800
+++ linux-2.6/Documentation/sysctl/kernel.txt	2011-01-15 17:46:04.235371899 +0800
@@ -402,6 +402,15 @@ Value from 0 - 10000 is allowed.
 
 ==============================================================
 
+printk_delay_lines:
+
+Delay printk message every printk_delay_lines printks
+in printk_delay milliseconds
+
+Value from 1 - 10000 is allowed.
+
+==============================================================
+
 randomize-va-space:
 
 This option can be used to select the type of process address
--- linux-2.6.orig/include/linux/printk.h	2011-01-15 17:40:02.134000239 +0800
+++ linux-2.6/include/linux/printk.h	2011-01-15 17:46:04.235371899 +0800
@@ -109,6 +109,7 @@ extern bool printk_timed_ratelimit(unsig
 				   unsigned int interval_msec);
 
 extern int printk_delay_msec;
+extern int printk_delay_lines;
 extern int dmesg_restrict;
 extern int kptr_restrict;
 
--- linux-2.6.orig/kernel/printk.c	2011-01-15 17:40:02.134000239 +0800
+++ linux-2.6/kernel/printk.c	2011-01-15 18:43:25.984078816 +0800
@@ -203,40 +203,42 @@ out:
 
 __setup("log_buf_len=", log_buf_len_setup);
 
-#ifdef CONFIG_BOOT_PRINTK_DELAY
-
-static int boot_delay; /* msecs delay after each printk during bootup */
-static unsigned long long loops_per_msec;	/* based on boot_delay */
-
-static int __init boot_delay_setup(char *str)
+static unsigned long long loops_per_msec;     /* based on preset_lpj */
+static int __init printk_delay_setup(char *str)
 {
 	unsigned long lpj;
 
 	lpj = preset_lpj ? preset_lpj : 1000000;	/* some guess */
 	loops_per_msec = (unsigned long long)lpj / 1000 * HZ;
+	get_option(&str, &printk_delay_msec);
+	if (printk_delay_msec < 0 || printk_delay_msec > 10 * 1000)
+		printk_delay_msec = 0;
+
+		pr_debug("printk_delay_msec: %u, preset_lpj: %ld, lpj: %lu, "
+			"HZ: %d, loops_per_msec: %llu\n",
+			printk_delay_msec, preset_lpj, lpj, HZ, loops_per_msec);
 
-	get_option(&str, &boot_delay);
-	if (boot_delay > 10 * 1000)
-		boot_delay = 0;
-
-	pr_debug("boot_delay: %u, preset_lpj: %ld, lpj: %lu, "
-		"HZ: %d, loops_per_msec: %llu\n",
-		boot_delay, preset_lpj, lpj, HZ, loops_per_msec);
 	return 1;
 }
-__setup("boot_delay=", boot_delay_setup);
+__setup("printk_delay=", printk_delay_setup);
 
-static void boot_delay_msec(void)
+static int __init printk_delay_lines_setup(char *str)
 {
-	unsigned long long k;
-	unsigned long timeout;
+	get_option(&str, &printk_delay_lines);
+	if (printk_delay_lines < 1 || printk_delay_lines > 10 * 1000)
+		printk_delay_lines = 1;
 
-	if (boot_delay == 0 || system_state != SYSTEM_BOOTING)
-		return;
+	return 1;
+}
+__setup("printk_delay_lines=", printk_delay_lines_setup);
 
-	k = (unsigned long long)loops_per_msec * boot_delay;
+static void boot_delay(void)
+{
+	unsigned long long k;
+	unsigned long timeout;
 
-	timeout = jiffies + msecs_to_jiffies(boot_delay);
+	k = (unsigned long long)loops_per_msec * printk_delay_msec;
+	timeout = jiffies + msecs_to_jiffies(printk_delay_msec);
 	while (k) {
 		k--;
 		cpu_relax();
@@ -250,11 +252,6 @@ static void boot_delay_msec(void)
 		touch_nmi_watchdog();
 	}
 }
-#else
-static inline void boot_delay_msec(void)
-{
-}
-#endif
 
 #ifdef CONFIG_SECURITY_DMESG_RESTRICT
 int dmesg_restrict = 1;
@@ -697,16 +694,25 @@ static int new_text_line = 1;
 static char printk_buf[1024];
 
 int printk_delay_msec __read_mostly;
+int printk_delay_lines __read_mostly = 1;
 
 static inline void printk_delay(void)
 {
 	if (unlikely(printk_delay_msec)) {
+		static atomic_t l = ATOMIC_INIT(0);
 		int m = printk_delay_msec;
 
-		while (m--) {
-			mdelay(1);
-			touch_nmi_watchdog();
-		}
+		atomic_cmpxchg(&l, 0, printk_delay_lines);
+		if (atomic_dec_return(&l))
+			return;
+
+		if (system_state == SYSTEM_BOOTING)
+			boot_delay();
+		else
+			while (m--) {
+				mdelay(1);
+				touch_nmi_watchdog();
+			}
 	}
 }
 
@@ -718,9 +724,6 @@ asmlinkage int vprintk(const char *fmt, 
 	int this_cpu;
 	char *p;
 
-	boot_delay_msec();
-	printk_delay();
-
 	preempt_disable();
 	/* This stops the holder of console_sem just where we want him */
 	raw_local_irq_save(flags);
@@ -839,6 +842,7 @@ out_restore_irqs:
 	raw_local_irq_restore(flags);
 
 	preempt_enable();
+	printk_delay();
 	return printed_len;
 }
 EXPORT_SYMBOL(printk);
--- linux-2.6.orig/kernel/sysctl.c	2011-01-15 17:40:02.134000239 +0800
+++ linux-2.6/kernel/sysctl.c	2011-01-15 17:46:04.238705214 +0800
@@ -716,6 +716,15 @@ static struct ctl_table kern_table[] = {
 		.extra1		= &zero,
 		.extra2		= &two,
 	},
+	{
+		.procname	= "printk_delay_lines",
+		.data		= &printk_delay_lines,
+		.maxlen		= sizeof(int),
+		.mode		= 0644,
+		.proc_handler	= proc_dointvec_minmax,
+		.extra1		= &one,
+		.extra2		= &ten_thousand,
+	},
 #endif
 	{
 		.procname	= "ngroups_max",
--- linux-2.6.orig/lib/Kconfig.debug	2011-01-15 17:40:02.137333554 +0800
+++ linux-2.6/lib/Kconfig.debug	2011-01-15 17:46:04.238705214 +0800
@@ -814,24 +814,6 @@ config FRAME_POINTER
 	  larger and slower, but it gives very useful debugging information
 	  in case of kernel bugs. (precise oopses/stacktraces/warnings)
 
-config BOOT_PRINTK_DELAY
-	bool "Delay each boot printk message by N milliseconds"
-	depends on DEBUG_KERNEL && PRINTK && GENERIC_CALIBRATE_DELAY
-	help
-	  This build option allows you to read kernel boot messages
-	  by inserting a short delay after each one.  The delay is
-	  specified in milliseconds on the kernel command line,
-	  using "boot_delay=N".
-
-	  It is likely that you would also need to use "lpj=M" to preset
-	  the "loops per jiffie" value.
-	  See a previous boot log for the "lpj" value to use for your
-	  system, and then set "lpj=M" before setting "boot_delay=N".
-	  NOTE:  Using this option may adversely affect SMP systems.
-	  I.e., processors other than the first one may not boot up.
-	  BOOT_PRINTK_DELAY also may cause DETECT_SOFTLOCKUP to detect
-	  what it believes to be lockup conditions.
-
 config RCU_TORTURE_TEST
 	tristate "torture tests for RCU"
 	depends on DEBUG_KERNEL