From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751957AbdIVJCe (ORCPT ); Fri, 22 Sep 2017 05:02:34 -0400 Received: from bombadil.infradead.org ([65.50.211.133]:57007 "EHLO bombadil.infradead.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751809AbdIVJCd (ORCPT ); Fri, 22 Sep 2017 05:02:33 -0400 Date: Fri, 22 Sep 2017 11:02:29 +0200 From: Peter Zijlstra To: Joel Fernandes Cc: linux-kernel@vger.kernel.org, kernel-team@android.com, Steven Rostedt Subject: Re: [PATCH v6 2/2] tracing: Add support for preempt and irq enable/disable events Message-ID: <20170922090229.rdicci6emtyffqdn@hirez.programming.kicks-ass.net> References: <20170922015024.16123-1-joelaf@google.com> <20170922015024.16123-3-joelaf@google.com> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: <20170922015024.16123-3-joelaf@google.com> User-Agent: NeoMutt/20170609 (1.8.3) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Thu, Sep 21, 2017 at 06:50:24PM -0700, Joel Fernandes wrote: > +DECLARE_EVENT_CLASS(preemptirq_template, > + > + TP_PROTO(unsigned long ip, unsigned long parent_ip), > + > + TP_ARGS(ip, parent_ip), > + > + TP_STRUCT__entry( > + __field(u32, caller_offs) > + __field(u32, parent_offs) > + ), > + > + TP_fast_assign( > + __entry->caller_offs = (u32)(ip - (unsigned long)_stext); > + __entry->parent_offs = (u32)(parent_ip - (unsigned long)_stext); > + ), > + > + TP_printk("caller=%pF parent=%pF", > + (void *)((unsigned long)(_stext) + __entry->caller_offs), > + (void *)((unsigned long)(_stext) + __entry->parent_offs)) > +); So I don't get that function prototype. Why do we need two IPs? > diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c > index 26c688740742..f3087e7278cb 100644 > --- a/kernel/trace/trace_irqsoff.c > +++ b/kernel/trace/trace_irqsoff.c > @@ -16,6 +16,9 @@ > > #include "trace.h" > > +#define CREATE_TRACE_POINTS > +#include > + > #if defined(CONFIG_IRQSOFF_TRACER) || defined(CONFIG_PREEMPT_TRACER) > static struct trace_array *irqsoff_trace __read_mostly; > static int tracer_enabled __read_mostly; > @@ -777,14 +780,29 @@ static inline void tracer_preempt_on(unsigned long a0, unsigned long a1) { } > static inline void tracer_preempt_off(unsigned long a0, unsigned long a1) { } > #endif > > +static DEFINE_PER_CPU(int, tracing_irq_cpu); > +static DEFINE_PER_CPU(int, tracing_preempt_cpu); > + > void start_critical_timings(void) > { > + if (this_cpu_read(tracing_preempt_cpu)) > + trace_preempt_enable_rcuidle(CALLER_ADDR0, CALLER_ADDR1); > + > + if (this_cpu_read(tracing_irq_cpu)) > + trace_irq_enable_rcuidle(CALLER_ADDR0, CALLER_ADDR1); > + > start_critical_timings_tracer(); > } > EXPORT_SYMBOL_GPL(start_critical_timings); > > void stop_critical_timings(void) > { > + if (this_cpu_read(tracing_preempt_cpu)) > + trace_preempt_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1); > + > + if (this_cpu_read(tracing_irq_cpu)) > + trace_irq_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1); > + > stop_critical_timings_tracer(); > } > EXPORT_SYMBOL_GPL(stop_critical_timings); And I feel these yield somewhat odd semantics, does that need explaining somewhere? > @@ -792,24 +810,48 @@ EXPORT_SYMBOL_GPL(stop_critical_timings); > #if defined(CONFIG_TRACE_IRQFLAGS) && !defined(CONFIG_PROVE_LOCKING) > void trace_hardirqs_on(void) > { > + if (!this_cpu_read(tracing_irq_cpu)) > + return; > + > + trace_irq_enable_rcuidle(CALLER_ADDR0, CALLER_ADDR1); > tracer_hardirqs_on(); > + > + this_cpu_write(tracing_irq_cpu, 0); > } > EXPORT_SYMBOL(trace_hardirqs_on); > > void trace_hardirqs_off(void) > { > + if (this_cpu_read(tracing_irq_cpu)) > + return; > + > + this_cpu_write(tracing_irq_cpu, 1); > + > + trace_irq_disable_rcuidle(CALLER_ADDR0, CALLER_ADDR1); > tracer_hardirqs_off(); > } > EXPORT_SYMBOL(trace_hardirqs_off); > > __visible void trace_hardirqs_on_caller(unsigned long caller_addr) > { > + if (!this_cpu_read(tracing_irq_cpu)) > + return; > + > + trace_irq_enable_rcuidle(CALLER_ADDR0, caller_addr); > tracer_hardirqs_on_caller(caller_addr); > + > + this_cpu_write(tracing_irq_cpu, 0); > } > EXPORT_SYMBOL(trace_hardirqs_on_caller); > > __visible void trace_hardirqs_off_caller(unsigned long caller_addr) > { > + if (this_cpu_read(tracing_irq_cpu)) > + return; > + > + this_cpu_write(tracing_irq_cpu, 1); > + > + trace_irq_disable_rcuidle(CALLER_ADDR0, caller_addr); > tracer_hardirqs_off_caller(caller_addr); > } > EXPORT_SYMBOL(trace_hardirqs_off_caller); > @@ -831,14 +873,27 @@ inline void print_irqtrace_events(struct task_struct *curr) > } > #endif > > -#ifdef CONFIG_PREEMPT_TRACER > +#if defined(CONFIG_PREEMPT_TRACER) || \ > + (defined(CONFIG_DEBUG_PREEMPT) && defined(CONFIG_PREEMPTIRQ_EVENTS)) > void trace_preempt_on(unsigned long a0, unsigned long a1) > { > + if (!this_cpu_read(tracing_preempt_cpu)) > + return; > + > + trace_preempt_enable_rcuidle(a0, a1); > tracer_preempt_on(a0, a1); > + > + this_cpu_write(tracing_preempt_cpu, 0); > } > > void trace_preempt_off(unsigned long a0, unsigned long a1) > { > + if (this_cpu_read(tracing_preempt_cpu)) > + return; > + > + this_cpu_write(tracing_preempt_cpu, 1); > + > + trace_preempt_disable_rcuidle(a0, a1); > tracer_preempt_off(a0, a1); > } > #endif And here you assume things like double on / double off don't happen, which might well be so, but does seem somewhat fragile. So all in all I don't see anything particularly wrong, but I see lots that could do with explaining.