From 55c9b3d14f45a276188f0cf168898d2268fd0723 Mon Sep 17 00:00:00 2001 From: Pavankumar Kondeti Date: Mon, 26 Mar 2018 16:59:43 +0530 Subject: [PATCH] trace/irq: Add trace point to track IRQs disable callers Add trace point to track IRQs disable callers to isolate issues unrelated to scheduler and improve debug turn around time. Change-Id: Ib1ef45d8bed1fc0e128b5ab2051f0c30e8c50ee7 Signed-off-by: Pavankumar Kondeti Signed-off-by: Satya Durga Srinivasu Prabhala Signed-off-by: Lingutla Chandrasekhar --- include/linux/sched/sysctl.h | 1 + include/trace/events/preemptirq.h | 28 +++++++++++++++++++++ kernel/sysctl.c | 8 +++++- kernel/trace/trace_irqsoff.c | 42 +++++++++++++++++++++++++++++++ 4 files changed, 78 insertions(+), 1 deletion(-) diff --git a/include/linux/sched/sysctl.h b/include/linux/sched/sysctl.h index 58941b90ebe4..52d5609bff8e 100644 --- a/include/linux/sched/sysctl.h +++ b/include/linux/sched/sysctl.h @@ -87,6 +87,7 @@ extern unsigned int sysctl_sched_short_sleep; #if defined(CONFIG_PREEMPT_TRACER) || defined(CONFIG_IRQSOFF_TRACER) extern unsigned int sysctl_preemptoff_tracing_threshold_ns; +extern unsigned int sysctl_irqsoff_tracing_threshold_ns; #endif enum sched_tunable_scaling { diff --git a/include/trace/events/preemptirq.h b/include/trace/events/preemptirq.h index 9c4eb33c5a1d..3c5118011a2c 100644 --- a/include/trace/events/preemptirq.h +++ b/include/trace/events/preemptirq.h @@ -52,6 +52,34 @@ DEFINE_EVENT(preemptirq_template, preempt_enable, TP_ARGS(ip, parent_ip)); #endif +TRACE_EVENT(irqs_disable, + + TP_PROTO(u64 delta, unsigned long caddr0, unsigned long caddr1, + unsigned long caddr2, unsigned long caddr3), + + TP_ARGS(delta, caddr0, caddr1, caddr2, caddr3), + + TP_STRUCT__entry( + __field(u64, delta) + __field(void*, caddr0) + __field(void*, caddr1) + __field(void*, caddr2) + __field(void*, caddr3) + ), + + TP_fast_assign( + __entry->delta = delta; + __entry->caddr0 = (void *)caddr0; + __entry->caddr1 = (void *)caddr1; + __entry->caddr2 = (void *)caddr2; + __entry->caddr3 = (void *)caddr3; + ), + + TP_printk("delta=%llu(ns) Callers:(%pf<-%pf<-%pf<-%pf)", __entry->delta, + __entry->caddr0, __entry->caddr1, + __entry->caddr2, __entry->caddr3) +); + #endif /* _TRACE_PREEMPTIRQ_H */ #include diff --git a/kernel/sysctl.c b/kernel/sysctl.c index 5ada14880707..14f19af9d79a 100644 --- a/kernel/sysctl.c +++ b/kernel/sysctl.c @@ -299,7 +299,13 @@ static struct ctl_table kern_table[] = { .mode = 0644, .proc_handler = proc_dointvec, }, - + { + .procname = "irqsoff_tracing_threshold_ns", + .data = &sysctl_irqsoff_tracing_threshold_ns, + .maxlen = sizeof(unsigned int), + .mode = 0644, + .proc_handler = proc_dointvec, + }, #endif #ifdef CONFIG_SCHED_HMP { diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index 21b162c07e83..c00137ea939e 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -13,6 +13,7 @@ #include #include #include +#include #include "trace.h" @@ -39,6 +40,12 @@ static int save_flags; static void stop_irqsoff_tracer(struct trace_array *tr, int graph); static int start_irqsoff_tracer(struct trace_array *tr, int graph); +/* + * irqsoff stack tracing threshold in ns. + * default: 1ms + */ +unsigned int sysctl_irqsoff_tracing_threshold_ns = 1000000UL; + #ifdef CONFIG_PREEMPT_TRACER static inline int preempt_trace(void) @@ -454,17 +461,52 @@ void time_hardirqs_off(unsigned long a0, unsigned long a1) #else /* !CONFIG_PROVE_LOCKING */ +#ifdef CONFIG_PREEMPTIRQ_EVENTS +struct irqsoff_store { + u64 ts; + unsigned long caddr[4]; +}; + +static DEFINE_PER_CPU(struct irqsoff_store, the_irqsoff); +#endif /* CONFIG_PREEMPTIRQ_EVENTS */ + /* * We are only interested in hardirq on/off events: */ static inline void tracer_hardirqs_on(void) { +#ifdef CONFIG_PREEMPTIRQ_EVENTS + struct irqsoff_store *is = &per_cpu(the_irqsoff, + raw_smp_processor_id()); + + if (!is->ts) { + is->ts = sched_clock(); + is->caddr[0] = CALLER_ADDR0; + is->caddr[1] = CALLER_ADDR1; + is->caddr[2] = CALLER_ADDR2; + is->caddr[3] = CALLER_ADDR3; + } +#endif /* CONFIG_PREEMPTIRQ_EVENTS */ if (!preempt_trace() && irq_trace()) stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); } static inline void tracer_hardirqs_off(void) { +#ifdef CONFIG_PREEMPTIRQ_EVENTS + struct irqsoff_store *is = &per_cpu(the_irqsoff, + raw_smp_processor_id()); + u64 delta = 0; + + if (is->ts) { + delta = sched_clock() - is->ts; + is->ts = 0; + } + if (delta > sysctl_irqsoff_tracing_threshold_ns) + trace_irqs_disable(delta, is->caddr[0], is->caddr[1], + is->caddr[2], is->caddr[3]); +#endif /* CONFIG_PREEMPTIRQ_EVENTS */ + if (!preempt_trace() && irq_trace()) start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); }