slow down printk during boot
[safe/jmp/linux-2.6] / kernel / printk.c
index 13ced0f..b2b5c3a 100644 (file)
 #include <linux/mm.h>
 #include <linux/tty.h>
 #include <linux/tty_driver.h>
-#include <linux/smp_lock.h>
 #include <linux/console.h>
 #include <linux/init.h>
+#include <linux/jiffies.h>
+#include <linux/nmi.h>
 #include <linux/module.h>
+#include <linux/moduleparam.h>
 #include <linux/interrupt.h>                   /* For in_interrupt() */
-#include <linux/config.h>
 #include <linux/delay.h>
 #include <linux/smp.h>
 #include <linux/security.h>
 #include <linux/bootmem.h>
 #include <linux/syscalls.h>
+#include <linux/jiffies.h>
 
 #include <asm/uaccess.h>
 
@@ -52,10 +54,8 @@ int console_printk[4] = {
        DEFAULT_CONSOLE_LOGLEVEL,       /* default_console_loglevel */
 };
 
-EXPORT_SYMBOL(console_printk);
-
 /*
- * Low lever drivers may need that to know if they can schedule in
+ * Low level drivers may need that to know if they can schedule in
  * their unblank() callback or not. So let's export it.
  */
 int oops_in_progress;
@@ -67,6 +67,7 @@ EXPORT_SYMBOL(oops_in_progress);
  * driver system.
  */
 static DECLARE_MUTEX(console_sem);
+static DECLARE_MUTEX(secondary_console_sem);
 struct console *console_drivers;
 /*
  * This is used for debugging the mess that is the VT code by
@@ -76,7 +77,7 @@ struct console *console_drivers;
  * path in the console code where we end up in places I want
  * locked without the console sempahore held
  */
-static int console_locked;
+static int console_locked, console_suspended;
 
 /*
  * logbuf_lock protects log_buf, log_start, log_end, con_start and logged_chars
@@ -122,44 +123,6 @@ static char *log_buf = __log_buf;
 static int log_buf_len = __LOG_BUF_LEN;
 static unsigned long logged_chars; /* Number of chars produced since last read+clear operation */
 
-/*
- *     Setup a list of consoles. Called from init/main.c
- */
-static int __init console_setup(char *str)
-{
-       char name[sizeof(console_cmdline[0].name)];
-       char *s, *options;
-       int idx;
-
-       /*
-        *      Decode str into name, index, options.
-        */
-       if (str[0] >= '0' && str[0] <= '9') {
-               strcpy(name, "ttyS");
-               strncpy(name + 4, str, sizeof(name) - 5);
-       } else
-               strncpy(name, str, sizeof(name) - 1);
-       name[sizeof(name) - 1] = 0;
-       if ((options = strchr(str, ',')) != NULL)
-               *(options++) = 0;
-#ifdef __sparc__
-       if (!strcmp(str, "ttya"))
-               strcpy(name, "ttyS0");
-       if (!strcmp(str, "ttyb"))
-               strcpy(name, "ttyS1");
-#endif
-       for (s = name; *s; s++)
-               if ((*s >= '0' && *s <= '9') || *s == ',')
-                       break;
-       idx = simple_strtoul(s, NULL, 10);
-       *s = 0;
-
-       add_preferred_console(name, idx, options);
-       return 1;
-}
-
-__setup("console=", console_setup);
-
 static int __init log_buf_len_setup(char *str)
 {
        unsigned long size = memparse(str, &str);
@@ -201,6 +164,61 @@ out:
 
 __setup("log_buf_len=", log_buf_len_setup);
 
+#ifdef CONFIG_BOOT_PRINTK_DELAY
+
+static unsigned int boot_delay; /* msecs delay after each printk during bootup */
+static unsigned long long printk_delay_msec; /* per msec, based on boot_delay */
+
+static int __init boot_delay_setup(char *str)
+{
+       unsigned long lpj;
+       unsigned long long loops_per_msec;
+
+       lpj = preset_lpj ? preset_lpj : 1000000;        /* some guess */
+       loops_per_msec = (unsigned long long)lpj / 1000 * HZ;
+
+       get_option(&str, &boot_delay);
+       if (boot_delay > 10 * 1000)
+               boot_delay = 0;
+
+       printk_delay_msec = loops_per_msec;
+       printk(KERN_DEBUG "boot_delay: %u, preset_lpj: %ld, lpj: %lu, "
+               "HZ: %d, printk_delay_msec: %llu\n",
+               boot_delay, preset_lpj, lpj, HZ, printk_delay_msec);
+       return 1;
+}
+__setup("boot_delay=", boot_delay_setup);
+
+static void boot_delay_msec(void)
+{
+       unsigned long long k;
+       unsigned long timeout;
+
+       if (boot_delay == 0 || system_state != SYSTEM_BOOTING)
+               return;
+
+       k = (unsigned long long)printk_delay_msec * boot_delay;
+
+       timeout = jiffies + msecs_to_jiffies(boot_delay);
+       while (k) {
+               k--;
+               cpu_relax();
+               /*
+                * use (volatile) jiffies to prevent
+                * compiler reduction; loop termination via jiffies
+                * is secondary and may or may not happen.
+                */
+               if (time_after(jiffies, timeout))
+                       break;
+               touch_nmi_watchdog();
+       }
+}
+#else
+static inline void boot_delay_msec(void)
+{
+}
+#endif
+
 /*
  * Commands to do_syslog:
  *
@@ -364,18 +382,32 @@ static void __call_console_drivers(unsigned long start, unsigned long end)
        struct console *con;
 
        for (con = console_drivers; con; con = con->next) {
-               if ((con->flags & CON_ENABLED) && con->write)
+               if ((con->flags & CON_ENABLED) && con->write &&
+                               (cpu_online(smp_processor_id()) ||
+                               (con->flags & CON_ANYTIME)))
                        con->write(con, &LOG_BUF(start), end - start);
        }
 }
 
+static int __read_mostly ignore_loglevel;
+
+static int __init ignore_loglevel_setup(char *str)
+{
+       ignore_loglevel = 1;
+       printk(KERN_INFO "debug: ignoring loglevel setting.\n");
+
+       return 1;
+}
+
+__setup("ignore_loglevel", ignore_loglevel_setup);
+
 /*
  * Write out chars from start to end - 1 inclusive
  */
 static void _call_console_drivers(unsigned long start,
                                unsigned long end, int msg_log_level)
 {
-       if (msg_log_level < console_loglevel &&
+       if ((msg_log_level < console_loglevel || ignore_loglevel) &&
                        console_drivers && start != end) {
                if ((start & LOG_BUF_MASK) > (end & LOG_BUF_MASK)) {
                        /* wrapped write */
@@ -398,8 +430,7 @@ static void call_console_drivers(unsigned long start, unsigned long end)
        unsigned long cur_index, start_print;
        static int msg_level = -1;
 
-       if (((long)(start - end)) > 0)
-               BUG();
+       BUG_ON(((long)(start - end)) > 0);
 
        cur_index = start;
        start_print = start;
@@ -475,12 +506,16 @@ static int printk_time = 1;
 #else
 static int printk_time = 0;
 #endif
+module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
 
 static int __init printk_time_setup(char *str)
 {
        if (*str)
                return 0;
        printk_time = 1;
+       printk(KERN_NOTICE "The 'time' option is deprecated and "
+               "is scheduled for removal in early 2008\n");
+       printk(KERN_NOTICE "Use 'printk.time=<value>' instead\n");
        return 1;
 }
 
@@ -491,11 +526,26 @@ __attribute__((weak)) unsigned long long printk_clock(void)
        return sched_clock();
 }
 
+/* Check if we have any console registered that can be called early in boot. */
+static int have_callable_console(void)
+{
+       struct console *con;
+
+       for (con = console_drivers; con; con = con->next)
+               if (con->flags & CON_ANYTIME)
+                       return 1;
+
+       return 0;
+}
+
 /**
  * printk - print a kernel message
  * @fmt: format string
  *
- * This is printk.  It can be called from any context.  We want it to work.
+ * This is printk().  It can be called from any context.  We want it to work.
+ * Be aware of the fact that if oops_in_progress is not set, we might try to
+ * wake klogd up which could deadlock on runqueue lock if printk() is called
+ * from scheduler code.
  *
  * We try to grab the console_sem.  If we succeed, it's easy - we log the output and
  * call the console drivers.  If we fail to get the semaphore we place the output
@@ -534,6 +584,8 @@ asmlinkage int vprintk(const char *fmt, va_list args)
        static char printk_buf[1024];
        static int log_level_unknown = 1;
 
+       boot_delay_msec();
+
        preempt_disable();
        if (unlikely(oops_in_progress) && printk_cpu == smp_processor_id())
                /* If a crash is occurring during printk() on this CPU,
@@ -541,7 +593,9 @@ asmlinkage int vprintk(const char *fmt, va_list args)
                zap_locks();
 
        /* This stops the holder of console_sem just where we want him */
-       spin_lock_irqsave(&logbuf_lock, flags);
+       raw_local_irq_save(flags);
+       lockdep_off();
+       spin_lock(&logbuf_lock);
        printk_cpu = smp_processor_id();
 
        /* Emit the output into the temporary buffer */
@@ -604,27 +658,31 @@ asmlinkage int vprintk(const char *fmt, va_list args)
                        log_level_unknown = 1;
        }
 
-       if (!cpu_online(smp_processor_id())) {
+       if (!down_trylock(&console_sem)) {
                /*
-                * Some console drivers may assume that per-cpu resources have
-                * been allocated.  So don't allow them to be called by this
-                * CPU until it is officially up.  We shouldn't be calling into
-                * random console drivers on a CPU which doesn't exist yet..
+                * We own the drivers.  We can drop the spinlock and
+                * let release_console_sem() print the text, maybe ...
                 */
-               printk_cpu = UINT_MAX;
-               spin_unlock_irqrestore(&logbuf_lock, flags);
-               goto out;
-       }
-       if (!down_trylock(&console_sem)) {
                console_locked = 1;
+               printk_cpu = UINT_MAX;
+               spin_unlock(&logbuf_lock);
+
                /*
-                * We own the drivers.  We can drop the spinlock and let
-                * release_console_sem() print the text
+                * Console drivers may assume that per-cpu resources have
+                * been allocated. So unless they're explicitly marked as
+                * being able to cope (CON_ANYTIME) don't call them until
+                * this CPU is officially up.
                 */
-               printk_cpu = UINT_MAX;
-               spin_unlock_irqrestore(&logbuf_lock, flags);
-               console_may_schedule = 0;
-               release_console_sem();
+               if (cpu_online(smp_processor_id()) || have_callable_console()) {
+                       console_may_schedule = 0;
+                       release_console_sem();
+               } else {
+                       /* Release by hand to avoid flushing the buffer. */
+                       console_locked = 0;
+                       up(&console_sem);
+               }
+               lockdep_on();
+               raw_local_irq_restore(flags);
        } else {
                /*
                 * Someone else owns the drivers.  We drop the spinlock, which
@@ -632,9 +690,11 @@ asmlinkage int vprintk(const char *fmt, va_list args)
                 * console drivers with the output which we just produced.
                 */
                printk_cpu = UINT_MAX;
-               spin_unlock_irqrestore(&logbuf_lock, flags);
+               spin_unlock(&logbuf_lock);
+               lockdep_on();
+               raw_local_irq_restore(flags);
        }
-out:
+
        preempt_enable();
        return printed_len;
 }
@@ -645,19 +705,52 @@ EXPORT_SYMBOL(vprintk);
 
 asmlinkage long sys_syslog(int type, char __user *buf, int len)
 {
-       return 0;
+       return -ENOSYS;
 }
 
-int do_syslog(int type, char __user *buf, int len)
+static void call_console_drivers(unsigned long start, unsigned long end)
 {
-       return 0;
 }
 
-static void call_console_drivers(unsigned long start, unsigned long end)
+#endif
+
+/*
+ * Set up a list of consoles.  Called from init/main.c
+ */
+static int __init console_setup(char *str)
 {
-}
+       char buf[sizeof(console_cmdline[0].name) + 4]; /* 4 for index */
+       char *s, *options;
+       int idx;
 
+       /*
+        * Decode str into name, index, options.
+        */
+       if (str[0] >= '0' && str[0] <= '9') {
+               strcpy(buf, "ttyS");
+               strncpy(buf + 4, str, sizeof(buf) - 5);
+       } else {
+               strncpy(buf, str, sizeof(buf) - 1);
+       }
+       buf[sizeof(buf) - 1] = 0;
+       if ((options = strchr(str, ',')) != NULL)
+               *(options++) = 0;
+#ifdef __sparc__
+       if (!strcmp(str, "ttya"))
+               strcpy(buf, "ttyS0");
+       if (!strcmp(str, "ttyb"))
+               strcpy(buf, "ttyS1");
 #endif
+       for (s = buf; *s; s++)
+               if ((*s >= '0' && *s <= '9') || *s == ',')
+                       break;
+       idx = simple_strtoul(s, NULL, 10);
+       *s = 0;
+
+       add_preferred_console(buf, idx, options);
+       return 1;
+}
+__setup("console=", console_setup);
 
 /**
  * add_preferred_console - add a device to the list of preferred consoles.
@@ -681,7 +774,7 @@ int __init add_preferred_console(char *name, int idx, char *options)
         *      See if this tty is not yet registered, and
         *      if we have a slot free.
         */
-       for(i = 0; i < MAX_CMDLINECONSOLES && console_cmdline[i].name[0]; i++)
+       for (i = 0; i < MAX_CMDLINECONSOLES && console_cmdline[i].name[0]; i++)
                if (strcmp(console_cmdline[i].name, name) == 0 &&
                          console_cmdline[i].index == idx) {
                                selected_console = i;
@@ -698,6 +791,45 @@ int __init add_preferred_console(char *name, int idx, char *options)
        return 0;
 }
 
+int update_console_cmdline(char *name, int idx, char *name_new, int idx_new, char *options)
+{
+       struct console_cmdline *c;
+       int i;
+
+       for (i = 0; i < MAX_CMDLINECONSOLES && console_cmdline[i].name[0]; i++)
+               if (strcmp(console_cmdline[i].name, name) == 0 &&
+                         console_cmdline[i].index == idx) {
+                               c = &console_cmdline[i];
+                               memcpy(c->name, name_new, sizeof(c->name));
+                               c->name[sizeof(c->name) - 1] = 0;
+                               c->options = options;
+                               c->index = idx_new;
+                               return i;
+               }
+       /* not found */
+       return -1;
+}
+
+#ifndef CONFIG_DISABLE_CONSOLE_SUSPEND
+/**
+ * suspend_console - suspend the console subsystem
+ *
+ * This disables printk() while we go into suspend states
+ */
+void suspend_console(void)
+{
+       printk("Suspending console(s)\n");
+       acquire_console_sem();
+       console_suspended = 1;
+}
+
+void resume_console(void)
+{
+       console_suspended = 0;
+       release_console_sem();
+}
+#endif /* CONFIG_DISABLE_CONSOLE_SUSPEND */
+
 /**
  * acquire_console_sem - lock the console system for exclusive use.
  *
@@ -708,8 +840,11 @@ int __init add_preferred_console(char *name, int idx, char *options)
  */
 void acquire_console_sem(void)
 {
-       if (in_interrupt())
-               BUG();
+       BUG_ON(in_interrupt());
+       if (console_suspended) {
+               down(&secondary_console_sem);
+               return;
+       }
        down(&console_sem);
        console_locked = 1;
        console_may_schedule = 1;
@@ -730,7 +865,12 @@ int is_console_locked(void)
 {
        return console_locked;
 }
-EXPORT_SYMBOL(is_console_locked);
+
+void wake_up_klogd(void)
+{
+       if (!oops_in_progress && waitqueue_active(&log_wait))
+               wake_up_interruptible(&log_wait);
+}
 
 /**
  * release_console_sem - unlock the console system
@@ -752,6 +892,13 @@ void release_console_sem(void)
        unsigned long _con_start, _log_end;
        unsigned long wake_klogd = 0;
 
+       if (console_suspended) {
+               up(&secondary_console_sem);
+               return;
+       }
+
+       console_may_schedule = 0;
+
        for ( ; ; ) {
                spin_lock_irqsave(&logbuf_lock, flags);
                wake_klogd |= log_start - log_end;
@@ -765,11 +912,10 @@ void release_console_sem(void)
                local_irq_restore(flags);
        }
        console_locked = 0;
-       console_may_schedule = 0;
        up(&console_sem);
        spin_unlock_irqrestore(&logbuf_lock, flags);
-       if (wake_klogd && !oops_in_progress && waitqueue_active(&log_wait))
-               wake_up_interruptible(&log_wait);
+       if (wake_klogd)
+               wake_up_klogd();
 }
 EXPORT_SYMBOL(release_console_sem);
 
@@ -868,10 +1014,21 @@ void register_console(struct console *console)
 {
        int i;
        unsigned long flags;
+       struct console *bootconsole = NULL;
 
-       if (preferred_console < 0)
+       if (console_drivers) {
+               if (console->flags & CON_BOOT)
+                       return;
+               if (console_drivers->flags & CON_BOOT)
+                       bootconsole = console_drivers;
+       }
+
+       if (preferred_console < 0 || bootconsole || !console_drivers)
                preferred_console = selected_console;
 
+       if (console->early_setup)
+               console->early_setup();
+
        /*
         *      See if we want to use this console driver. If we
         *      didn't select a console we take the first one
@@ -915,9 +1072,15 @@ void register_console(struct console *console)
        if (!(console->flags & CON_ENABLED))
                return;
 
-       if (console_drivers && (console_drivers->flags & CON_BOOT)) {
-               unregister_console(console_drivers);
+       if (bootconsole && (console->flags & CON_CONSDEV)) {
+               printk(KERN_INFO "console handover: boot [%s%d] -> real [%s%d]\n",
+                      bootconsole->name, bootconsole->index,
+                      console->name, console->index);
+               unregister_console(bootconsole);
                console->flags &= ~CON_PRINTBUFFER;
+       } else {
+               printk(KERN_INFO "console [%s%d] enabled\n",
+                      console->name, console->index);
        }
 
        /*
@@ -967,16 +1130,11 @@ int unregister_console(struct console *console)
                }
        }
 
-       /* If last console is removed, we re-enable picking the first
-        * one that gets registered. Without that, pmac early boot console
-        * would prevent fbcon from taking over.
-        *
+       /*
         * If this isn't the last console and it has CON_CONSDEV set, we
         * need to set it on the next preferred console.
         */
-       if (console_drivers == NULL)
-               preferred_console = selected_console;
-       else if (console->flags & CON_CONSDEV)
+       if (console_drivers != NULL && console->flags & CON_CONSDEV)
                console_drivers->flags |= CON_CONSDEV;
 
        release_console_sem();
@@ -984,6 +1142,19 @@ int unregister_console(struct console *console)
 }
 EXPORT_SYMBOL(unregister_console);
 
+static int __init disable_boot_consoles(void)
+{
+       if (console_drivers != NULL) {
+               if (console_drivers->flags & CON_BOOT) {
+                       printk(KERN_INFO "turn off boot console %s%d\n",
+                               console_drivers->name, console_drivers->index);
+                       return unregister_console(console_drivers);
+               }
+       }
+       return 0;
+}
+late_initcall(disable_boot_consoles);
+
 /**
  * tty_write_message - write a message to a certain tty, not just the console.
  * @tty: the destination tty_struct
@@ -1049,3 +1220,23 @@ int printk_ratelimit(void)
                                printk_ratelimit_burst);
 }
 EXPORT_SYMBOL(printk_ratelimit);
+
+/**
+ * printk_timed_ratelimit - caller-controlled printk ratelimiting
+ * @caller_jiffies: pointer to caller's state
+ * @interval_msecs: minimum interval between prints
+ *
+ * printk_timed_ratelimit() returns true if more than @interval_msecs
+ * milliseconds have elapsed since the last time printk_timed_ratelimit()
+ * returned true.
+ */
+bool printk_timed_ratelimit(unsigned long *caller_jiffies,
+                       unsigned int interval_msecs)
+{
+       if (*caller_jiffies == 0 || time_after(jiffies, *caller_jiffies)) {
+               *caller_jiffies = jiffies + msecs_to_jiffies(interval_msecs);
+               return true;
+       }
+       return false;
+}
+EXPORT_SYMBOL(printk_timed_ratelimit);