On Thu, Aug 18, 2016 at 12:39:25PM +0530, Binoy Jayan wrote:
static struct trace_array *irqsoff_trace __read_mostly; static int tracer_enabled __read_mostly; static DEFINE_PER_CPU(int, tracing_cpu);
+static DEFINE_PER_CPU(cycle_t, ts_irqs); +static DEFINE_PER_CPU(cycle_t, ts_preempt); +static DEFINE_PER_CPU(cycle_t, ts_critical_timings); static DEFINE_RAW_SPINLOCK(max_trace_lock);
What about creating cycle_t array and introduce only one tracepoint type which containts the type? I think it should be possible to get the right plot via hist's filter option:
'hist:key=latency.bucket:val=hitcount:sort=latency if cpu==0 && type==0'
Obviously, there is a performance impact. It would be good to see some numbers.
cheers, daniel
Just as rough idea (not tested):
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c index 03cdff8..012544c 100644 --- a/kernel/trace/trace_irqsoff.c +++ b/kernel/trace/trace_irqsoff.c @@ -19,7 +19,15 @@ static struct trace_array *irqsoff_trace __read_mostly; static int tracer_enabled __read_mostly;
+enum latency_type { + LAT_IRQ, + LAT_PREEMPT, + LAT_CRITTIME, + LAT_MAX +}; + static DEFINE_PER_CPU(int, tracing_cpu); +static DEFINE_PER_CPU(cycle_t[LAT_MAX], lat_data);
static DEFINE_RAW_SPINLOCK(max_trace_lock);
@@ -350,6 +358,19 @@ out: __trace_function(tr, CALLER_ADDR0, parent_ip, flags, pc); }
+static inline void lat_timestamp(enum latency_type type) +{ + int cpu = raw_smp_processor_id(); + per_cpu(lat_data[type], cpu) = ftrace_now(cpu); +} + +static inline void lat_trace(enum latency_type type) +{ + int cpu = raw_smp_processor_id(); + trace_latency_preempt(type, + ftrace_now(cpu) - per_cpu(lat_data[type], cpu)); +} + static inline void start_critical_timing(unsigned long ip, unsigned long parent_ip) { @@ -422,6 +443,9 @@ stop_critical_timing(unsigned long ip, unsigned long parent_ip) /* start and stop critical timings used to for stoppage (in idle) */ void start_critical_timings(void) { + if (trace_latency_preempt_enabled()) + lat_timestamp(LAT_CRITTIME); + if (preempt_trace() || irq_trace()) start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); } @@ -431,6 +455,9 @@ void stop_critical_timings(void) { if (preempt_trace() || irq_trace()) stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); + + if (trace_latency_preempt_enabled()) + lat_trace(LAT_CRITTIME); } EXPORT_SYMBOL_GPL(stop_critical_timings);
@@ -438,6 +465,9 @@ EXPORT_SYMBOL_GPL(stop_critical_timings); #ifdef CONFIG_PROVE_LOCKING void time_hardirqs_on(unsigned long a0, unsigned long a1) { + if (trace_latency_preempt_enable()) + lat_trace(LAT_CRITTIME); + if (!preempt_trace() && irq_trace()) stop_critical_timing(a0, a1); } @@ -446,6 +476,9 @@ void time_hardirqs_off(unsigned long a0, unsigned long a1) { if (!preempt_trace() && irq_trace()) start_critical_timing(a0, a1); + + if (trace_latency_preempt_enabled()) + lat_timestamp(LAT_IRQ); }
#else /* !CONFIG_PROVE_LOCKING */