Re: [PATCH 0/7 v2] tracing: Have ring_buffer_event_time_stamp() work for all events

Tom Zanussi
2021-03-16T21:16:52Z

Hi Steve,

On Tue, 2021-03-16 at 12:41 -0400, Steven Rostedt wrote:
> Yordan has been working on a patch set that will not repeat functions
> in the function tracer but instead show a single event that states
> that
> the previous function repeated X amount of times. I recommended that
> this should also show the time of the last function that repeated.
> To save on space, Yordan suggested to use a 32 bit delta instead of
> a full 64 bit timestamp of the last event. But to create this delta,
> we need a way to extract the time of the repeat event and use that
> to calculate the delta of the last function event.
>
> But currently the ring_buffer_event_time_stamp() only works if all
> events
> has an absolute time stamp attached to it. That would be counter
> productive
> to make all functions record the full time stamp because we wanted to
> use a 32 bit counter instead of a 64 bit counter for the rare repeat
> event!
>
> This patch series makes ring_buffer_event_time_stamp() work for all
> non committed events (after reserve and before it is committed).
> The trick is that the per CPU descriptor of the buffer holds the time
> stamp used for the event being processed. It has a nesting of 5
> levels
> to deal with interrupts that add events. Extracting the time for the
> event
> can only be done for the current event being processed and not yet
> committed.
>
> To achieve this, the buffer that the event is on needs to be passed
> to
> the ring_buffer_event_time_stamp(). That caused a bit of churn for
> the histogram code, because that buffer wasn't available at the time
> the ring_buffer_event_time_stamp() was called. Although the
> hist_field
> contained a pointer to the trace_array that holds the ring buffer,
> if tracing was disabled, then a temporary buffer was used instead,
> and that temporary buffer would need to be passed to the
> ring_buffer_event_time_stamp(). That buffer is exposed to the trace
> event
> logic, but was not passed down into the trigger code. That had to be
> done to take advantage of the new code.
>
> The second to last patch adds verifier logic (although commented out)
> that was used to debug the issue when a temporary buffer was in use.
> It proved to be very valuable and is kept in, in case this needs to
> be
> debugged again.
>
> Finally the last patch is for use with Yordan's work, and is needed
> because
> when filtering is enabled, the event being processed may not even be
> on the buffer, and the tracing_event_time_stamp() checks for that and
> will just use the current time stamp if the event is not reserved
> yet.
> This could be used also for the histogram code, but wanted to hold
> off
> on that.
>
> Changes since v1:
>
> - Applied change of last patch to pass buffer not trace_array
> - Fixed prototype of stack_track_data_snapshot() when snapshot not
> configured
>
> Steven Rostedt (VMware) (7):
> ring-buffer: Separate out internal use of
> ring_buffer_event_time_stamp()
> ring-buffer: Add a event_stamp to cpu_buffer for each level of
> nesting
> tracing: Pass buffer of event to trigger operations
> ring-buffer: Allow ring_buffer_event_time_stamp() to return
> time stamp of all events
> tracing: Use a no_filter_buffering_ref to stop using the filter
> buffer
> ring-buffer: Add verifier for using
> ring_buffer_event_time_stamp()
> tracing: Add tracing_event_time_stamp() API
>
> ----
> include/linux/ring_buffer.h | 3 +-
> include/linux/trace_events.h | 5 +-
> kernel/trace/ring_buffer.c | 138
> ++++++++++++++++++++++++++++++------
> kernel/trace/trace.c | 38 +++++-----
> kernel/trace/trace.h | 9 +--
> kernel/trace/trace_events_hist.c | 100 +++++++++++++++++---------
> kernel/trace/trace_events_trigger.c | 45 +++++++-----
> 7 files changed, 239 insertions(+), 99 deletions(-)

This all looks fine to me.

Reviewed-by: Tom Zanussi <zanussi@kernel.org>