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, bigeasy@linutronix.de,
	joel.opensrc@gmail.com, joelaf@google.com,
	mathieu.desnoyers@efficios.com, baohong.liu@intel.com,
	rajvi.jingar@intel.com, julia@ni.com, fengguang.wu@intel.com,
	linux-kernel@vger.kernel.org, linux-rt-users@vger.kernel.org,
	Tom Zanussi <tom.zanussi@linux.intel.com>
Subject: [PATCH v6 06/37] ring-buffer: Redefine the unimplemented RINGBUF_TYPE_TIME_STAMP
Date: Fri, 17 Nov 2017 14:32:45 -0600	[thread overview]
Message-ID: <501b9cfcb4865710f0e00aa2bec397c9d68c228a.1510948725.git.tom.zanussi@linux.intel.com> (raw)
In-Reply-To: <cover.1510948725.git.tom.zanussi@linux.intel.com>
In-Reply-To: <cover.1510948725.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  | 104 ++++++++++++++++++++++++++++++++------------
 2 files changed, 83 insertions(+), 33 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 1e5b75a..763b3fb 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);
 
@@ -141,12 +143,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;
@@ -210,7 +215,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 +237,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 +254,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 +281,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 */
@@ -2221,12 +2247,15 @@ 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)
+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 +2298,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 +2488,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 */
@@ -2501,10 +2532,11 @@ 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 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;
 	}
@@ -2657,7 +2689,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 */
@@ -2735,8 +2767,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);
@@ -3418,14 +3453,13 @@ 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 */
+		delta = ring_buffer_event_time_stamp(event);
+		cpu_buffer->read_stamp = delta;
 		return;
 
 	case RINGBUF_TYPE_DATA:
@@ -3449,14 +3483,13 @@ 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 */
+		delta = ring_buffer_event_time_stamp(event);
+		iter->read_stamp = delta;
 		return;
 
 	case RINGBUF_TYPE_DATA:
@@ -3680,6 +3713,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.
@@ -3716,12 +3751,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);
@@ -3746,6 +3786,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;
 
@@ -3798,12 +3841,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-11-17 20:35 UTC|newest]

Thread overview: 50+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2017-11-17 20:32 [PATCH v6 00/37] tracing: Inter-event (e.g. latency) support Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 01/37] tracing: Move hist trigger Documentation to histogram.txt Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 02/37] tracing: Add Documentation for log2 modifier Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 03/37] tracing: Add support to detect and avoid duplicates Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 04/37] tracing: Remove code which merges duplicates Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 05/37] ring-buffer: Add interface for setting absolute time stamps Tom Zanussi
2017-11-17 20:32 ` Tom Zanussi [this message]
2017-11-17 20:32 ` [PATCH v6 07/37] tracing: Add timestamp_mode trace file Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 08/37] tracing: Give event triggers access to ring_buffer_event Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 09/37] tracing: Add ring buffer event param to hist field functions Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 10/37] tracing: Break out hist trigger assignment parsing Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 11/37] tracing: Add hist trigger timestamp support Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 12/37] tracing: Add per-element variable support to tracing_map Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 13/37] tracing: Add hist_data member to hist_field Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 14/37] tracing: Add usecs modifier for hist trigger timestamps Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 15/37] tracing: Add variable support to hist triggers Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 16/37] tracing: Account for variables in named trigger compatibility Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 17/37] tracing: Move get_hist_field_flags() Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 18/37] tracing: Add simple expression support to hist triggers Tom Zanussi
2017-11-20  6:05   ` Namhyung Kim
2017-11-17 20:32 ` [PATCH v6 19/37] tracing: Generalize per-element hist trigger data Tom Zanussi
2017-11-17 20:32 ` [PATCH v6 20/37] tracing: Pass tracing_map_elt to hist_field accessor functions Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 21/37] tracing: Add hist_field 'type' field Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 22/37] tracing: Add variable reference handling to hist triggers Tom Zanussi
2017-11-21 10:53   ` Namhyung Kim
2017-11-17 20:33 ` [PATCH v6 23/37] tracing: Add hist trigger action hook Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 24/37] tracing: Add support for 'synthetic' events Tom Zanussi
2017-11-21 11:32   ` Namhyung Kim
2017-11-17 20:33 ` [PATCH v6 25/37] tracing: Add support for 'field variables' Tom Zanussi
2017-11-21 12:08   ` Namhyung Kim
2017-11-22  6:05   ` Namhyung Kim
2017-11-17 20:33 ` [PATCH v6 26/37] tracing: Add 'onmatch' hist trigger action support Tom Zanussi
2017-11-22  9:49   ` Namhyung Kim
2017-11-17 20:33 ` [PATCH v6 27/37] tracing: Add 'onmax' " Tom Zanussi
2017-11-23  5:09   ` Namhyung Kim
2017-11-29 20:53     ` Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 28/37] tracing: Allow whitespace to surround hist trigger filter Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 29/37] tracing: Add cpu field for hist triggers Tom Zanussi
2017-11-23  5:25   ` Namhyung Kim
2017-11-29 21:02     ` Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 30/37] tracing: Add hist trigger support for variable reference aliases Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 31/37] tracing: Add 'last error' error facility for hist triggers Tom Zanussi
2017-11-23  6:22   ` Namhyung Kim
2017-11-17 20:33 ` [PATCH v6 32/37] tracing: Add inter-event hist trigger Documentation Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 33/37] tracing: Make tracing_set_clock() non-static Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 34/37] tracing: Add a clock attribute for hist triggers Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 35/37] tracing: Increase trace_recursive_lock() limit for synthetic events Tom Zanussi
2017-11-17 20:33 ` [PATCH v6 36/37] tracing: Add inter-event blurb to HIST_TRIGGERS config option Tom Zanussi
2017-11-23  6:57   ` Namhyung Kim
2017-11-17 20:33 ` [PATCH v6 37/37] selftests: ftrace: Add inter-event hist triggers testcases 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=501b9cfcb4865710f0e00aa2bec397c9d68c228a.1510948725.git.tom.zanussi@linux.intel.com \
    --to=tom.zanussi@linux.intel.com \
    --cc=baohong.liu@intel.com \
    --cc=bigeasy@linutronix.de \
    --cc=fengguang.wu@intel.com \
    --cc=joel.opensrc@gmail.com \
    --cc=joelaf@google.com \
    --cc=julia@ni.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-rt-users@vger.kernel.org \
    --cc=mathieu.desnoyers@efficios.com \
    --cc=mhiramat@kernel.org \
    --cc=namhyung@kernel.org \
    --cc=rajvi.jingar@intel.com \
    --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.