printk

Flush to console

Flush to console

console_unlock
---
    for (;;) {

        raw_spin_lock_irqsave(&logbuf_lock, flags);

        //get the log from printk log buffer

        raw_spin_unlock(&logbuf_lock);

        //irq is disabled

        stop_critical_timings();    /* don't trace print latency */
        call_console_drivers(level, text, len);
        start_critical_timings();
        local_irq_restore(flags);

        if (do_cond_resched)
            cond_resched();
    }
---
static void call_console_drivers(int level, const char *text, size_t len)
{
    struct console *con;

    trace_console(text, len);

    if (level >= console_loglevel && !ignore_loglevel)
        return;

    console_loglevel is the first one of the /proc/sys/kernel/printk


    if (!console_drivers)
        return;

    for_each_console(con) {
        if (exclusive_console && con != exclusive_console)
            continue;
        if (!(con->flags & CON_ENABLED))
            continue;
        if (!con->write)
            continue;
        if (!cpu_online(smp_processor_id()) &&
            !(con->flags & CON_ANYTIME))
            continue;
        con->write(con, text, len);

    output to console device, maybe a serial port or other.


    }
}
As we know, printk could be used anywhere, even irq context or critical section.
This means console->write callback cannot invoke any function that will lead to schedule.
How to achieve this ? Let look at one example:
sclp_console -> sclp_console_write() ->sclp_sync_wait()
>>>>
    /* Loop until driver state indicates finished request */
    while (sclp_running_state != sclp_running_state_idle) {
        /* Check for expired request timer */
        if (timer_pending(&sclp_request_timer) &&
            get_clock() > timeout &&
            del_timer(&sclp_request_timer))
            sclp_request_timer.function(sclp_request_timer.data);
        cpu_relax(); 
    }
>>>>>
The irq has been disabled in console_unlock, so it is a polling under irq disabled.
If the console is very slow and dmesgs are flooded, softlockup, rcu stall even harlockup maybe triggered.
Here is an example:
workqueue: avoid hard lockups in show_workqueue_state()

show_workqueue_state() can print out a lot of messages while being in
atomic context, e.g. sysrq-t -> show_workqueue_state(). If the console
device is slow it may end up triggering NMI hard lockup watchdog.

Signed-off-by: Sergey Senozhatsky 
---
 kernel/workqueue.c | 13 +++++++++++++
 1 file changed, 13 insertions(+)

diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index 9960f8842b31..8dd2e66e8383 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -48,6 +48,7 @@
 #include 
 #include 
 #include 
+#include 
 
 #include "workqueue_internal.h"
 
@@ -4473,6 +4474,12 @@ void show_workqueue_state(void)
             if (pwq->nr_active || !list_empty(&pwq->delayed_works))
                 show_pwq(pwq);
             spin_unlock_irqrestore(&pwq->pool->lock, flags);
+            /*
+             * We could be printing a lot from atomic context, e.g.
+             * sysrq-t -> show_workqueue_state(). Avoid triggering
+             * hard lockup.
+             */
+            touch_nmi_watchdog();
         }
     }
 
@@ -4500,6 +4507,12 @@ void show_workqueue_state(void)
         pr_cont("\n");
     next_pool:
         spin_unlock_irqrestore(&pool->lock, flags);
+        /*
+         * We could be printing a lot from atomic context, e.g.
+         * sysrq-t -> show_workqueue_state(). Avoid triggering
+         * hard lockup.
+         */
+        touch_nmi_watchdog();
     }
 
     rcu_read_unlock_sched();