public inbox for linux-kernel@vger.kernel.org
 help / color / mirror / Atom feed
From: Steven Rostedt <rostedt@goodmis.org>
To: linux-kernel@vger.kernel.org
Cc: Ingo Molnar <mingo@kernel.org>,
	Andrew Morton <akpm@linux-foundation.org>,
	Tom Zanussi <tom.zanussi@linux.intel.com>
Subject: [for-next][PATCH 06/46] ring-buffer: Redefine the unimplemented RINGBUF_TYPE_TIME_STAMP
Date: Tue, 20 Mar 2018 22:20:58 -0400	[thread overview]
Message-ID: <20180321022123.846969384@goodmis.org> (raw)
In-Reply-To: 20180321022052.030055576@goodmis.org

[-- Attachment #1: 0006-ring-buffer-Redefine-the-unimplemented-RINGBUF_TYPE_.patch --]
[-- Type: text/plain, Size: 10911 bytes --]

From: Tom Zanussi <tom.zanussi@linux.intel.com>

RINGBUF_TYPE_TIME_STAMP is defined but not used, and from what I can
gather was reserved for something like an absolute timestamp feature
for the ring buffer, if not a complete replacement of the current
time_delta scheme.

This code redefines RINGBUF_TYPE_TIME_STAMP to implement absolute time
stamps.  Another way to look at it is that it essentially forces
extended time_deltas for all events.

The motivation for doing this is to enable time_deltas that aren't
dependent on previous events in the ring buffer, making it feasible to
use the ring_buffer_event timetamps in a more random-access way, for
purposes other than serial event printing.

To set/reset this mode, use tracing_set_timestamp_abs() from the
previous interface patch.

Link: http://lkml.kernel.org/r/477b362dba1ce7fab9889a1a8e885a62c472f041.1516069914.git.tom.zanussi@linux.intel.com

Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 include/linux/ring_buffer.h |  12 ++---
 kernel/trace/ring_buffer.c  | 104 ++++++++++++++++++++++++++++++++------------
 2 files changed, 83 insertions(+), 33 deletions(-)

diff --git a/include/linux/ring_buffer.h b/include/linux/ring_buffer.h
index 025159e17e1b..7cb84774c20d 100644
--- a/include/linux/ring_buffer.h
+++ b/include/linux/ring_buffer.h
@@ -34,10 +34,12 @@ struct ring_buffer_event {
  *				 array[0] = time delta (28 .. 59)
  *				 size = 8 bytes
  *
- * @RINGBUF_TYPE_TIME_STAMP:	Sync time stamp with external clock
- *				 array[0]    = tv_nsec
- *				 array[1..2] = tv_sec
- *				 size = 16 bytes
+ * @RINGBUF_TYPE_TIME_STAMP:	Absolute timestamp
+ *				 Same format as TIME_EXTEND except that the
+ *				 value is an absolute timestamp, not a delta
+ *				 event.time_delta contains bottom 27 bits
+ *				 array[0] = top (28 .. 59) bits
+ *				 size = 8 bytes
  *
  * <= @RINGBUF_TYPE_DATA_TYPE_LEN_MAX:
  *				Data record
@@ -54,12 +56,12 @@ enum ring_buffer_type {
 	RINGBUF_TYPE_DATA_TYPE_LEN_MAX = 28,
 	RINGBUF_TYPE_PADDING,
 	RINGBUF_TYPE_TIME_EXTEND,
-	/* FIXME: RINGBUF_TYPE_TIME_STAMP not implemented */
 	RINGBUF_TYPE_TIME_STAMP,
 };
 
 unsigned ring_buffer_event_length(struct ring_buffer_event *event);
 void *ring_buffer_event_data(struct ring_buffer_event *event);
+u64 ring_buffer_event_time_stamp(struct ring_buffer_event *event);
 
 /*
  * ring_buffer_discard_commit will remove an event that has not
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 2a03e069bbc6..33073cdebb26 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -41,6 +41,8 @@ int ring_buffer_print_entry_header(struct trace_seq *s)
 			 RINGBUF_TYPE_PADDING);
 	trace_seq_printf(s, "\ttime_extend : type == %d\n",
 			 RINGBUF_TYPE_TIME_EXTEND);
+	trace_seq_printf(s, "\ttime_stamp : type == %d\n",
+			 RINGBUF_TYPE_TIME_STAMP);
 	trace_seq_printf(s, "\tdata max type_len  == %d\n",
 			 RINGBUF_TYPE_DATA_TYPE_LEN_MAX);
 
@@ -140,12 +142,15 @@ int ring_buffer_print_entry_header(struct trace_seq *s)
 
 enum {
 	RB_LEN_TIME_EXTEND = 8,
-	RB_LEN_TIME_STAMP = 16,
+	RB_LEN_TIME_STAMP =  8,
 };
 
 #define skip_time_extend(event) \
 	((struct ring_buffer_event *)((char *)event + RB_LEN_TIME_EXTEND))
 
+#define extended_time(event) \
+	(event->type_len >= RINGBUF_TYPE_TIME_EXTEND)
+
 static inline int rb_null_event(struct ring_buffer_event *event)
 {
 	return event->type_len == RINGBUF_TYPE_PADDING && !event->time_delta;
@@ -209,7 +214,7 @@ rb_event_ts_length(struct ring_buffer_event *event)
 {
 	unsigned len = 0;
 
-	if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) {
+	if (extended_time(event)) {
 		/* time extends include the data event after it */
 		len = RB_LEN_TIME_EXTEND;
 		event = skip_time_extend(event);
@@ -231,7 +236,7 @@ unsigned ring_buffer_event_length(struct ring_buffer_event *event)
 {
 	unsigned length;
 
-	if (event->type_len == RINGBUF_TYPE_TIME_EXTEND)
+	if (extended_time(event))
 		event = skip_time_extend(event);
 
 	length = rb_event_length(event);
@@ -248,7 +253,7 @@ EXPORT_SYMBOL_GPL(ring_buffer_event_length);
 static __always_inline void *
 rb_event_data(struct ring_buffer_event *event)
 {
-	if (event->type_len == RINGBUF_TYPE_TIME_EXTEND)
+	if (extended_time(event))
 		event = skip_time_extend(event);
 	BUG_ON(event->type_len > RINGBUF_TYPE_DATA_TYPE_LEN_MAX);
 	/* If length is in len field, then array[0] has the data */
@@ -275,6 +280,27 @@ EXPORT_SYMBOL_GPL(ring_buffer_event_data);
 #define TS_MASK		((1ULL << TS_SHIFT) - 1)
 #define TS_DELTA_TEST	(~TS_MASK)
 
+/**
+ * ring_buffer_event_time_stamp - return the event's extended timestamp
+ * @event: the event to get the timestamp of
+ *
+ * Returns the extended timestamp associated with a data event.
+ * An extended time_stamp is a 64-bit timestamp represented
+ * internally in a special way that makes the best use of space
+ * contained within a ring buffer event.  This function decodes
+ * it and maps it to a straight u64 value.
+ */
+u64 ring_buffer_event_time_stamp(struct ring_buffer_event *event)
+{
+	u64 ts;
+
+	ts = event->array[0];
+	ts <<= TS_SHIFT;
+	ts += event->time_delta;
+
+	return ts;
+}
+
 /* Flag when events were overwritten */
 #define RB_MISSED_EVENTS	(1 << 31)
 /* Missed count stored at end */
@@ -2217,12 +2243,15 @@ rb_move_tail(struct ring_buffer_per_cpu *cpu_buffer,
 
 /* Slow path, do not inline */
 static noinline struct ring_buffer_event *
-rb_add_time_stamp(struct ring_buffer_event *event, u64 delta)
+rb_add_time_stamp(struct ring_buffer_event *event, u64 delta, bool abs)
 {
-	event->type_len = RINGBUF_TYPE_TIME_EXTEND;
+	if (abs)
+		event->type_len = RINGBUF_TYPE_TIME_STAMP;
+	else
+		event->type_len = RINGBUF_TYPE_TIME_EXTEND;
 
-	/* Not the first event on the page? */
-	if (rb_event_index(event)) {
+	/* Not the first event on the page, or not delta? */
+	if (abs || rb_event_index(event)) {
 		event->time_delta = delta & TS_MASK;
 		event->array[0] = delta >> TS_SHIFT;
 	} else {
@@ -2265,7 +2294,9 @@ rb_update_event(struct ring_buffer_per_cpu *cpu_buffer,
 	 * add it to the start of the resevered space.
 	 */
 	if (unlikely(info->add_timestamp)) {
-		event = rb_add_time_stamp(event, delta);
+		bool abs = ring_buffer_time_stamp_abs(cpu_buffer->buffer);
+
+		event = rb_add_time_stamp(event, info->delta, abs);
 		length -= RB_LEN_TIME_EXTEND;
 		delta = 0;
 	}
@@ -2453,7 +2484,7 @@ static __always_inline void rb_end_commit(struct ring_buffer_per_cpu *cpu_buffer
 
 static inline void rb_event_discard(struct ring_buffer_event *event)
 {
-	if (event->type_len == RINGBUF_TYPE_TIME_EXTEND)
+	if (extended_time(event))
 		event = skip_time_extend(event);
 
 	/* array[0] holds the actual length for the discarded event */
@@ -2497,10 +2528,11 @@ rb_update_write_stamp(struct ring_buffer_per_cpu *cpu_buffer,
 			cpu_buffer->write_stamp =
 				cpu_buffer->commit_page->page->time_stamp;
 		else if (event->type_len == RINGBUF_TYPE_TIME_EXTEND) {
-			delta = event->array[0];
-			delta <<= TS_SHIFT;
-			delta += event->time_delta;
+			delta = ring_buffer_event_time_stamp(event);
 			cpu_buffer->write_stamp += delta;
+		} else if (event->type_len == RINGBUF_TYPE_TIME_STAMP) {
+			delta = ring_buffer_event_time_stamp(event);
+			cpu_buffer->write_stamp = delta;
 		} else
 			cpu_buffer->write_stamp += event->time_delta;
 	}
@@ -2680,7 +2712,7 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
 	 * If this is the first commit on the page, then it has the same
 	 * timestamp as the page itself.
 	 */
-	if (!tail)
+	if (!tail && !ring_buffer_time_stamp_abs(cpu_buffer->buffer))
 		info->delta = 0;
 
 	/* See if we shot pass the end of this buffer page */
@@ -2757,8 +2789,11 @@ rb_reserve_next_event(struct ring_buffer *buffer,
 	/* make sure this diff is calculated here */
 	barrier();
 
-	/* Did the write stamp get updated already? */
-	if (likely(info.ts >= cpu_buffer->write_stamp)) {
+	if (ring_buffer_time_stamp_abs(buffer)) {
+		info.delta = info.ts;
+		rb_handle_timestamp(cpu_buffer, &info);
+	} else /* Did the write stamp get updated already? */
+		if (likely(info.ts >= cpu_buffer->write_stamp)) {
 		info.delta = diff;
 		if (unlikely(test_time_stamp(info.delta)))
 			rb_handle_timestamp(cpu_buffer, &info);
@@ -3440,14 +3475,13 @@ rb_update_read_stamp(struct ring_buffer_per_cpu *cpu_buffer,
 		return;
 
 	case RINGBUF_TYPE_TIME_EXTEND:
-		delta = event->array[0];
-		delta <<= TS_SHIFT;
-		delta += event->time_delta;
+		delta = ring_buffer_event_time_stamp(event);
 		cpu_buffer->read_stamp += delta;
 		return;
 
 	case RINGBUF_TYPE_TIME_STAMP:
-		/* FIXME: not implemented */
+		delta = ring_buffer_event_time_stamp(event);
+		cpu_buffer->read_stamp = delta;
 		return;
 
 	case RINGBUF_TYPE_DATA:
@@ -3471,14 +3505,13 @@ rb_update_iter_read_stamp(struct ring_buffer_iter *iter,
 		return;
 
 	case RINGBUF_TYPE_TIME_EXTEND:
-		delta = event->array[0];
-		delta <<= TS_SHIFT;
-		delta += event->time_delta;
+		delta = ring_buffer_event_time_stamp(event);
 		iter->read_stamp += delta;
 		return;
 
 	case RINGBUF_TYPE_TIME_STAMP:
-		/* FIXME: not implemented */
+		delta = ring_buffer_event_time_stamp(event);
+		iter->read_stamp = delta;
 		return;
 
 	case RINGBUF_TYPE_DATA:
@@ -3702,6 +3735,8 @@ rb_buffer_peek(struct ring_buffer_per_cpu *cpu_buffer, u64 *ts,
 	struct buffer_page *reader;
 	int nr_loops = 0;
 
+	if (ts)
+		*ts = 0;
  again:
 	/*
 	 * We repeat when a time extend is encountered.
@@ -3738,12 +3773,17 @@ rb_buffer_peek(struct ring_buffer_per_cpu *cpu_buffer, u64 *ts,
 		goto again;
 
 	case RINGBUF_TYPE_TIME_STAMP:
-		/* FIXME: not implemented */
+		if (ts) {
+			*ts = ring_buffer_event_time_stamp(event);
+			ring_buffer_normalize_time_stamp(cpu_buffer->buffer,
+							 cpu_buffer->cpu, ts);
+		}
+		/* Internal data, OK to advance */
 		rb_advance_reader(cpu_buffer);
 		goto again;
 
 	case RINGBUF_TYPE_DATA:
-		if (ts) {
+		if (ts && !(*ts)) {
 			*ts = cpu_buffer->read_stamp + event->time_delta;
 			ring_buffer_normalize_time_stamp(cpu_buffer->buffer,
 							 cpu_buffer->cpu, ts);
@@ -3768,6 +3808,9 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts)
 	struct ring_buffer_event *event;
 	int nr_loops = 0;
 
+	if (ts)
+		*ts = 0;
+
 	cpu_buffer = iter->cpu_buffer;
 	buffer = cpu_buffer->buffer;
 
@@ -3820,12 +3863,17 @@ rb_iter_peek(struct ring_buffer_iter *iter, u64 *ts)
 		goto again;
 
 	case RINGBUF_TYPE_TIME_STAMP:
-		/* FIXME: not implemented */
+		if (ts) {
+			*ts = ring_buffer_event_time_stamp(event);
+			ring_buffer_normalize_time_stamp(cpu_buffer->buffer,
+							 cpu_buffer->cpu, ts);
+		}
+		/* Internal data, OK to advance */
 		rb_advance_iter(iter);
 		goto again;
 
 	case RINGBUF_TYPE_DATA:
-		if (ts) {
+		if (ts && !(*ts)) {
 			*ts = iter->read_stamp + event->time_delta;
 			ring_buffer_normalize_time_stamp(buffer,
 							 cpu_buffer->cpu, ts);
-- 
2.15.1

  parent reply	other threads:[~2018-03-21  2:30 UTC|newest]

Thread overview: 47+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2018-03-21  2:20 [for-next][PATCH 00/46] tracing: Updates for v4.17 Steven Rostedt
2018-03-21  2:20 ` [for-next][PATCH 01/46] tracing: Move hist trigger Documentation to histogram.txt Steven Rostedt
2018-03-21  2:20 ` [for-next][PATCH 02/46] tracing: Add Documentation for log2 modifier Steven Rostedt
2018-03-21  2:20 ` [for-next][PATCH 03/46] tracing: Add support to detect and avoid duplicates Steven Rostedt
2018-03-21  2:20 ` [for-next][PATCH 04/46] tracing: Remove code which merges duplicates Steven Rostedt
2018-03-21  2:20 ` [for-next][PATCH 05/46] ring-buffer: Add interface for setting absolute time stamps Steven Rostedt
2018-03-21  2:20 ` Steven Rostedt [this message]
2018-03-21  2:20 ` [for-next][PATCH 07/46] tracing: Add timestamp_mode trace file Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 08/46] tracing: Give event triggers access to ring_buffer_event Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 09/46] tracing: Add ring buffer event param to hist field functions Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 10/46] tracing: Break out hist trigger assignment parsing Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 11/46] tracing: Add hist trigger timestamp support Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 12/46] tracing: Add per-element variable support to tracing_map Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 13/46] tracing: Add hist_data member to hist_field Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 14/46] tracing: Add usecs modifier for hist trigger timestamps Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 15/46] tracing: Add variable support to hist triggers Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 16/46] tracing: Account for variables in named trigger compatibility Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 17/46] tracing: Move get_hist_field_flags() Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 18/46] tracing: Add simple expression support to hist triggers Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 19/46] tracing: Generalize per-element hist trigger data Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 20/46] tracing: Pass tracing_map_elt to hist_field accessor functions Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 21/46] tracing: Add hist_field type field Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 22/46] tracing: Add variable reference handling to hist triggers Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 23/46] tracing: Add hist trigger action hook Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 24/46] tracing: Add support for synthetic events Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 25/46] tracing: Add support for field variables Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 26/46] tracing: Add onmatch hist trigger action support Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 27/46] tracing: Add onmax " Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 28/46] tracing: Allow whitespace to surround hist trigger filter Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 29/46] tracing: Add cpu field for hist triggers Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 30/46] tracing: Add hist trigger support for variable reference aliases Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 31/46] tracing: Add last error error facility for hist triggers Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 32/46] tracing: Add inter-event hist trigger Documentation Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 33/46] tracing: Make tracing_set_clock() non-static Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 34/46] tracing: Add a clock attribute for hist triggers Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 35/46] ring-buffer: Add nesting for adding events within events Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 36/46] tracing: Use the ring-buffer nesting to allow synthetic events to be traced Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 37/46] tracing: Add inter-event blurb to HIST_TRIGGERS config option Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 38/46] selftests: ftrace: Add inter-event hist triggers testcases Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 39/46] tracing: Remove BUG_ON() from append_filter_string() Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 40/46] tracing: Use trace_seq instead of open code string appending Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 41/46] tracing: Remove filter allocator helper Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 42/46] tracing: Only add filter list when needed Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 43/46] tracing: Embed replace_filter_string() helper function Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 44/46] tracing: Combine enum and arrays into single macro in filter code Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 45/46] tracing: Clean up and document pred_funcs_##type creation and use Steven Rostedt
2018-03-21  2:21 ` [for-next][PATCH 46/46] tracing: Rewrite filter logic to be simpler and faster Steven Rostedt

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20180321022123.846969384@goodmis.org \
    --to=rostedt@goodmis.org \
    --cc=akpm@linux-foundation.org \
    --cc=linux-kernel@vger.kernel.org \
    --cc=mingo@kernel.org \
    --cc=tom.zanussi@linux.intel.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox