Re: [PATCH v6 3/4] tracing: Add trace_irqsoff tracepoints

[Steven Rostedt <rostedt@goodmis.org>]

On Thu, 8 Sep 2016 10:06:13 +0200 (CEST)
Thomas Gleixner <tglx@linutronix.de> wrote:


> > +
> >  	if (preempt_trace() || irq_trace())
> >  		start_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
> >  }
> > @@ -431,6 +451,9 @@ void stop_critical_timings(void)
> >  {
> >  	if (preempt_trace() || irq_trace())
> >  		stop_critical_timing(CALLER_ADDR0, CALLER_ADDR1);
> > +
> > +	if (unlikely(trace_latency_preempt_enabled()))
> > +		latency_preempt_timing_stop(LT_CRITTIME);  
> 
> And this is silly as well. You can put the whole evaluation into the trace
> event assignement so the tracer core will handle that conditional.
> 
> Aside of that it is silly to evaluate trace_clock_local() for the actual
> tracepoint simply because that time is already stored in the tracepoint
> itself. The flow here is:
> 
> 	event = trace_event_buffer_lock_reserve();
> 	entry = ring_buffer_event_data(event);
>        	{ <assign>; }  <-- Here we assign the entries by the __field and
>                            __array macros.
> 
> 
> So you should talk to Steven about having a way to retrieve that time from
> entry itself in a generic way.

Note, the time stamp in the ring buffer is not guaranteed to be
trace_local_clock(), it could be changed to be something like
x86_64-tsc.

That said, the timestamp that is saved in the event is an offset from
the previous event (to save space in the buffer). It wont be efficient
to calculate the timestamp at record time because of this. Although,
the last stamp recoded is saved in the buffer descriptor. But it could
be racy to capture it, as NMIs and interrupts could update it.

-- Steve