Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
From:   Viktor Rosendahl <Viktor.Rosendahl@bmw.de>
To:     Ingo Molnar <mingo@redhat.com>,
        Steven Rostedt <rostedt@goodmis.org>,
        linux-kernel@vger.kernel.org
Subject: [PATCH 4/4] ftrace: Add an option for tracing console latencies
Date:   Mon, 21 Jan 2019 14:35:13 +0200
Message-Id: <1548074113-16599-5-git-send-email-Viktor.Rosendahl@bmw.de>
In-Reply-To: <1548074113-16599-1-git-send-email-Viktor.Rosendahl@bmw.de>
References: <1548074113-16599-1-git-send-email-Viktor.Rosendahl@bmw.de>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

This new option CONFIG_TRACE_CONSOLE_LATENCY will enable the latency
tracers to trace the console latencies. Previously this has always been
implicitely disabled. I guess this is because they are considered
to be well known and unavoidable.

However, for some organizations it may nevertheless be desirable to
trace them. Basically, we want to be able to tell that there are
latencies in the system under test because someone has incorrectly
enabled the serial console.

Signed-off-by: Viktor Rosendahl <Viktor.Rosendahl@bmw.de>
---
 include/linux/irqflags.h | 13 +++++++++++++
 kernel/printk/printk.c   |  5 +++--
 kernel/trace/Kconfig     | 11 +++++++++++
 3 files changed, 27 insertions(+), 2 deletions(-)

diff --git a/include/linux/irqflags.h b/include/linux/irqflags.h
index 21619c92c377..791bee718448 100644
--- a/include/linux/irqflags.h
+++ b/include/linux/irqflags.h
@@ -73,6 +73,19 @@ do {						\
 # define start_critical_timings() do { } while (0)
 #endif
 
+#ifdef CONFIG_TRACE_CONSOLE_LATENCY
+
+#define console_stop_critical_timings()  do {} while (0)
+#define console_start_critical_timings() do {} while (0)
+
+#else /* !CONFIG_TRACE_CONSOLE_LATENCY */
+
+/* don't trace print latency */
+#define console_stop_critical_timings()  stop_critical_timings()
+#define console_start_critical_timings() start_critical_timings()
+
+#endif /* !CONFIG_TRACE_CONSOLE_LATENCY */
+
 /*
  * Wrap the arch provided IRQ routines to provide appropriate checks.
  */
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index d3d170374ceb..303b8f656009 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2404,9 +2404,10 @@ void console_unlock(void)
 		 */
 		console_lock_spinning_enable();
 
-		stop_critical_timings();	/* don't trace print latency */
+		/* don't trace print latency if it's disabled */
+		console_stop_critical_timings();
 		call_console_drivers(ext_text, ext_len, text, len);
-		start_critical_timings();
+		console_start_critical_timings();
 
 		if (console_lock_spinning_disable_and_check()) {
 			printk_safe_exit_irqrestore(flags);
diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index ca80cb08bd39..5063b32de66c 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -244,6 +244,17 @@ config PREEMPT_TRACER
 	  modification of /sys/kernel/debug/tracing/trace through the inotify
 	  interface.
 
+	config TRACE_CONSOLE_LATENCY
+	bool "Do not turn off latency tracing for the console"
+	default n
+	depends on IRQSOFF_TRACER || PREEMPT_TRACER
+	help
+	  Some of the console drivers will cause long unavoidable
+	  latencies because they are slow and need to print immediately
+	  in a serialized manner. Because of this their latencies are not
+	  traced by default. This option will change behavior so that
+	  they are traced.
+
 config SCHED_TRACER
 	bool "Scheduling Latency Tracer"
 	select GENERIC_TRACER
-- 
2.17.1