From: Steven Rostedt <rostedt@goodmis.org>
To: linux-kernel@vger.kernel.org
Cc: Ingo Molnar <mingo@kernel.org>,
Andrew Morton <akpm@linux-foundation.org>,
Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Subject: [for-next][PATCH 15/18] ring-buffer: Consolidate add_timestamp to remove some branches
Date: Thu, 02 Jul 2020 17:58:27 -0400 [thread overview]
Message-ID: <20200702215833.709172905@goodmis.org> (raw)
In-Reply-To: 20200702215812.428188663@goodmis.org
From: "Steven Rostedt (VMware)" <rostedt@goodmis.org>
Reorganize a little the logic to handle adding the absolute time stamp,
extended and forced time stamps, in such a way to remove a branch or two.
This is just a micro optimization.
Also add before and after time stamps to the rb_event_info structure to
display those values in the rb_check_timestamps() code, if something were to
go wrong.
Suggested-by: Mathieu Desnoyers <mathieu.desnoyers@efficios.com>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
kernel/trace/ring_buffer.c | 139 +++++++++++++++++++------------------
1 file changed, 73 insertions(+), 66 deletions(-)
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 888bc9177937..ce125cbe98a5 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -416,6 +416,8 @@ struct rb_irq_work {
struct rb_event_info {
u64 ts;
u64 delta;
+ u64 before;
+ u64 after;
unsigned long length;
struct buffer_page *tail_page;
int add_timestamp;
@@ -2619,6 +2621,33 @@ rb_add_time_stamp(struct ring_buffer_event *event, u64 delta, bool abs)
static inline bool rb_event_is_commit(struct ring_buffer_per_cpu *cpu_buffer,
struct ring_buffer_event *event);
+#ifndef CONFIG_HAVE_UNSTABLE_SCHED_CLOCK
+static inline bool sched_clock_stable(void)
+{
+ return true;
+}
+#endif
+
+static noinline void
+rb_check_timestamp(struct ring_buffer_per_cpu *cpu_buffer,
+ struct rb_event_info *info)
+{
+ u64 write_stamp;
+
+ WARN_ONCE(info->delta > (1ULL << 59),
+ KERN_WARNING "Delta way too big! %llu ts=%llu before=%llu after=%llu write stamp=%llu\n%s",
+ (unsigned long long)info->delta,
+ (unsigned long long)info->ts,
+ (unsigned long long)info->before,
+ (unsigned long long)info->after,
+ (unsigned long long)(rb_time_read(&cpu_buffer->write_stamp, &write_stamp) ? write_stamp : 0),
+ sched_clock_stable() ? "" :
+ "If you just came from a suspend/resume,\n"
+ "please switch to the trace global clock:\n"
+ " echo global > /sys/kernel/debug/tracing/trace_clock\n"
+ "or add trace_clock=global to the kernel command line\n");
+}
+
/**
* rb_update_event - update event type and data
* @cpu_buffer: The per cpu buffer of the @event
@@ -2646,6 +2675,7 @@ rb_update_event(struct ring_buffer_per_cpu *cpu_buffer,
bool abs = info->add_timestamp &
(RB_ADD_STAMP_FORCE | RB_ADD_STAMP_ABSOLUTE);
+ rb_check_timestamp(cpu_buffer, info);
event = rb_add_time_stamp(event, abs ? info->delta : delta, abs);
length -= RB_LEN_TIME_EXTEND;
delta = 0;
@@ -2692,13 +2722,6 @@ static unsigned rb_calculate_event_length(unsigned length)
return length;
}
-#ifndef CONFIG_HAVE_UNSTABLE_SCHED_CLOCK
-static inline bool sched_clock_stable(void)
-{
- return true;
-}
-#endif
-
static __always_inline bool
rb_event_is_commit(struct ring_buffer_per_cpu *cpu_buffer,
struct ring_buffer_event *event)
@@ -3092,24 +3115,6 @@ int ring_buffer_unlock_commit(struct trace_buffer *buffer,
}
EXPORT_SYMBOL_GPL(ring_buffer_unlock_commit);
-static noinline void
-rb_check_timestamp(struct ring_buffer_per_cpu *cpu_buffer,
- struct rb_event_info *info)
-{
- u64 write_stamp;
-
- WARN_ONCE(info->delta > (1ULL << 59),
- KERN_WARNING "Delta way too big! %llu ts=%llu write stamp = %llu\n%s",
- (unsigned long long)info->delta,
- (unsigned long long)info->ts,
- (unsigned long long)(rb_time_read(&cpu_buffer->write_stamp, &write_stamp) ? write_stamp : 0),
- sched_clock_stable() ? "" :
- "If you just came from a suspend/resume,\n"
- "please switch to the trace global clock:\n"
- " echo global > /sys/kernel/debug/tracing/trace_clock\n"
- "or add trace_clock=global to the kernel command line\n");
-}
-
static struct ring_buffer_event *
__rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
struct rb_event_info *info)
@@ -3117,7 +3122,6 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
struct ring_buffer_event *event;
struct buffer_page *tail_page;
unsigned long tail, write, w;
- u64 before, after;
bool a_ok;
bool b_ok;
@@ -3126,40 +3130,31 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
/*A*/ w = local_read(&tail_page->write) & RB_WRITE_MASK;
barrier();
- b_ok = rb_time_read(&cpu_buffer->before_stamp, &before);
- a_ok = rb_time_read(&cpu_buffer->write_stamp, &after);
+ b_ok = rb_time_read(&cpu_buffer->before_stamp, &info->before);
+ a_ok = rb_time_read(&cpu_buffer->write_stamp, &info->after);
barrier();
info->ts = rb_time_stamp(cpu_buffer->buffer);
- if (ring_buffer_time_stamp_abs(cpu_buffer->buffer)) {
+ if ((info->add_timestamp & RB_ADD_STAMP_ABSOLUTE)) {
info->delta = info->ts;
- info->add_timestamp = RB_ADD_STAMP_ABSOLUTE;
} else {
- info->delta = info->ts - after;
- }
-
- if (likely(a_ok && b_ok)) {
- if (unlikely(test_time_stamp(info->delta))) {
- rb_check_timestamp(cpu_buffer, info);
- info->add_timestamp |= RB_ADD_STAMP_EXTEND;
+ /*
+ * If interrupting an event time update, we may need an
+ * absolute timestamp.
+ * Don't bother if this is the start of a new page (w == 0).
+ */
+ if (unlikely(!a_ok || !b_ok || (info->before != info->after && w))) {
+ info->add_timestamp |= RB_ADD_STAMP_FORCE | RB_ADD_STAMP_EXTEND;
+ info->length += RB_LEN_TIME_EXTEND;
+ } else {
+ info->delta = info->ts - info->after;
+ if (unlikely(test_time_stamp(info->delta))) {
+ info->add_timestamp |= RB_ADD_STAMP_EXTEND;
+ info->length += RB_LEN_TIME_EXTEND;
+ }
}
}
- /*
- * If interrupting an event time update, we may need an absolute timestamp.
- * Don't bother if this is the start of a new page (w == 0).
- */
- if (unlikely(!a_ok || !b_ok || (before != after && w)))
- info->add_timestamp |= RB_ADD_STAMP_FORCE | RB_ADD_STAMP_EXTEND;
-
- /*
- * If the time delta since the last event is too big to
- * hold in the time field of the event, then we append a
- * TIME EXTEND event ahead of the data event.
- */
- if (unlikely(info->add_timestamp))
- info->length += RB_LEN_TIME_EXTEND;
-
/*B*/ rb_time_set(&cpu_buffer->before_stamp, info->ts);
/*C*/ write = local_add_return(info->length, &tail_page->write);
@@ -3173,10 +3168,11 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
if (unlikely(write > BUF_PAGE_SIZE)) {
if (tail != w) {
/* before and after may now different, fix it up*/
- b_ok = rb_time_read(&cpu_buffer->before_stamp, &before);
- a_ok = rb_time_read(&cpu_buffer->write_stamp, &after);
- if (a_ok && b_ok && before != after)
- (void)rb_time_cmpxchg(&cpu_buffer->before_stamp, before, after);
+ b_ok = rb_time_read(&cpu_buffer->before_stamp, &info->before);
+ a_ok = rb_time_read(&cpu_buffer->write_stamp, &info->after);
+ if (a_ok && b_ok && info->before != info->after)
+ (void)rb_time_cmpxchg(&cpu_buffer->before_stamp,
+ info->before, info->after);
}
return rb_move_tail(cpu_buffer, tail, info);
}
@@ -3193,7 +3189,7 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
if (likely(!(info->add_timestamp &
(RB_ADD_STAMP_FORCE | RB_ADD_STAMP_ABSOLUTE))))
/* This did not interrupt any time update */
- info->delta = info->ts - after;
+ info->delta = info->ts - info->after;
else
/* Just use full timestamp for inerrupting event */
info->delta = info->ts;
@@ -3201,31 +3197,33 @@ __rb_reserve_next(struct ring_buffer_per_cpu *cpu_buffer,
if (unlikely(info->ts != save_before)) {
/* SLOW PATH - Interrupted between C and E */
- a_ok = rb_time_read(&cpu_buffer->write_stamp, &after);
+ a_ok = rb_time_read(&cpu_buffer->write_stamp, &info->after);
RB_WARN_ON(cpu_buffer, !a_ok);
/* Write stamp must only go forward */
- if (save_before > after) {
+ if (save_before > info->after) {
/*
* We do not care about the result, only that
* it gets updated atomically.
*/
- (void)rb_time_cmpxchg(&cpu_buffer->write_stamp, after, save_before);
+ (void)rb_time_cmpxchg(&cpu_buffer->write_stamp,
+ info->after, save_before);
}
}
} else {
u64 ts;
/* SLOW PATH - Interrupted between A and C */
- a_ok = rb_time_read(&cpu_buffer->write_stamp, &after);
+ a_ok = rb_time_read(&cpu_buffer->write_stamp, &info->after);
/* Was interrupted before here, write_stamp must be valid */
RB_WARN_ON(cpu_buffer, !a_ok);
ts = rb_time_stamp(cpu_buffer->buffer);
barrier();
/*E*/ if (write == (local_read(&tail_page->write) & RB_WRITE_MASK) &&
- after < ts) {
+ info->after < ts) {
/* Nothing came after this event between C and E */
- info->delta = ts - after;
- (void)rb_time_cmpxchg(&cpu_buffer->write_stamp, after, info->ts);
+ info->delta = ts - info->after;
+ (void)rb_time_cmpxchg(&cpu_buffer->write_stamp,
+ info->after, info->ts);
info->ts = ts;
} else {
/*
@@ -3277,6 +3275,7 @@ rb_reserve_next_event(struct trace_buffer *buffer,
struct ring_buffer_event *event;
struct rb_event_info info;
int nr_loops = 0;
+ int add_ts_default;
rb_start_commit(cpu_buffer);
/* The commit page can not change after this */
@@ -3297,8 +3296,16 @@ rb_reserve_next_event(struct trace_buffer *buffer,
#endif
info.length = rb_calculate_event_length(length);
+
+ if (ring_buffer_time_stamp_abs(cpu_buffer->buffer)) {
+ add_ts_default = RB_ADD_STAMP_ABSOLUTE;
+ info.length += RB_LEN_TIME_EXTEND;
+ } else {
+ add_ts_default = RB_ADD_STAMP_NONE;
+ }
+
again:
- info.add_timestamp = RB_ADD_STAMP_NONE;
+ info.add_timestamp = add_ts_default;
info.delta = 0;
/*
@@ -3316,7 +3323,7 @@ rb_reserve_next_event(struct trace_buffer *buffer,
event = __rb_reserve_next(cpu_buffer, &info);
if (unlikely(PTR_ERR(event) == -EAGAIN)) {
- if (info.add_timestamp)
+ if (info.add_timestamp & (RB_ADD_STAMP_FORCE | RB_ADD_STAMP_EXTEND))
info.length -= RB_LEN_TIME_EXTEND;
goto again;
}
--
2.26.2
next prev parent reply other threads:[~2020-07-02 21:59 UTC|newest]
Thread overview: 24+ messages / expand[flat|nested] mbox.gz Atom feed top
2020-07-02 21:58 [for-next][PATCH 00/18] tracing: Updatse for 5.9 Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 01/18] tracing: Only allow trace_array_printk() to be used by instances Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 02/18] x86/ftrace: Make non direct case the default in ftrace_regs_caller Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 03/18] x86/ftrace: Only have the builtin ftrace_regs_caller call direct hooks Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 04/18] x86/ftrace: Do not jump to direct code in created trampolines Steven Rostedt
2020-07-03 8:10 ` Peter Zijlstra
2020-07-14 3:24 ` Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 05/18] tracing: not necessary to undefine DEFINE_EVENT again Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 06/18] tracing: not necessary re-define DEFINE_EVENT_PRINT Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 07/18] tracing: define DEFINE_EVENT_PRINT not related to DEFINE_EVENT Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 08/18] tracing: not necessary to define DEFINE_EVENT_PRINT to be empty again Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 09/18] tracing: Move pipe reference to trace array instead of current_tracer Steven Rostedt
2020-07-31 19:33 ` dann frazier
2020-07-31 21:16 ` Steven Rostedt
2020-07-31 21:17 ` dann frazier
2020-07-02 21:58 ` [for-next][PATCH 10/18] ring-buffer: Have nested events still record running time stamp Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 11/18] ring-buffer: Incorporate absolute timestamp into add_timestamp logic Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 12/18] ring-buffer: Add rb_time_t 64 bit operations for speeding up 32 bit Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 13/18] ring-buffer: speed up buffer resets by avoiding synchronize_rcu for each CPU Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 14/18] ring-buffer: Mark the !tail (crossing a page) as unlikely Steven Rostedt
2020-07-02 21:58 ` Steven Rostedt [this message]
2020-07-02 21:58 ` [for-next][PATCH 16/18] ring-buffer: Move the add_timestamp into its own function Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 17/18] ring-buffer: Call trace_clock_local() directly for RETPOLINE kernels Steven Rostedt
2020-07-02 21:58 ` [for-next][PATCH 18/18] ring-buffer: Do not trigger a WARN if clock going backwards is detected 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=20200702215833.709172905@goodmis.org \
--to=rostedt@goodmis.org \
--cc=akpm@linux-foundation.org \
--cc=linux-kernel@vger.kernel.org \
--cc=mathieu.desnoyers@efficios.com \
--cc=mingo@kernel.org \
/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