v2.6.19-rc1 regression: printk missing klogd wakeup

v2.6.19-rc1 regression: printk missing klogd wakeup

[Tilman Schmidt]

[-- Attachment #1: Type: text/plain, Size: 1677 bytes --]

Unsurprisingly, v2.6.19-rc1 still contains the problem I reported
for v2.6.18-rc1 under the subject "Linux v2.6.18-rc1: printk delays"
and later (unfortunately not before it made it into v2.6.18) tracked
down through bisecting to

[a0f1ccfd8d37457a6d8a9e01acebeefcdfcc306e] lockdep: do not recurse in printk

Problem description:
> While X is running, output from printk() appears in syslog (eg.
> /var/log/messages) only after a key is pressed on the system keyboard,
> even though it is visible with dmesg immediately.
(from lkml message <450BF1CC.2070309@imap.cc> - see that message
for further details)

The problem did not exist in 2.6.17, so I think it qualifies as a
regression.

The following naive patch fixes the problem for me, without any
apparent ill effects (ie. the menace of lockup never manifested
itself):

--- a/kernel/printk.c   2006-10-07 00:51:09.000000000 +0200
+++ b/kernel/printk.c   2006-10-07 00:51:41.000000000 +0200
@@ -826,8 +826,7 @@ void release_console_sem(void)
                 * from within the scheduler code, then do not lock
                 * up due to self-recursion:
                 */
-               if (!lockdep_internal())
-                       wake_up_interruptible(&log_wait);
+               wake_up_interruptible(&log_wait);
        }
 }
 EXPORT_SYMBOL(release_console_sem);

But I guess for a proper fix the if() condition should rather be
refined a bit than thrown out completely.

-- 
Tilman Schmidt                          E-Mail: tilman@imap.cc
Bonn, Germany
Diese Nachricht besteht zu 100% aus wiederverwerteten Bits.
Ungeoeffnet mindestens haltbar bis: (siehe Rueckseite)


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 253 bytes --]

v2.6.19-rc1 build warnings

[Tilman Schmidt]

[-- Attachment #1.1: Type: text/plain, Size: 608 bytes --]

Building v2.6.19-rc1 on a rather ordinary, oldish i386 I see:

  Building modules, stage 2.
  MODPOST 910 modules
WARNING: drivers/acpi/processor.o - Section mismatch: reference to .init.data: from .text between 'acpi_processor_power_init' (at offset 0x146c) and 'acpi_processor_cst_has_changed'
WARNING: Can't handle masks in drivers/ide/pci/atiixp:FFFF05

Just thought I would let you know.

-- 
Tilman Schmidt                          E-Mail: tilman@imap.cc
Bonn, Germany
Diese Nachricht besteht zu 100% aus wiederverwerteten Bits.
Ungeoeffnet mindestens haltbar bis: (siehe Rueckseite)



[-- Attachment #1.2: signature.asc --]
[-- Type: application/pgp-signature, Size: 263 bytes --]

[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 253 bytes --]

[patch] lockdep: fix printk recursion logic

[Ingo Molnar]

* Tilman Schmidt <tilman@imap.cc> wrote:

> Problem description:
> > While X is running, output from printk() appears in syslog (eg.
> > /var/log/messages) only after a key is pressed on the system keyboard,
> > even though it is visible with dmesg immediately.
> (from lkml message <450BF1CC.2070309@imap.cc> - see that message
> for further details)
> 
> The problem did not exist in 2.6.17, so I think it qualifies as a 
> regression.
> 
> The following naive patch fixes the problem for me, without any 
> apparent ill effects (ie. the menace of lockup never manifested 
> itself):
> 
> --- a/kernel/printk.c   2006-10-07 00:51:09.000000000 +0200
> +++ b/kernel/printk.c   2006-10-07 00:51:41.000000000 +0200
> @@ -826,8 +826,7 @@ void release_console_sem(void)
>                  * from within the scheduler code, then do not lock
>                  * up due to self-recursion:
>                  */
> -               if (!lockdep_internal())
> -                       wake_up_interruptible(&log_wait);
> +               wake_up_interruptible(&log_wait);

the reason is that i initially only had the chunk above to protect 
against lockdep recursion within vprintk() - it grew the 'outer' 
lockdep_off()/on() protection only later on. But that lockdep_off() made 
the release_console_sem() within vprintk() always happen under the 
lockdep_internal() condition, causing your bug.

so the right solution is your patch: to remove the inner protection 
against recursion here - the outer one is enough.

Andrew, could we use the patch below - it also removes a now stale 
comment. Also for -stable review i think.

	Ingo

---------------->
Subject: lockdep: fix printk recursion logic
From: Ingo Molnar <mingo@elte.hu>

bug reported and fixed by Tilman Schmidt <tilman@imap.cc>: if
lockdep is enabled then log messages make it to /var/log/messages
belatedly. The reason is a missed wakeup of klogd.

initially there was only a lockdep_internal() protection against
lockdep recursion within vprintk() - it grew the 'outer'
lockdep_off()/on() protection only later on. But that lockdep_off() made
the release_console_sem() within vprintk() always happen under the
lockdep_internal() condition, causing the bug.

the right solution to remove the inner protection against
recursion here - the outer one is enough.

Signed-off-by: Ingo Molnar <mingo@elte.hu>
---
 kernel/printk.c |   11 ++---------
 1 file changed, 2 insertions(+), 9 deletions(-)

Index: linux/kernel/printk.c
===================================================================
--- linux.orig/kernel/printk.c
+++ linux/kernel/printk.c
@@ -801,15 +801,8 @@ void release_console_sem(void)
 	console_locked = 0;
 	up(&console_sem);
 	spin_unlock_irqrestore(&logbuf_lock, flags);
-	if (wake_klogd && !oops_in_progress && waitqueue_active(&log_wait)) {
-		/*
-		 * If we printk from within the lock dependency code,
-		 * from within the scheduler code, then do not lock
-		 * up due to self-recursion:
-		 */
-		if (!lockdep_internal())
-			wake_up_interruptible(&log_wait);
-	}
+	if (wake_klogd && !oops_in_progress && waitqueue_active(&log_wait))
+		wake_up_interruptible(&log_wait);
 }
 EXPORT_SYMBOL(release_console_sem);