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 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.