From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S932626AbcH2JoF (ORCPT ); Mon, 29 Aug 2016 05:44:05 -0400 Received: from cit-hm8-mail01.bmw-carit.de ([212.118.206.84]:55405 "EHLO cit-hm8-gw01.bmw-carit.de" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1751097AbcH2JoE (ORCPT ); Mon, 29 Aug 2016 05:44:04 -0400 X-CTCH-RefID: str=0001.0A0C0208.57C403D8.0101,ss=1,re=0.000,recu=0.000,reip=0.000,cl=1,cld=1,fgs=0 Subject: Re: [PATCH v3 2/3] tracing: Add trace_irqsoff tracepoints To: Binoy Jayan , "Steven Rostedt (Red Hat)" References: <1472453728-577-1-git-send-email-binoy.jayan@linaro.org> <1472453728-577-3-git-send-email-binoy.jayan@linaro.org> CC: Ingo Molnar , Arnd Bergmann , , Carsten Emde , , Masami From: Daniel Wagner Message-ID: Date: Mon, 29 Aug 2016 11:43:50 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:45.0) Gecko/20100101 Thunderbird/45.2.0 MIME-Version: 1.0 In-Reply-To: <1472453728-577-3-git-send-email-binoy.jayan@linaro.org> Content-Type: text/plain; charset="windows-1252"; format=flowed Content-Transfer-Encoding: 7bit X-Originating-IP: [10.10.50.53] X-ClientProxiedBy: CIT-HM8-EX01.bmw-carit.intra (10.40.100.13) To CIT-HM8-EX01.bmw-carit.intra (10.40.100.13) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Hi Binoy, Some minor nitpicking. On 08/29/2016 08:55 AM, Binoy Jayan wrote: > +DECLARE_EVENT_CLASS(latency_template, > + TP_PROTO(int ltype, int cpu, cycles_t latency), > + > + TP_ARGS(ltype, cpu, latency), > + > + TP_STRUCT__entry( > + __field(int, ltype) > + __field(int, cpu) > + __field(cycles_t, latency) > + ), > + > + TP_fast_assign( > + __entry->ltype = ltype; > + __entry->cpu = cpu; > + __entry->latency = latency; > + ), > + > + TP_printk("ltype=%d, cpu=%d, latency=%lu", > + __entry->ltype, __entry->cpu, (unsigned long) __entry->latency) > +); As Steven already pointed out, the cpu field is available in all traces. It's one of the predefined fields (see kernel/trace/trace_events.c/trace_define_generic_fields()). Just drop it. > + > +DEFINE_EVENT(latency_template, latency_preempt, > + TP_PROTO(int ltype, int cpu, cycles_t latency), > + TP_ARGS(ltype, cpu, latency)); > + > +#endif /* _TRACE_HIST_H */ > + > +/* This part must be outside protection */ > +#include > diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c > index 03cdff8..d4f2b25 100644 > --- a/kernel/trace/trace_irqsoff.c > +++ b/kernel/trace/trace_irqsoff.c > @@ -13,14 +13,27 @@ > #include > #include > #include > +#include > + > +#include > > #include "trace.h" > > +#define CREATE_TRACE_POINTS > +#include > + > static struct trace_array *irqsoff_trace __read_mostly; > static int tracer_enabled __read_mostly; > > -static DEFINE_PER_CPU(int, tracing_cpu); > +enum latency_type { > + TS_IRQ, > + TS_PREEMPT, > + TS_CRITTIME, > + TS_MAX > +}; Come to think of it, the TS_ prefix doesn't really make sense, maybe LT_ would be more consistent (short hand for latency type). > +static DEFINE_PER_CPU(int, tracing_cpu); > +static DEFINE_PER_CPU(cycle_t, lat_ts[TS_MAX]); > static DEFINE_RAW_SPINLOCK(max_trace_lock); > > enum { > @@ -419,9 +432,19 @@ stop_critical_timing(unsigned long ip, unsigned long parent_ip) > atomic_dec(&data->disabled); > } > > +static inline void latency_trace(enum latency_type type) > +{ > + trace_latency_preempt(type, raw_smp_processor_id(), > + (cycle_t) trace_clock_local() - this_cpu_read(lat_ts[type])); > + > +} empty line here > /* start and stop critical timings used to for stoppage (in idle) */ > void start_critical_timings(void) > { > + if (trace_latency_preempt_enabled()) > + this_cpu_write(lat_ts[TS_CRITTIME], > + (cycle_t) trace_clock_local()); > + Introduce a inline function like the latency_trace() function. No need to open code this logic 3 times. > if (preempt_trace() || irq_trace()) > start_critical_timing(CALLER_ADDR0, CALLER_ADDR1); > } > @@ -431,6 +454,10 @@ void stop_critical_timings(void) > { > if (preempt_trace() || irq_trace()) > stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1); > + > + if (trace_latency_preempt_enabled()) > + latency_trace(TS_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_enabled()) { > + latency_trace(TS_IRQ); > + } Please follow the style of the rest of the file. Just drop the brackets. > if (!preempt_trace() && irq_trace()) > stop_critical_timing(a0, a1); > } > @@ -446,6 +476,11 @@ 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()) { > + this_cpu_write(lat_ts[TS_IRQ], > + (cycle_t) trace_clock_local()); > + } Same thing. > } > > #else /* !CONFIG_PROVE_LOCKING */ > @@ -503,6 +538,9 @@ EXPORT_SYMBOL(trace_hardirqs_off_caller); > #ifdef CONFIG_PREEMPT_TRACER > void trace_preempt_on(unsigned long a0, unsigned long a1) > { > + if (trace_latency_preempt_enabled()) > + latency_trace(TS_PREEMPT); > + > if (preempt_trace() && !irq_trace()) > stop_critical_timing(a0, a1); > } > @@ -511,6 +549,11 @@ void trace_preempt_off(unsigned long a0, unsigned long a1) > { > if (preempt_trace() && !irq_trace()) > start_critical_timing(a0, a1); > + > + if (trace_latency_preempt_enabled()) { > + this_cpu_write(lat_ts[TS_PREEMPT], > + (cycle_t) trace_clock_local()); > + } And here too. > } > #endif /* CONFIG_PREEMPT_TRACER */ cheers, daniel