ftrace: printk and trace irqsoff and wakeups

printk called from wakeup critical timings and irqs off can
cause deadlocks since printk might do a wakeup itself. If the
call to printk happens with the runqueue lock held, it can
deadlock.

This patch protects the printk from being called in trace irqs off
with a test to see if the runqueue for the current CPU is locked.
If it is locked, the printk is skipped.

The wakeup always holds the runqueue lock, so the printk is
simply removed.

Signed-off-by: Steven Rostedt <srostedt@redhat.com>
Signed-off-by: Ingo Molnar <mingo@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>

diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 7a4dc014b8ab755a8e6824afef53d5b3fb43a621..d0c1748b1e2cdabec64a66270189e4f8e2d85908 100644 (file)
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -165,18 +165,20 @@ check_critical_timing(struct trace_array *tr,
 
        update_max_tr_single(tr, current, cpu);
 
-       if (tracing_thresh) {
-               printk(KERN_INFO "(%16s-%-5d|#%d):"
-                       " %lu us critical section violates %lu us threshold.\n",
-                               current->comm, current->pid,
-                               raw_smp_processor_id(),
-                               latency, nsecs_to_usecs(tracing_thresh));
-       } else {
-               printk(KERN_INFO "(%16s-%-5d|#%d):"
-                      " new %lu us maximum-latency critical section.\n",
-                               current->comm, current->pid,
-                               raw_smp_processor_id(),
-                               latency);
+       if (!runqueue_is_locked()) {
+               if (tracing_thresh) {
+                       printk(KERN_INFO "(%16s-%-5d|#%d): %lu us critical"
+                              " section violates %lu us threshold.\n",
+                              current->comm, current->pid,
+                              raw_smp_processor_id(),
+                              latency, nsecs_to_usecs(tracing_thresh));
+               } else {
+                       printk(KERN_INFO "(%16s-%-5d|#%d): new %lu us"
+                              " maximum-latency critical section.\n",
+                              current->comm, current->pid,
+                              raw_smp_processor_id(),
+                              latency);
+               }
        }
 
        max_sequence++;

diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index 2a012423f9d080eebc2765c62fca35e941c36d51..5948011006bca9f4f05d97dcfc4af79de89f778a 100644 (file)
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c
@@ -106,19 +106,6 @@ wakeup_sched_switch(struct task_struct *prev, struct task_struct *next)
 
        update_max_tr(tr, wakeup_task, wakeup_cpu);
 
-       if (tracing_thresh) {
-               printk(KERN_INFO "(%16s-%-5d|#%d):"
-                       " %lu us wakeup latency violates %lu us threshold.\n",
-                               wakeup_task->comm, wakeup_task->pid,
-                               raw_smp_processor_id(),
-                               latency, nsecs_to_usecs(tracing_thresh));
-       } else {
-               printk(KERN_INFO "(%16s-%-5d|#%d):"
-                       " new %lu us maximum wakeup latency.\n",
-                               wakeup_task->comm, wakeup_task->pid,
-                               cpu, latency);
-       }
-
 out_unlock:
        __wakeup_reset(tr);
        spin_unlock_irqrestore(&wakeup_lock, flags);