init: scream bloody murder if interrupts are enabled too early
Steven Rostedt [Mon, 29 Apr 2013 23:18:18 +0000 (16:18 -0700)]
As I was testing a lot of my code recently, and having several
"successes", I accidentally noticed in the dmesg this little line:

  start_kernel(): bug: interrupts were enabled *very* early, fixing it

Sure enough, one of my patches two commits ago enabled interrupts early.
The sad part here is that I never noticed it, and I ran several tests with
ktest too, and ktest did not notice this line.

What ktest looks for (and so does many other automated testing scripts) is
a back trace produced by a WARN_ON() or BUG().  As a back trace was never
produced, my buggy patch could have slipped into linux-next, or even
worse, mainline.

Adding a WARN(!irqs_disabled()) makes this bug a little more obvious:

  PID hash table entries: 4096 (order: 3, 32768 bytes)
  __ex_table already sorted, skipping sort
  Checking aperture...
  No AGP bridge found
  Calgary: detecting Calgary via BIOS EBDA area
  Calgary: Unable to locate Rio Grande table in EBDA - bailing!
  Memory: 2003252k/2054848k available (4857k kernel code, 460k absent, 51136k reserved, 6210k data, 1096k init)
  ------------[ cut here ]------------
  WARNING: at /home/rostedt/work/git/linux-trace.git/init/main.c:543 start_kernel+0x21e/0x415()
  Hardware name: To Be Filled By O.E.M.
  Interrupts were enabled *very* early, fixing it
  Modules linked in:
  Pid: 0, comm: swapper/0 Not tainted 3.8.0-test+ #286
  Call Trace:
    warn_slowpath_common+0x83/0x9b
    warn_slowpath_fmt+0x46/0x48
    start_kernel+0x21e/0x415
    x86_64_start_reservations+0x10e/0x112
    x86_64_start_kernel+0x102/0x111
  ---[ end trace 007d8b0491b4f5d8 ]---
  Preemptible hierarchical RCU implementation.
   RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=4.
  NR_IRQS:4352 nr_irqs:712 16
  Console: colour VGA+ 80x25
  console [ttyS0] enabled, bootconsole disabled

Do you see it?

The original version of this patch just slapped a WARN_ON() in there and
kept the printk().  Ard van Breemen suggested using the WARN() interface,
which makes the code a bit cleaner.

Also, while examining other warnings in init/main.c, I found two other
locations that deserve a bloody murder scream if their conditions are hit,
and updated them accordingly.

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Cc: Ard van Breemen <ard@telegraafnet.nl>
Signed-off-by: Andrew Morton <akpm@linux-foundation.org>
Signed-off-by: Linus Torvalds <torvalds@linux-foundation.org>

init/main.c

index 63534a1..26cd398 100644 (file)
@@ -539,11 +539,8 @@ asmlinkage void __init start_kernel(void)
         * fragile until we cpu_idle() for the first time.
         */
        preempt_disable();
-       if (!irqs_disabled()) {
-               printk(KERN_WARNING "start_kernel(): bug: interrupts were "
-                               "enabled *very* early, fixing it\n");
+       if (WARN(!irqs_disabled(), "Interrupts were enabled *very* early, fixing it\n"))
                local_irq_disable();
-       }
        idr_init_cache();
        perf_event_init();
        rcu_init();
@@ -558,9 +555,7 @@ asmlinkage void __init start_kernel(void)
        time_init();
        profile_init();
        call_function_init();
-       if (!irqs_disabled())
-               printk(KERN_CRIT "start_kernel(): bug: interrupts were "
-                                "enabled early\n");
+       WARN(!irqs_disabled(), "Interrupts were enabled early\n");
        early_boot_irqs_disabled = false;
        local_irq_enable();
 
@@ -702,9 +697,7 @@ int __init_or_module do_one_initcall(initcall_t fn)
                strlcat(msgbuf, "disabled interrupts ", sizeof(msgbuf));
                local_irq_enable();
        }
-       if (msgbuf[0]) {
-               printk("initcall %pF returned with %s\n", fn, msgbuf);
-       }
+       WARN(msgbuf[0], "initcall %pF returned with %s\n", fn, msgbuf);
 
        return ret;
 }