[tip:perf/core] tracing,x86: Add a TSC trace_clock
Commit-ID: 8cbd9cc6254065c97c4bac42daa55ba1abe73a8e Gitweb: http://git.kernel.org/tip/8cbd9cc6254065c97c4bac42daa55ba1abe73a8e Author: David Sharp AuthorDate: Tue, 13 Nov 2012 12:18:21 -0800 Committer: Steven Rostedt CommitDate: Tue, 13 Nov 2012 15:48:27 -0500 tracing,x86: Add a TSC trace_clock In order to promote interoperability between userspace tracers and ftrace, add a trace_clock that reports raw TSC values which will then be recorded in the ring buffer. Userspace tracers that also record TSCs are then on exactly the same time base as the kernel and events can be unambiguously interlaced. Tested: Enabled a tracepoint and the "tsc" trace_clock and saw very large timestamp values. v2: Move arch-specific bits out of generic code. v3: Rename "x86-tsc", cleanups v7: Generic arch bits in Kbuild. Google-Bug-Id: 6980623 Link: http://lkml.kernel.org/r/1352837903-32191-1-git-send-email-dhsh...@google.com Acked-by: Ingo Molnar Cc: Masami Hiramatsu Cc: Ingo Molnar Cc: Thomas Gleixner Cc: "H. Peter Anvin" Signed-off-by: David Sharp Signed-off-by: Steven Rostedt --- arch/alpha/include/asm/Kbuild | 1 + arch/arm/include/asm/Kbuild| 1 + arch/arm64/include/asm/Kbuild | 1 + arch/avr32/include/asm/Kbuild | 1 + arch/blackfin/include/asm/Kbuild | 1 + arch/c6x/include/asm/Kbuild| 1 + arch/cris/include/asm/Kbuild | 1 + arch/frv/include/asm/Kbuild| 1 + arch/h8300/include/asm/Kbuild | 1 + arch/hexagon/include/asm/Kbuild| 1 + arch/ia64/include/asm/Kbuild | 1 + arch/m32r/include/asm/Kbuild | 1 + arch/m68k/include/asm/Kbuild | 1 + arch/microblaze/include/asm/Kbuild | 1 + arch/mips/include/asm/Kbuild | 1 + arch/mn10300/include/asm/Kbuild| 1 + arch/openrisc/include/asm/Kbuild | 1 + arch/parisc/include/asm/Kbuild | 1 + arch/powerpc/include/asm/Kbuild| 1 + arch/s390/include/asm/Kbuild | 1 + arch/score/include/asm/Kbuild | 1 + arch/sh/include/asm/Kbuild | 1 + arch/sparc/include/asm/Kbuild | 1 + arch/tile/include/asm/Kbuild | 1 + arch/um/include/asm/Kbuild | 1 + arch/unicore32/include/asm/Kbuild | 1 + arch/x86/include/asm/trace_clock.h | 20 arch/x86/kernel/Makefile | 1 + arch/x86/kernel/trace_clock.c | 21 + arch/xtensa/include/asm/Kbuild | 1 + include/asm-generic/trace_clock.h | 16 include/linux/trace_clock.h| 2 ++ kernel/trace/trace.c | 1 + 33 files changed, 88 insertions(+) diff --git a/arch/alpha/include/asm/Kbuild b/arch/alpha/include/asm/Kbuild index 64ffc9e..dcfabb9 100644 --- a/arch/alpha/include/asm/Kbuild +++ b/arch/alpha/include/asm/Kbuild @@ -11,3 +11,4 @@ header-y += reg.h header-y += regdef.h header-y += sysinfo.h generic-y += exec.h +generic-y += trace_clock.h diff --git a/arch/arm/include/asm/Kbuild b/arch/arm/include/asm/Kbuild index f70ae17..514e398 100644 --- a/arch/arm/include/asm/Kbuild +++ b/arch/arm/include/asm/Kbuild @@ -31,5 +31,6 @@ generic-y += sockios.h generic-y += termbits.h generic-y += termios.h generic-y += timex.h +generic-y += trace_clock.h generic-y += types.h generic-y += unaligned.h diff --git a/arch/arm64/include/asm/Kbuild b/arch/arm64/include/asm/Kbuild index a581a22..6e9ca46 100644 --- a/arch/arm64/include/asm/Kbuild +++ b/arch/arm64/include/asm/Kbuild @@ -43,6 +43,7 @@ generic-y += swab.h generic-y += termbits.h generic-y += termios.h generic-y += topology.h +generic-y += trace_clock.h generic-y += types.h generic-y += unaligned.h generic-y += user.h diff --git a/arch/avr32/include/asm/Kbuild b/arch/avr32/include/asm/Kbuild index 4807ded..4dd4f78 100644 --- a/arch/avr32/include/asm/Kbuild +++ b/arch/avr32/include/asm/Kbuild @@ -1,3 +1,4 @@ generic-y += clkdev.h generic-y += exec.h +generic-y += trace_clock.h diff --git a/arch/blackfin/include/asm/Kbuild b/arch/blackfin/include/asm/Kbuild index 5a0625a..27d7075 100644 --- a/arch/blackfin/include/asm/Kbuild +++ b/arch/blackfin/include/asm/Kbuild @@ -38,6 +38,7 @@ generic-y += statfs.h generic-y += termbits.h generic-y += termios.h generic-y += topology.h +generic-y += trace_clock.h generic-y += types.h generic-y += ucontext.h generic-y += unaligned.h diff --git a/arch/c6x/include/asm/Kbuild b/arch/c6x/include/asm/Kbuild index 112a496..eae7b59 100644 --- a/arch/c6x/include/asm/Kbuild +++ b/arch/c6x/include/asm/Kbuild @@ -49,6 +49,7 @@ generic-y += termbits.h generic-y += termios.h generic-y += tlbflush.h generic-y += topology.h +generic-y += trace_clock.h generic-y += types.h generic-y += ucontext.h generic-y += user.h diff --git a/arch/cris/include/asm/Kbuild b/arch/cris/include/asm/Kbuild index 6d43a95..15a122c 100644 --- a/arch/cris/include/asm/Kbuild +++ b/arch/cris/include/asm/Kbuild @@ -11,3 +11,4 @@ header-y += sync_serial.h generic-y += clkdev.h generic-y += exec.h generic-
[tip:perf/core] tracing: Format non-nanosec times from tsc clock without a decimal point.
Commit-ID: 8be0709f10e3dd5d7d07933ad61a9f18c4b93ca5
Gitweb: http://git.kernel.org/tip/8be0709f10e3dd5d7d07933ad61a9f18c4b93ca5
Author: David Sharp
AuthorDate: Tue, 13 Nov 2012 12:18:22 -0800
Committer: Steven Rostedt
CommitDate: Tue, 13 Nov 2012 15:48:40 -0500
tracing: Format non-nanosec times from tsc clock without a decimal point.
With the addition of the "tsc" clock, formatting timestamps to look like
fractional seconds is misleading. Mark clocks as either in nanoseconds or
not, and format non-nanosecond timestamps as decimal integers.
Tested:
$ cd /sys/kernel/debug/tracing/
$ cat trace_clock
[local] global tsc
$ echo sched_switch > set_event
$ echo 1 > tracing_on ; sleep 0.0005 ; echo 0 > tracing_on
$ cat trace
-0 [000] 6330.52: sched_switch: prev_comm=swapper
prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=29964
next_prio=120
sleep-29964 [000] 6330.555628: sched_switch: prev_comm=bash
prev_pid=29964 prev_prio=120 prev_state=S ==> next_comm=swapper next_pid=0
next_prio=120
...
$ echo 1 > options/latency-format
$ cat trace
-0 0 4104553247us+: sched_switch: prev_comm=swapper prev_pid=0
prev_prio=120 prev_state=R ==> next_comm=bash next_pid=29964 next_prio=120
sleep-29964 0 4104553322us+: sched_switch: prev_comm=bash prev_pid=29964
prev_prio=120 prev_state=S ==> next_comm=swapper next_pid=0 next_prio=120
...
$ echo tsc > trace_clock
$ cat trace
$ echo 1 > tracing_on ; sleep 0.0005 ; echo 0 > tracing_on
$ echo 0 > options/latency-format
$ cat trace
-0 [000] 16490053398357: sched_switch: prev_comm=swapper
prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=bash next_pid=31128
next_prio=120
sleep-31128 [000] 16490053588518: sched_switch: prev_comm=bash
prev_pid=31128 prev_prio=120 prev_state=S ==> next_comm=swapper next_pid=0
next_prio=120
...
echo 1 > options/latency-format
$ cat trace
-0 0 91557653238+: sched_switch: prev_comm=swapper prev_pid=0
prev_prio=120 prev_state=R ==> next_comm=bash next_pid=31128 next_prio=120
sleep-31128 0 91557843399+: sched_switch: prev_comm=bash prev_pid=31128
prev_prio=120 prev_state=S ==> next_comm=swapper next_pid=0 next_prio=120
...
v2:
Move arch-specific bits out of generic code.
v4:
Fix x86_32 build due to 64-bit division.
Google-Bug-Id: 6980623
Link:
http://lkml.kernel.org/r/1352837903-32191-2-git-send-email-dhsh...@google.com
Cc: Masami Hiramatsu
Signed-off-by: David Sharp
Signed-off-by: Steven Rostedt
---
arch/x86/include/asm/trace_clock.h | 2 +-
include/linux/ftrace_event.h | 6 +++
kernel/trace/trace.c | 15 ++--
kernel/trace/trace.h | 4 --
kernel/trace/trace_output.c| 78 ++
5 files changed, 72 insertions(+), 33 deletions(-)
diff --git a/arch/x86/include/asm/trace_clock.h
b/arch/x86/include/asm/trace_clock.h
index 5c16527..beab86c 100644
--- a/arch/x86/include/asm/trace_clock.h
+++ b/arch/x86/include/asm/trace_clock.h
@@ -9,7 +9,7 @@
extern u64 notrace trace_clock_x86_tsc(void);
# define ARCH_TRACE_CLOCKS \
- { trace_clock_x86_tsc, "x86-tsc" },
+ { trace_clock_x86_tsc, "x86-tsc", .in_ns = 0 },
#else /* !CONFIG_X86_TSC */
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index b80c8dd..a3d4895 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -86,6 +86,12 @@ struct trace_iterator {
cpumask_var_t started;
};
+enum trace_iter_flags {
+ TRACE_FILE_LAT_FMT = 1,
+ TRACE_FILE_ANNOTATE = 2,
+ TRACE_FILE_TIME_IN_NS = 4,
+};
+
struct trace_event;
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 0d20620..d943e69 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -484,10 +484,11 @@ static const char *trace_options[] = {
static struct {
u64 (*func)(void);
const char *name;
+ int in_ns; /* is this clock in nanoseconds? */
} trace_clocks[] = {
- { trace_clock_local,"local" },
- { trace_clock_global, "global" },
- { trace_clock_counter, "counter" },
+ { trace_clock_local,"local",1 },
+ { trace_clock_global, "global", 1 },
+ { trace_clock_counter, "counter", 0 },
ARCH_TRACE_CLOCKS
};
@@ -2478,6 +2479,10 @@ __tracing_open(struct inode *inode, struct file *file)
if (ring_buffer_overruns(iter->tr->buffer))
iter->iter_flags |= TRACE_FILE_ANNOTATE;
+ /* Output in nanoseconds only if we are using a clock in nanoseconds. */
+ if (trace_clocks[trace_clock_id].in_ns)
+ iter->iter_flags |= TRACE_FILE_TIME_IN_NS;
+
/* stop the trace while dumping */
tracing_stop();
@@ -3339,6 +3344,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags & TRACE_ITER_LATENCY_FMT)
[tip:perf/core] tracing: Trivial cleanup
Commit-ID: 01e3e710a9265fb7092efd67243d7b6dd6e2548a
Gitweb: http://git.kernel.org/tip/01e3e710a9265fb7092efd67243d7b6dd6e2548a
Author: David Sharp
AuthorDate: Thu, 7 Jun 2012 16:46:24 -0700
Committer: Steven Rostedt
CommitDate: Wed, 31 Oct 2012 16:45:33 -0400
tracing: Trivial cleanup
Remove ftrace_format_syscall() declaration; it is neither defined nor
used. Also update a comment and formatting.
Link:
http://lkml.kernel.org/r/1339112785-21806-1-git-send-email-vnagarn...@google.com
Signed-off-by: David Sharp
Signed-off-by: Vaibhav Nagarnaik
Signed-off-by: Steven Rostedt
---
include/trace/syscall.h|2 --
kernel/trace/ring_buffer.c |6 +++---
2 files changed, 3 insertions(+), 5 deletions(-)
diff --git a/include/trace/syscall.h b/include/trace/syscall.h
index 31966a4..0c95796 100644
--- a/include/trace/syscall.h
+++ b/include/trace/syscall.h
@@ -39,8 +39,6 @@ extern int reg_event_syscall_enter(struct ftrace_event_call
*call);
extern void unreg_event_syscall_enter(struct ftrace_event_call *call);
extern int reg_event_syscall_exit(struct ftrace_event_call *call);
extern void unreg_event_syscall_exit(struct ftrace_event_call *call);
-extern int
-ftrace_format_syscall(struct ftrace_event_call *call, struct trace_seq *s);
enum print_line_t print_syscall_enter(struct trace_iterator *iter, int flags,
struct trace_event *event);
enum print_line_t print_syscall_exit(struct trace_iterator *iter, int flags,
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 0ebeb1d..23a384b 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -1821,7 +1821,7 @@ rb_add_time_stamp(struct ring_buffer_event *event, u64
delta)
}
/**
- * ring_buffer_update_event - update event type and data
+ * rb_update_event - update event type and data
* @event: the even to update
* @type: the type of event
* @length: the size of the event field in the ring buffer
@@ -2723,8 +2723,8 @@ EXPORT_SYMBOL_GPL(ring_buffer_discard_commit);
* and not the length of the event which would hold the header.
*/
int ring_buffer_write(struct ring_buffer *buffer,
- unsigned long length,
- void *data)
+ unsigned long length,
+ void *data)
{
struct ring_buffer_per_cpu *cpu_buffer;
struct ring_buffer_event *event;
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[tip:perf/core] tracing: Reset ring buffer when changing trace_clocks
Commit-ID: 60303ed3f4b9332b9aa9bc17c68bc174e7343e2d Gitweb: http://git.kernel.org/tip/60303ed3f4b9332b9aa9bc17c68bc174e7343e2d Author: David Sharp AuthorDate: Thu, 11 Oct 2012 16:27:52 -0700 Committer: Steven Rostedt CommitDate: Fri, 2 Nov 2012 10:21:47 -0400 tracing: Reset ring buffer when changing trace_clocks Because the "tsc" clock isn't in nanoseconds, the ring buffer must be reset when changing clocks so that incomparable timestamps don't end up in the same trace. Tested: Confirmed switching clocks resets the trace buffer. Google-Bug-Id: 6980623 Link: http://lkml.kernel.org/r/1349998076-15495-3-git-send-email-dhsh...@google.com Cc: Masami Hiramatsu Signed-off-by: David Sharp Signed-off-by: Steven Rostedt --- kernel/trace/trace.c |8 1 files changed, 8 insertions(+), 0 deletions(-) diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index 88111b0..6ed6013 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -4073,6 +4073,14 @@ static ssize_t tracing_clock_write(struct file *filp, const char __user *ubuf, if (max_tr.buffer) ring_buffer_set_clock(max_tr.buffer, trace_clocks[i].func); + /* +* New clock may not be consistent with the previous clock. +* Reset the buffer so that it doesn't have incomparable timestamps. +*/ + tracing_reset_online_cpus(&global_trace); + if (max_tr.buffer) + tracing_reset_online_cpus(&max_tr); + mutex_unlock(&trace_types_lock); *fpos += cnt; -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
