All of lore.kernel.org
 help / color / mirror / Atom feed
From: Tom Zanussi <tom.zanussi@linux.intel.com>
To: rostedt@goodmis.org
Cc: tglx@linutronix.de, mhiramat@kernel.org, namhyung@kernel.org,
	vedang.patel@intel.com, linux-kernel@vger.kernel.org,
	linux-rt-users@vger.kernel.org,
	Tom Zanussi <tom.zanussi@linux.intel.com>
Subject: [PATCH 04/32] ring-buffer: Redefine the unimplemented RINGBUF_TIME_TIME_STAMP
Date: Mon, 26 Jun 2017 17:49:05 -0500	[thread overview]
Message-ID: <6272b132695d1404c64430f9c81a9365a1686dee.1498510759.git.tom.zanussi@linux.intel.com> (raw)
In-Reply-To: <cover.1498510759.git.tom.zanussi@linux.intel.com>
In-Reply-To: <cover.1498510759.git.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.

Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
---
 include/linux/ring_buffer.h |  12 ++---
 kernel/trace/ring_buffer.c  | 107 +++++++++++++++++++++++++++++++-------------
 2 files changed, 83 insertions(+), 36 deletions(-)

diff --git a/include/linux/ring_buffer.h b/include/linux/ring_buffer.h
index 28e3472..74bc276 100644
--- a/include/linux/ring_buffer.h
+++ b/include/linux/ring_buffer.h
@@ -36,10 +36,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
@@ -56,12 +58,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 f544738..df848f0 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -42,6 +42,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);
 
@@ -147,6 +149,9 @@ enum {
 #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;
@@ -187,10 +192,8 @@ static void rb_event_set_padding(struct ring_buffer_event *event)
 		return  event->array[0] + RB_EVNT_HDR_SIZE;
 
 	case RINGBUF_TYPE_TIME_EXTEND:
-		return RB_LEN_TIME_EXTEND;
-
 	case RINGBUF_TYPE_TIME_STAMP:
-		return RB_LEN_TIME_STAMP;
+		return RB_LEN_TIME_EXTEND;
 
 	case RINGBUF_TYPE_DATA:
 		return rb_event_data_length(event);
@@ -210,7 +213,7 @@ static void rb_event_set_padding(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);
@@ -232,7 +235,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);
@@ -249,7 +252,7 @@ unsigned ring_buffer_event_length(struct ring_buffer_event *event)
 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 */
@@ -276,6 +279,27 @@ void *ring_buffer_event_data(struct ring_buffer_event *event)
 #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 */
@@ -2220,13 +2244,16 @@ static void rb_inc_iter(struct ring_buffer_iter *iter)
 }
 
 /* Slow path, do not inline */
-static noinline struct ring_buffer_event *
-rb_add_time_stamp(struct ring_buffer_event *event, u64 delta)
+static struct noinline ring_buffer_event *
+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 {
@@ -2269,7 +2296,9 @@ static inline bool rb_event_is_commit(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;
 	}
@@ -2457,7 +2486,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 */
@@ -2488,6 +2517,10 @@ static inline void rb_event_discard(struct ring_buffer_event *event)
 {
 	u64 delta;
 
+	/* In TIME_STAMP mode, write_stamp is unused, nothing to do */
+	if (event->type_len == RINGBUF_TYPE_TIME_STAMP)
+		return;
+
 	/*
 	 * The event first in the commit queue updates the
 	 * time stamp.
@@ -2501,9 +2534,7 @@ static inline void rb_event_discard(struct ring_buffer_event *event)
 			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
 			cpu_buffer->write_stamp += event->time_delta;
@@ -2687,7 +2718,7 @@ int ring_buffer_unlock_commit(struct ring_buffer *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 */
@@ -2765,8 +2796,11 @@ int ring_buffer_unlock_commit(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);
@@ -3448,14 +3482,12 @@ int ring_buffer_iter_empty(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);
 		cpu_buffer->read_stamp += delta;
 		return;
 
 	case RINGBUF_TYPE_TIME_STAMP:
-		/* FIXME: not implemented */
+		/* In TIME_STAMP mode, write_stamp is unused, nothing to do */
 		return;
 
 	case RINGBUF_TYPE_DATA:
@@ -3479,14 +3511,12 @@ int ring_buffer_iter_empty(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 */
+		/* In TIME_STAMP mode, write_stamp is unused, nothing to do */
 		return;
 
 	case RINGBUF_TYPE_DATA:
@@ -3710,6 +3740,8 @@ static int rb_lost_events(struct ring_buffer_per_cpu *cpu_buffer)
 	struct buffer_page *reader;
 	int nr_loops = 0;
 
+	if (ts)
+		*ts = 0;
  again:
 	/*
 	 * We repeat when a time extend is encountered.
@@ -3746,12 +3778,17 @@ static int rb_lost_events(struct ring_buffer_per_cpu *cpu_buffer)
 		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);
@@ -3776,6 +3813,9 @@ static int rb_lost_events(struct ring_buffer_per_cpu *cpu_buffer)
 	struct ring_buffer_event *event;
 	int nr_loops = 0;
 
+	if (ts)
+		*ts = 0;
+
 	cpu_buffer = iter->cpu_buffer;
 	buffer = cpu_buffer->buffer;
 
@@ -3828,12 +3868,17 @@ static int rb_lost_events(struct ring_buffer_per_cpu *cpu_buffer)
 		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);
-- 
1.9.3

  parent reply	other threads:[~2017-06-26 22:56 UTC|newest]

Thread overview: 66+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2017-06-26 22:49 [PATCH 00/32] tracing: Inter-event (e.g. latency) support Tom Zanussi
2017-06-26 22:49 ` [PATCH 01/32] tracing: Add hist_field_name() accessor Tom Zanussi
2017-07-13  6:49   ` Piotr Gregor
2017-07-13 14:41     ` Tom Zanussi
2017-07-14  2:19   ` Namhyung Kim
2017-06-26 22:49 ` [PATCH 02/32] tracing: Reimplement log2 Tom Zanussi
2017-07-14  2:33   ` Namhyung Kim
2017-07-14 16:13     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 03/32] ring-buffer: Add interface for setting absolute time stamps Tom Zanussi
2017-07-14  5:25   ` Namhyung Kim
2017-07-14 16:14     ` Tom Zanussi
2017-06-26 22:49 ` Tom Zanussi [this message]
2017-07-02  8:51   ` [PATCH 04/32] ring-buffer: Redefine the unimplemented RINGBUF_TIME_TIME_STAMP Joel Fernandes (Google)
2017-06-26 22:49 ` [PATCH 05/32] tracing: Give event triggers access to ring_buffer_event Tom Zanussi
2017-06-26 22:49 ` [PATCH 06/32] tracing: Add ring buffer event param to hist field functions Tom Zanussi
2017-06-26 22:49 ` [PATCH 07/32] tracing: Increase tracing map KEYS_MAX size Tom Zanussi
2017-06-26 22:49 ` [PATCH 08/32] tracing: Break out hist trigger assignment parsing Tom Zanussi
2017-06-26 22:49 ` [PATCH 09/32] tracing: Make traceprobe parsing code reusable Tom Zanussi
2017-06-26 22:49 ` [PATCH 10/32] tracing: Add NO_DISCARD event file flag Tom Zanussi
2017-06-26 22:49 ` [PATCH 11/32] tracing: Add post-trigger flag to hist trigger command Tom Zanussi
2017-06-26 22:49 ` [PATCH 12/32] tracing: Add hist trigger timestamp support Tom Zanussi
2017-07-17  6:00   ` Namhyung Kim
2017-07-17 16:57     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 13/32] tracing: Add per-element variable support to tracing_map Tom Zanussi
2017-06-26 22:49 ` [PATCH 14/32] tracing: Add hist_data member to hist_field Tom Zanussi
2017-06-26 22:49 ` [PATCH 15/32] tracing: Add usecs modifier for hist trigger timestamps Tom Zanussi
2017-06-26 22:49 ` [PATCH 16/32] tracing: Add variable support to hist triggers Tom Zanussi
2017-07-19  1:07   ` Namhyung Kim
2017-07-19 15:40     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 17/32] tracing: Account for variables in named trigger compatibility Tom Zanussi
2017-06-26 22:49 ` [PATCH 18/32] tracing: Add simple expression support to hist triggers Tom Zanussi
2017-07-21  2:02   ` Namhyung Kim
2017-07-21 16:29     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 19/32] tracing: Add variable reference handling " Tom Zanussi
2017-07-21  3:31   ` Namhyung Kim
2017-07-21 16:41     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 20/32] tracing: Add support for dynamic tracepoints Tom Zanussi
2017-06-26 22:49 ` [PATCH 21/32] tracing: Add hist trigger action hook Tom Zanussi
2017-06-26 22:49 ` [PATCH 22/32] tracing: Add support for 'synthetic' events Tom Zanussi
2017-07-23 12:00   ` Namhyung Kim
2017-07-24 16:11     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 23/32] tracing: Add 'onmatch' hist trigger action support Tom Zanussi
2017-07-23 15:12   ` Namhyung Kim
2017-07-24 16:17     ` Tom Zanussi
2017-07-26  2:40   ` Namhyung Kim
2017-07-26 16:38     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 24/32] tracing: Add 'onmax' " Tom Zanussi
2017-07-26  3:04   ` Namhyung Kim
2017-07-26 16:45     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 25/32] tracing: Allow whitespace to surround hist trigger filter Tom Zanussi
2017-06-26 22:49 ` [PATCH 26/32] tracing: Make duplicate count from tracing_map available Tom Zanussi
2017-06-26 22:49 ` [PATCH 27/32] tracing: Add cpu field for hist triggers Tom Zanussi
2017-06-26 22:49 ` [PATCH 28/32] tracing: Add hist trigger support for variable reference aliases Tom Zanussi
2017-06-26 22:49 ` [PATCH 29/32] tracing: Add 'last error' error facility for hist triggers Tom Zanussi
2017-07-26  4:39   ` Namhyung Kim
2017-07-26 16:47     ` Tom Zanussi
2017-06-26 22:49 ` [PATCH 30/32] tracing: Add inter-event hist trigger Documentation Tom Zanussi
2017-06-26 22:49 ` [PATCH 31/32] tracing: Make tracing_set_clock() non-static Tom Zanussi
2017-06-26 22:49 ` [PATCH 32/32] tracing: Add a clock attribute for hist triggers Tom Zanussi
2017-06-27 14:58 ` [PATCH 00/32] tracing: Inter-event (e.g. latency) support Steven Rostedt
2017-06-28 14:21 ` Masami Hiramatsu
2017-06-28 19:09   ` Tom Zanussi
2017-07-01  7:01 ` Joel Fernandes (Google)
2017-07-12 19:17   ` Tom Zanussi
2017-07-04 16:12 ` Sebastian Andrzej Siewior
2017-07-12 19:20   ` Tom Zanussi

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=6272b132695d1404c64430f9c81a9365a1686dee.1498510759.git.tom.zanussi@linux.intel.com \
    --to=tom.zanussi@linux.intel.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-rt-users@vger.kernel.org \
    --cc=mhiramat@kernel.org \
    --cc=namhyung@kernel.org \
    --cc=rostedt@goodmis.org \
    --cc=tglx@linutronix.de \
    --cc=vedang.patel@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 an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.