2019-09-03 13:27:44

by Viktor Rosendahl

[permalink] [raw]
Subject: [PATCH v5 4/4] ftrace: Add an option for tracing console latencies

This new trace option "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 <[email protected]>
---
include/linux/irqflags.h | 21 +++++++++++++++++++++
kernel/printk/printk.c | 6 ++++--
kernel/trace/trace.h | 1 +
kernel/trace/trace_irqsoff.c | 12 ++++++++++++
4 files changed, 38 insertions(+), 2 deletions(-)

diff --git a/include/linux/irqflags.h b/include/linux/irqflags.h
index 21619c92c377..34b0424a32dc 100644
--- a/include/linux/irqflags.h
+++ b/include/linux/irqflags.h
@@ -68,9 +68,30 @@ do { \
defined(CONFIG_PREEMPT_TRACER)
extern void stop_critical_timings(void);
extern void start_critical_timings(void);
+ extern bool console_tracing_disabled(void);
+
+# define console_stop_critical_timings(flag) \
+ do { \
+ typecheck(bool, flag); \
+ flag = console_tracing_disabled(); \
+ if (flag) \
+ stop_critical_timings(); \
+ } while (0)
+
+# define console_start_critical_timings(flag) \
+ do { \
+ typecheck(bool, flag); \
+ if (flag) \
+ start_critical_timings(); \
+ } while (0)
+
#else
# define stop_critical_timings() do { } while (0)
# define start_critical_timings() do { } while (0)
+# define console_stop_critical_timings(flag) \
+ do { typecheck(bool, flag); } while (0)
+# define console_start_critical_timings(flag) \
+ do { typecheck(bool, flag); } while (0)
#endif

/*
diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index 1888f6a3b694..036460a7e4cd 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2359,6 +2359,7 @@ void console_unlock(void)
static char ext_text[CONSOLE_EXT_LOG_MAX];
static char text[LOG_LINE_MAX + PREFIX_MAX];
unsigned long flags;
+ bool cflag;
bool do_cond_resched, retry;

if (console_suspended) {
@@ -2459,9 +2460,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(cflag);
call_console_drivers(ext_text, ext_len, text, len);
- start_critical_timings();
+ console_start_critical_timings(cflag);

if (console_lock_spinning_disable_and_check()) {
printk_safe_exit_irqrestore(flags);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index d9f83b2aaa71..8e4c9736a801 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -1266,6 +1266,7 @@ extern int trace_get_user(struct trace_parser *parser, const char __user *ubuf,
C(PRINTK_MSGONLY, "printk-msg-only"), \
C(CONTEXT_INFO, "context-info"), /* Print pid/cpu/time */ \
C(LATENCY_FMT, "latency-format"), \
+ C(CONSOLE_LATENCY, "console-latency"), \
C(RECORD_CMD, "record-cmd"), \
C(RECORD_TGID, "record-tgid"), \
C(OVERWRITE, "overwrite"), \
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 29403a83a5f0..c8d17c4c1c91 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -456,6 +456,18 @@ void stop_critical_timings(void)
EXPORT_SYMBOL_GPL(stop_critical_timings);
NOKPROBE_SYMBOL(stop_critical_timings);

+bool console_tracing_disabled(void)
+{
+ struct trace_array *tr = irqsoff_trace;
+ int pc = preempt_count();
+
+ if (!preempt_trace(pc) && !irq_trace())
+ return false;
+
+ return !(tr->trace_flags & TRACE_ITER_CONSOLE_LATENCY);
+}
+EXPORT_SYMBOL_GPL(console_tracing_disabled);
+
#ifdef CONFIG_FUNCTION_TRACER
static bool function_enabled;

--
2.17.1


2019-09-04 05:05:02

by kernel test robot

[permalink] [raw]
Subject: Re: [PATCH v5 4/4] ftrace: Add an option for tracing console latencies

Hi Viktor,

Thank you for the patch! Yet something to improve:

[auto build test ERROR on linus/master]
[cannot apply to v5.3-rc7 next-20190903]
[if your patch is applied to the wrong git tree, please drop us a note to help improve the system]

url: https://github.com/0day-ci/linux/commits/Viktor-Rosendahl/Some-new-features-for-the-preempt-irqsoff-tracers/20190904-083632
config: sh-allmodconfig (attached as .config)
compiler: sh4-linux-gcc (GCC) 7.4.0
reproduce:
wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
chmod +x ~/bin/make.cross
# save the attached .config to linux build tree
GCC_VERSION=7.4.0 make.cross ARCH=sh

If you fix the issue, kindly add following tag
Reported-by: kbuild test robot <[email protected]>

All errors (new ones prefixed by >>):

In file included from kernel/events/hw_breakpoint.c:20:0:
>> include/linux/irqflags.h:71:9: error: unknown type name 'bool'
extern bool console_tracing_disabled(void);
^~~~

vim +/bool +71 include/linux/irqflags.h

66
67 #if defined(CONFIG_IRQSOFF_TRACER) || \
68 defined(CONFIG_PREEMPT_TRACER)
69 extern void stop_critical_timings(void);
70 extern void start_critical_timings(void);
> 71 extern bool console_tracing_disabled(void);
72

---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all Intel Corporation


Attachments:
(No filename) (1.50 kB)
.config.gz (50.57 kB)
Download all attachments