Re: [PATCH] tools lib api: respect CROSS_COMPILE for the linker
BTW: s/env/command line/ is true as well, i.e. running: `make CROSS_COMPILE=cross-` On Tue, Mar 22, 2016 at 11:22 AM, David Sharp <dhsh...@google.com> wrote: > So, note that without allow-override: > - The set default of "gcc" is not respected. > - Setting CC from the env does work. > - Setting CROSS_COMPILE from the env is not effective.
Re: [PATCH] tools lib api: respect CROSS_COMPILE for the linker
BTW: s/env/command line/ is true as well, i.e. running: `make CROSS_COMPILE=cross-` On Tue, Mar 22, 2016 at 11:22 AM, David Sharp wrote: > So, note that without allow-override: > - The set default of "gcc" is not respected. > - Setting CC from the env does work. > - Setting CROSS_COMPILE from the env is not effective.
Re: [PATCH] tools lib api: respect CROSS_COMPILE for the linker
On Tue, Mar 22, 2016 at 7:42 AM, Arnaldo Carvalho de Melo <a...@kernel.org> wrote: > Em Tue, Mar 22, 2016 at 08:50:42AM -0400, Steven Rostedt escreveu: >> On Tue, 22 Mar 2016 08:10:10 +0100 >> Jiri Olsa <jo...@redhat.com> wrote: >> >> > On Mon, Mar 21, 2016 at 05:40:30PM -0300, Arnaldo Carvalho de Melo wrote: >> > > Em Mon, Mar 21, 2016 at 09:08:52AM +0100, Jiri Olsa escreveu: >> > > > On Fri, Mar 18, 2016 at 02:38:52PM -0300, Arnaldo Carvalho de Melo >> > > > wrote: >> > > > > Em Fri, Mar 18, 2016 at 12:16:23PM -0500, Josh Poimboeuf escreveu: >> > > > > > So 'allow-override' would probably be a good option. >> > > >> > > > > Humm, my preference is to make tools/ look like the kernel, and the >> > > > > kernel doesn't use that allow-override thing, right? So perhaps add >> > > > > what >> > > > > is missing to make it look exactly like the kernel and then ditch >> > > > > this >> > > > > allow-override thing? >> > > >> > > > Steven explained his reason for allow-override in the comment above it, >> > > > please make sure the new solution follows that >> > > >> > > Sure, and I'm no make guru, but what puzzles me is why isn't this >> > > required in: >> > > >> > > [acme@jouet linux]$ grep -w ^CC Makefile >> > > CC= $(CROSS_COMPILE)gcc This works, but doesn't allow setting CC from env since it is unconditionally overwritten here. >> > > [acme@jouet linux]$ >> > >> > Steve has special requirements I guess ;-) CC-ed >> > >> >> I just copied what I had in trace-cmd. David Sharp is the one that >> added that code. >> >> Link: >> http://lkml.kernel.org/r/1299791491-1805-1-git-send-email-dhsh...@google.com > > David, so, what was the usecase for that? Something we can try to > reproduce so that we can check if the kernel solution covers your > specific case? > > - Arnaldo It was a very long time ago, so I don't fully remember my specific requirements at the time. However, I'm sure I was wanting to set just "CROSS_COMPILE" from the environment rather than all of CC, LD, AS, AR, etc, while still allowing the flexibility to set CC, etc from the environment. If you have just: CC ?= $(CROSS_COMPILE)gcc well, that line will never have any effect (not even the value of "gcc"), because CC is already set by default by make itself (to "cc"). Demo (gmail won't let me paste tabs, so you'll have to fix the tabs in the "all" rule): """ $ cat Makefile define allow-override $(if $(or $(findstring environment,$(origin $(1))),\ $(findstring command line,$(origin $(1,,\ $(eval $(1) = $(2))) endef CC ?= $(CROSS_COMPILE)gcc $(call allow-override,cross_CC,$(CROSS_COMPILE)gcc) all: @echo "CC: $(CC)" @echo "cross_CC: $(cross_CC)" $ make -f Makefile CC: cc cross_CC: gcc $ CC=other-gcc cross_CC=other-gcc make -f Makefile CC: other-gcc cross_CC: other-gcc $ CROSS_COMPILE=cross- make -f Makefile CC: cc cross_CC: cross-gcc """ So, note that without allow-override: - The set default of "gcc" is not respected. - Setting CC from the env does work. - Setting CROSS_COMPILE from the env is not effective. Hence the title of the patch and macro: "Makefiles suck". ;)
Re: [PATCH] tools lib api: respect CROSS_COMPILE for the linker
On Tue, Mar 22, 2016 at 7:42 AM, Arnaldo Carvalho de Melo wrote: > Em Tue, Mar 22, 2016 at 08:50:42AM -0400, Steven Rostedt escreveu: >> On Tue, 22 Mar 2016 08:10:10 +0100 >> Jiri Olsa wrote: >> >> > On Mon, Mar 21, 2016 at 05:40:30PM -0300, Arnaldo Carvalho de Melo wrote: >> > > Em Mon, Mar 21, 2016 at 09:08:52AM +0100, Jiri Olsa escreveu: >> > > > On Fri, Mar 18, 2016 at 02:38:52PM -0300, Arnaldo Carvalho de Melo >> > > > wrote: >> > > > > Em Fri, Mar 18, 2016 at 12:16:23PM -0500, Josh Poimboeuf escreveu: >> > > > > > So 'allow-override' would probably be a good option. >> > > >> > > > > Humm, my preference is to make tools/ look like the kernel, and the >> > > > > kernel doesn't use that allow-override thing, right? So perhaps add >> > > > > what >> > > > > is missing to make it look exactly like the kernel and then ditch >> > > > > this >> > > > > allow-override thing? >> > > >> > > > Steven explained his reason for allow-override in the comment above it, >> > > > please make sure the new solution follows that >> > > >> > > Sure, and I'm no make guru, but what puzzles me is why isn't this >> > > required in: >> > > >> > > [acme@jouet linux]$ grep -w ^CC Makefile >> > > CC= $(CROSS_COMPILE)gcc This works, but doesn't allow setting CC from env since it is unconditionally overwritten here. >> > > [acme@jouet linux]$ >> > >> > Steve has special requirements I guess ;-) CC-ed >> > >> >> I just copied what I had in trace-cmd. David Sharp is the one that >> added that code. >> >> Link: >> http://lkml.kernel.org/r/1299791491-1805-1-git-send-email-dhsh...@google.com > > David, so, what was the usecase for that? Something we can try to > reproduce so that we can check if the kernel solution covers your > specific case? > > - Arnaldo It was a very long time ago, so I don't fully remember my specific requirements at the time. However, I'm sure I was wanting to set just "CROSS_COMPILE" from the environment rather than all of CC, LD, AS, AR, etc, while still allowing the flexibility to set CC, etc from the environment. If you have just: CC ?= $(CROSS_COMPILE)gcc well, that line will never have any effect (not even the value of "gcc"), because CC is already set by default by make itself (to "cc"). Demo (gmail won't let me paste tabs, so you'll have to fix the tabs in the "all" rule): """ $ cat Makefile define allow-override $(if $(or $(findstring environment,$(origin $(1))),\ $(findstring command line,$(origin $(1,,\ $(eval $(1) = $(2))) endef CC ?= $(CROSS_COMPILE)gcc $(call allow-override,cross_CC,$(CROSS_COMPILE)gcc) all: @echo "CC: $(CC)" @echo "cross_CC: $(cross_CC)" $ make -f Makefile CC: cc cross_CC: gcc $ CC=other-gcc cross_CC=other-gcc make -f Makefile CC: other-gcc cross_CC: other-gcc $ CROSS_COMPILE=cross- make -f Makefile CC: cc cross_CC: cross-gcc """ So, note that without allow-override: - The set default of "gcc" is not respected. - Setting CC from the env does work. - Setting CROSS_COMPILE from the env is not effective. Hence the title of the patch and macro: "Makefiles suck". ;)
perf: TRACING_DATA header.size is invalid
We ran into an issue recently where a parser we have for perf.data could not handle TRACING_DATA events. It has a default behaviour of skipping event types it does not understand by using the header.size, since that seems to be how perf.data files are formatted. However, for TRACING_DATA events, header.size is set to sizeof(ev.tracing_data), even though all of the tracing data immediately follows the event. The simple fix would seem to be to set header.size to the size of the tracing data (plus sizeof ev.tracing_data). However, header.size is only 16 bits, and I imagine TRACING_DATA often exceeds UINT16_MAX, which is probably why the (u32) size was added outside the header. So I'm not sure we can fix this for real. But, I do have an idea to mitigate damage: set header.size to zero. This will cause one of a few things to happen to a parser that doesn't understand TRACING_DATA events: - Ideally: It will realize that a zero size is nonsense and bail. - It will try to advance by zero bytes and enter an infinite loop (this happened to our parser after it skipped around some bogus data and happened upon some data that had zero where size would be). I argue this is better than reading garbage. - I can also imagine an implementation that read()s only sizeof(header), then extends the read() by (header.size - sizeof(header)) additional bytes, and this would end up overflowing the unsigned values, and that could also cause bugs, but hopefully by reading to EOF. Any better ideas? A more difficult solution would be to split TRACING_DATA into UINT16_MAX-sized chunks, but would this needlessly break older readers of data produced by newer perf, even if they already know how to read TRACING_DATA correctly? Thanks, d# -- 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/
perf: TRACING_DATA header.size is invalid
We ran into an issue recently where a parser we have for perf.data could not handle TRACING_DATA events. It has a default behaviour of skipping event types it does not understand by using the header.size, since that seems to be how perf.data files are formatted. However, for TRACING_DATA events, header.size is set to sizeof(ev.tracing_data), even though all of the tracing data immediately follows the event. The simple fix would seem to be to set header.size to the size of the tracing data (plus sizeof ev.tracing_data). However, header.size is only 16 bits, and I imagine TRACING_DATA often exceeds UINT16_MAX, which is probably why the (u32) size was added outside the header. So I'm not sure we can fix this for real. But, I do have an idea to mitigate damage: set header.size to zero. This will cause one of a few things to happen to a parser that doesn't understand TRACING_DATA events: - Ideally: It will realize that a zero size is nonsense and bail. - It will try to advance by zero bytes and enter an infinite loop (this happened to our parser after it skipped around some bogus data and happened upon some data that had zero where size would be). I argue this is better than reading garbage. - I can also imagine an implementation that read()s only sizeof(header), then extends the read() by (header.size - sizeof(header)) additional bytes, and this would end up overflowing the unsigned values, and that could also cause bugs, but hopefully by reading to EOF. Any better ideas? A more difficult solution would be to split TRACING_DATA into UINT16_MAX-sized chunks, but would this needlessly break older readers of data produced by newer perf, even if they already know how to read TRACING_DATA correctly? Thanks, d# -- 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/
Re: [PATCH] tracing: a few fields of struct trace_iterator are zeroed by mistake
On Fri, Aug 2, 2013 at 10:16 AM, Andrew Vagin wrote:
> tracing_read_pipe zeros all fields bellow "seq". The declaration contains
> a comment about that, but it doesn't help.
>
> The first field is "snapshot", it's true when current open file is
> snapshot. Looks obvious, that it should not be zeroed.
>
> The second field is "started". It was converted from cpumask_t to
> cpumask_var_t (v2.6.28-4983-g4462344) or by another words it was
> converted from cpumask to pointer on cpumask.
>
> Currently the reference on "started" memory is lost after the first read
> from tracing_read_pipe and a proper object will never be freed.
>
> The "started" is never dereferenced for trace_pipe, because trace_pipe
> can't have the TRACE_FILE_ANNOTATE options (why?).
>
> Cc: Steven Rostedt
> Cc: Frederic Weisbecker
> Cc: Ingo Molnar
> Cc: David Sharp
> Cc: Hiraku Toyooka
> Cc: Arjan van de Ven
> Cc: Masami Hiramatsu
>
> Signed-off-by: Andrew Vagin
> ---
> include/linux/ftrace_event.h | 10 ++
> kernel/trace/trace.c |1 +
> 2 files changed, 7 insertions(+), 4 deletions(-)
>
> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
> index 4372658..44cdc11 100644
> --- a/include/linux/ftrace_event.h
> +++ b/include/linux/ftrace_event.h
> @@ -78,6 +78,11 @@ struct trace_iterator {
> /* trace_seq for __print_flags() and __print_symbolic() etc. */
> struct trace_seqtmp_seq;
>
> + cpumask_var_t started;
> +
> + /* it's true when current open file is snapshot */
> + boolsnapshot;
> +
> /* The below is zeroed out in pipe_read */
> struct trace_seqseq;
> struct trace_entry *ent;
> @@ -90,10 +95,7 @@ struct trace_iterator {
> loff_t pos;
> longidx;
>
> - cpumask_var_t started;
> -
> - /* it's true when current open file is snapshot */
> - boolsnapshot;
> + /* All new field here will be zeroed out in pipe_read */
Wow. That is a terrible hack. Thanks for noticing it.
If I may suggest a way better idea: put these zeroed-in-pipe_read
members in an embedded anonymous structure, and zero the structure in
pipe_read.
> };
>
> enum trace_iter_flags {
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index 0cd500b..897f553 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -4166,6 +4166,7 @@ waitagain:
> memset(>seq, 0,
>sizeof(struct trace_iterator) -
>offsetof(struct trace_iterator, seq));
> + cpumask_clear(iter->started);
> iter->pos = -1;
>
> trace_event_read_lock();
> --
> 1.7.1
>
--
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/
Re: [PATCH] tracing: a few fields of struct trace_iterator are zeroed by mistake
On Fri, Aug 2, 2013 at 10:16 AM, Andrew Vagin ava...@openvz.org wrote:
tracing_read_pipe zeros all fields bellow seq. The declaration contains
a comment about that, but it doesn't help.
The first field is snapshot, it's true when current open file is
snapshot. Looks obvious, that it should not be zeroed.
The second field is started. It was converted from cpumask_t to
cpumask_var_t (v2.6.28-4983-g4462344) or by another words it was
converted from cpumask to pointer on cpumask.
Currently the reference on started memory is lost after the first read
from tracing_read_pipe and a proper object will never be freed.
The started is never dereferenced for trace_pipe, because trace_pipe
can't have the TRACE_FILE_ANNOTATE options (why?).
Cc: Steven Rostedt rost...@goodmis.org
Cc: Frederic Weisbecker fweis...@gmail.com
Cc: Ingo Molnar mi...@redhat.com
Cc: David Sharp dhsh...@google.com
Cc: Hiraku Toyooka hiraku.toyooka...@hitachi.com
Cc: Arjan van de Ven ar...@linux.intel.com
Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com
Signed-off-by: Andrew Vagin ava...@openvz.org
---
include/linux/ftrace_event.h | 10 ++
kernel/trace/trace.c |1 +
2 files changed, 7 insertions(+), 4 deletions(-)
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 4372658..44cdc11 100644
--- a/include/linux/ftrace_event.h
+++ b/include/linux/ftrace_event.h
@@ -78,6 +78,11 @@ struct trace_iterator {
/* trace_seq for __print_flags() and __print_symbolic() etc. */
struct trace_seqtmp_seq;
+ cpumask_var_t started;
+
+ /* it's true when current open file is snapshot */
+ boolsnapshot;
+
/* The below is zeroed out in pipe_read */
struct trace_seqseq;
struct trace_entry *ent;
@@ -90,10 +95,7 @@ struct trace_iterator {
loff_t pos;
longidx;
- cpumask_var_t started;
-
- /* it's true when current open file is snapshot */
- boolsnapshot;
+ /* All new field here will be zeroed out in pipe_read */
Wow. That is a terrible hack. Thanks for noticing it.
If I may suggest a way better idea: put these zeroed-in-pipe_read
members in an embedded anonymous structure, and zero the structure in
pipe_read.
};
enum trace_iter_flags {
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 0cd500b..897f553 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4166,6 +4166,7 @@ waitagain:
memset(iter-seq, 0,
sizeof(struct trace_iterator) -
offsetof(struct trace_iterator, seq));
+ cpumask_clear(iter-started);
iter-pos = -1;
trace_event_read_lock();
--
1.7.1
--
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/
Re: [PATCH] tracing: Fix file mode of free_buffer
On Tue, May 28, 2013 at 12:34 PM, Vaibhav Nagarnaik
wrote:
> On Sun, May 26, 2013 at 1:52 AM, Wang YanQing wrote:
>> Commit 4f271a2a60c748599b30bb4dafff30d770439b96
>> (tracing: Add a proc file to stop tracing and free buffer)
>> implement a method to free up ring buffer in kernel memory
>> in the release code path of free_buffer's fd.
>>
>> Then we don't need read/write support for free_buffer,
>> indeed we just have a dummy write fop, and don't implement read fop.
>>
>> So the 0200 is more reasonable file mode for free_buffer than
>> the current file mode 0644.
>>
>> Signed-off-by: Wang YanQing
>
> Acked-by: Vaibhav Nagarnaik
Acked-by: David Sharp
>
> Vaibhav Nagarnaik
>
>
>> ---
>> kernel/trace/trace.c | 2 +-
>> 1 file changed, 1 insertion(+), 1 deletion(-)
>>
>> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
>> index ae6fa2d..02d9875 100644
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -5927,7 +5927,7 @@ init_tracer_debugfs(struct trace_array *tr, struct
>> dentry *d_tracer)
>> trace_create_file("buffer_total_size_kb", 0444, d_tracer,
>> tr, _total_entries_fops);
>>
>> - trace_create_file("free_buffer", 0644, d_tracer,
>> + trace_create_file("free_buffer", 0200, d_tracer,
>> tr, _free_buffer_fops);
>>
>> trace_create_file("trace_marker", 0220, d_tracer,
>> --
>> 1.7.12.4.dirty
> --
> 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/
--
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/
Re: [PATCH] tracing: Fix file mode of free_buffer
On Tue, May 28, 2013 at 12:34 PM, Vaibhav Nagarnaik vnagarn...@google.com wrote: On Sun, May 26, 2013 at 1:52 AM, Wang YanQing udkni...@gmail.com wrote: Commit 4f271a2a60c748599b30bb4dafff30d770439b96 (tracing: Add a proc file to stop tracing and free buffer) implement a method to free up ring buffer in kernel memory in the release code path of free_buffer's fd. Then we don't need read/write support for free_buffer, indeed we just have a dummy write fop, and don't implement read fop. So the 0200 is more reasonable file mode for free_buffer than the current file mode 0644. Signed-off-by: Wang YanQing udkni...@gmail.com Acked-by: Vaibhav Nagarnaik vnagarn...@google.com Acked-by: David Sharp dhsh...@google.com Vaibhav Nagarnaik --- kernel/trace/trace.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c index ae6fa2d..02d9875 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -5927,7 +5927,7 @@ init_tracer_debugfs(struct trace_array *tr, struct dentry *d_tracer) trace_create_file(buffer_total_size_kb, 0444, d_tracer, tr, tracing_total_entries_fops); - trace_create_file(free_buffer, 0644, d_tracer, + trace_create_file(free_buffer, 0200, d_tracer, tr, tracing_free_buffer_fops); trace_create_file(trace_marker, 0220, d_tracer, -- 1.7.12.4.dirty -- 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/ -- 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/
Re: [for-next][PATCH 0/8] tracing: Addition of multiple buffers
On Wed, Feb 27, 2013 at 9:22 AM, Steven Rostedt wrote: > With this patch set, a new directory is created in the debug/tracing > directory called "instances". Here you can mkdir/rmdir a new directory > that will contain some of the files in the debug/tracing directory. > Note, this is not totally finished, but it's at a point were it is > functional and useful. > > To add mkdir/rmdir in debugfs, as debugfs does not support these operations, Is there some reason not to extend debugfs to support mkdir/rmdir? > I had to have the instances' inode use its own inode_operations and add a > mkdir and rmdir method. As the instances directory can not be renamed > or removed, or modified in any other way, it has the inode mutex released > in order to call back to create or remove the debugfs directories. > It has its own mutex to protect against multiple instances of this, > and I've run many stress tests to make sure it can't crash. I haven't > found were it can. The alternative is to have a "new" and "free" file > to create and remove directories and it will basically do the exact > same thing that the mkdir/rmdir does now, with the exact same protection. > I do eventually want to make a tracefs, but that requires a lot of > design planning and wont be in the near future (too many other things > to do). -- 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/
Re: [for-next][PATCH 0/8] tracing: Addition of multiple buffers
On Wed, Feb 27, 2013 at 9:22 AM, Steven Rostedt rost...@goodmis.org wrote: With this patch set, a new directory is created in the debug/tracing directory called instances. Here you can mkdir/rmdir a new directory that will contain some of the files in the debug/tracing directory. Note, this is not totally finished, but it's at a point were it is functional and useful. To add mkdir/rmdir in debugfs, as debugfs does not support these operations, Is there some reason not to extend debugfs to support mkdir/rmdir? I had to have the instances' inode use its own inode_operations and add a mkdir and rmdir method. As the instances directory can not be renamed or removed, or modified in any other way, it has the inode mutex released in order to call back to create or remove the debugfs directories. It has its own mutex to protect against multiple instances of this, and I've run many stress tests to make sure it can't crash. I haven't found were it can. The alternative is to have a new and free file to create and remove directories and it will basically do the exact same thing that the mkdir/rmdir does now, with the exact same protection. I do eventually want to make a tracefs, but that requires a lot of design planning and wont be in the near future (too many other things to do). -- 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: 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 */
tracin
[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
[tip:perf/core] tracing,x86: Add a TSC trace_clock
Commit-ID: 8cbd9cc6254065c97c4bac42daa55ba1abe73a8e Gitweb: http://git.kernel.org/tip/8cbd9cc6254065c97c4bac42daa55ba1abe73a8e Author: David Sharp dhsh...@google.com AuthorDate: Tue, 13 Nov 2012 12:18:21 -0800 Committer: Steven Rostedt rost...@goodmis.org 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 mi...@kernel.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com Cc: Ingo Molnar mi...@kernel.org Cc: Thomas Gleixner t...@linutronix.de Cc: H. Peter Anvin h...@linux.intel.com Signed-off-by: David Sharp dhsh...@google.com Signed-off-by: Steven Rostedt rost...@goodmis.org --- 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
[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 dhsh...@google.com
AuthorDate: Tue, 13 Nov 2012 12:18:22 -0800
Committer: Steven Rostedt rost...@goodmis.org
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
idle-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
idle-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
idle-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
idle-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 masami.hiramatsu...@hitachi.com
Signed-off-by: David Sharp dhsh...@google.com
Signed-off-by: Steven Rostedt rost...@goodmis.org
---
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
Re: [PATCH 4/4] kernelshark: Full-height cursor and mark lines
On Wed, Nov 14, 2012 at 6:27 PM, Steven Rostedt wrote:
> On Wed, 2012-11-14 at 17:51 -0800, David Sharp wrote:
>> "width" and "height" were swapped, causing the vertical marker and cursor
>> lines
>> to be drawn with the wrong height.
>
> Is this the fix to the strange "mark bottom stays around" bug? It's been
> on my TODO list for a long time to fix that. ;-)
That's not how I would have described the bug, but maybe it's the
same. What I was seeing was the marks not extending all the way to the
bottom of all the plot area when scrolled down. I assume it would only
manifest that way when the plot is taller than it is wide (eg, tons of
thread plots and fully zoomed out). In the reverse situation, it would
be telling gdk to draw outside the bounds of the widget, which might
do something weird, although I would hope it would just draw what it
could and refuse to draw outside.
>
> -- Steve
>
>>
>> Signed-off-by: David Sharp
>> ---
>> trace-graph.c |8
>> 1 files changed, 4 insertions(+), 4 deletions(-)
>>
>> diff --git a/trace-graph.c b/trace-graph.c
>> index 6f72350..60e5241 100644
>> --- a/trace-graph.c
>> +++ b/trace-graph.c
>> @@ -380,7 +380,7 @@ static void draw_cursor(struct graph_info *ginfo)
>> x = convert_time_to_x(ginfo, ginfo->cursor);
>>
>> gdk_draw_line(ginfo->draw->window, ginfo->draw->style->mid_gc[3],
>> - x, 0, x, ginfo->draw->allocation.width);
>> + x, 0, x, ginfo->draw->allocation.height);
>> }
>>
>> static void draw_marka(struct graph_info *ginfo)
>> @@ -392,7 +392,7 @@ static void draw_marka(struct graph_info *ginfo)
>>
>> x = convert_time_to_x(ginfo, ginfo->marka_time);
>> gdk_draw_line(ginfo->draw->window, green,
>> - x, 0, x, ginfo->draw->allocation.width);
>> + x, 0, x, ginfo->draw->allocation.height);
>> }
>>
>> static void draw_markb(struct graph_info *ginfo)
>> @@ -404,7 +404,7 @@ static void draw_markb(struct graph_info *ginfo)
>>
>> x = convert_time_to_x(ginfo, ginfo->markb_time);
>> gdk_draw_line(ginfo->draw->window, red,
>> - x, 0, x, ginfo->draw->allocation.width);
>> + x, 0, x, ginfo->draw->allocation.height);
>> }
>>
>> static void update_with_backend(struct graph_info *ginfo,
>> @@ -434,7 +434,7 @@ static void
>> draw_line(GtkWidget *widget, gdouble x, struct graph_info *ginfo)
>> {
>> gdk_draw_line(widget->window, widget->style->black_gc,
>> - x, 0, x, widget->allocation.width);
>> + x, 0, x, widget->allocation.height);
>> }
>>
>> static void clear_line(struct graph_info *ginfo, gint x)
>
>
--
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/
Re: [PATCH 4/4] kernelshark: Full-height cursor and mark lines
On Wed, Nov 14, 2012 at 6:27 PM, Steven Rostedt rost...@goodmis.org wrote:
On Wed, 2012-11-14 at 17:51 -0800, David Sharp wrote:
width and height were swapped, causing the vertical marker and cursor
lines
to be drawn with the wrong height.
Is this the fix to the strange mark bottom stays around bug? It's been
on my TODO list for a long time to fix that. ;-)
That's not how I would have described the bug, but maybe it's the
same. What I was seeing was the marks not extending all the way to the
bottom of all the plot area when scrolled down. I assume it would only
manifest that way when the plot is taller than it is wide (eg, tons of
thread plots and fully zoomed out). In the reverse situation, it would
be telling gdk to draw outside the bounds of the widget, which might
do something weird, although I would hope it would just draw what it
could and refuse to draw outside.
-- Steve
Signed-off-by: David Sharp dhsh...@google.com
---
trace-graph.c |8
1 files changed, 4 insertions(+), 4 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 6f72350..60e5241 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -380,7 +380,7 @@ static void draw_cursor(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-cursor);
gdk_draw_line(ginfo-draw-window, ginfo-draw-style-mid_gc[3],
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void draw_marka(struct graph_info *ginfo)
@@ -392,7 +392,7 @@ static void draw_marka(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-marka_time);
gdk_draw_line(ginfo-draw-window, green,
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void draw_markb(struct graph_info *ginfo)
@@ -404,7 +404,7 @@ static void draw_markb(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-markb_time);
gdk_draw_line(ginfo-draw-window, red,
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void update_with_backend(struct graph_info *ginfo,
@@ -434,7 +434,7 @@ static void
draw_line(GtkWidget *widget, gdouble x, struct graph_info *ginfo)
{
gdk_draw_line(widget-window, widget-style-black_gc,
- x, 0, x, widget-allocation.width);
+ x, 0, x, widget-allocation.height);
}
static void clear_line(struct graph_info *ginfo, gint x)
--
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/
[PATCH 4/4] kernelshark: Full-height cursor and mark lines
"width" and "height" were swapped, causing the vertical marker and cursor lines
to be drawn with the wrong height.
Signed-off-by: David Sharp
---
trace-graph.c |8
1 files changed, 4 insertions(+), 4 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 6f72350..60e5241 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -380,7 +380,7 @@ static void draw_cursor(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo->cursor);
gdk_draw_line(ginfo->draw->window, ginfo->draw->style->mid_gc[3],
- x, 0, x, ginfo->draw->allocation.width);
+ x, 0, x, ginfo->draw->allocation.height);
}
static void draw_marka(struct graph_info *ginfo)
@@ -392,7 +392,7 @@ static void draw_marka(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo->marka_time);
gdk_draw_line(ginfo->draw->window, green,
- x, 0, x, ginfo->draw->allocation.width);
+ x, 0, x, ginfo->draw->allocation.height);
}
static void draw_markb(struct graph_info *ginfo)
@@ -404,7 +404,7 @@ static void draw_markb(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo->markb_time);
gdk_draw_line(ginfo->draw->window, red,
- x, 0, x, ginfo->draw->allocation.width);
+ x, 0, x, ginfo->draw->allocation.height);
}
static void update_with_backend(struct graph_info *ginfo,
@@ -434,7 +434,7 @@ static void
draw_line(GtkWidget *widget, gdouble x, struct graph_info *ginfo)
{
gdk_draw_line(widget->window, widget->style->black_gc,
- x, 0, x, widget->allocation.width);
+ x, 0, x, widget->allocation.height);
}
static void clear_line(struct graph_info *ginfo, gint x)
--
1.7.7.3
--
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/
Re: [PATCH 1/4] kernelshark: Fix bug with Plot CPU filtering
sorry for the dups... typoed Steve's domain. On Wed, Nov 14, 2012 at 5:51 PM, David Sharp wrote: > From: Venkatesh Pallipadi > > Plot CPU filtering in kernelshark has the following bug: > 1) Deselect CPU A from Plot CPU list > 2) Plot gets updated with no CPU A > 3) Deselect CPU B > 4) Plot continues to have CPU B > > This is due to a bug in graph_plot_cpus_update_callback(), > which seems to be checking old_all_cpus != new_all_cpus before doing any > update. This condition is true on 1, but false on 2. > Removing that check fixes the problem. > > Tested: > Above sequence now does expected filtering. > > Google-bug-id: 4258610 > Signed-off-by: Venkatesh Pallipadi > Signed-off-by: David Sharp -- 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/
[PATCH 1/4] kernelshark: Fix bug with Plot CPU filtering
From: Venkatesh Pallipadi
Plot CPU filtering in kernelshark has the following bug:
1) Deselect CPU A from Plot CPU list
2) Plot gets updated with no CPU A
3) Deselect CPU B
4) Plot continues to have CPU B
This is due to a bug in graph_plot_cpus_update_callback(),
which seems to be checking old_all_cpus != new_all_cpus before doing any
update. This condition is true on 1, but false on 2.
Removing that check fixes the problem.
Tested:
Above sequence now does expected filtering.
Google-bug-id: 4258610
Signed-off-by: Venkatesh Pallipadi
Signed-off-by: David Sharp
---
trace-plot-cpu.c |5 ++---
1 files changed, 2 insertions(+), 3 deletions(-)
diff --git a/trace-plot-cpu.c b/trace-plot-cpu.c
index 630d6c2..bb767d3 100644
--- a/trace-plot-cpu.c
+++ b/trace-plot-cpu.c
@@ -498,9 +498,8 @@ void graph_plot_cpus_update_callback(gboolean accept,
/* Get the current status */
graph_plot_cpus_plotted(ginfo, _all_cpus, _cpu_mask);
- if (old_all_cpus == all_cpus ||
- (selected_cpu_mask &&
-cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo->cpus))) {
+ if (selected_cpu_mask &&
+cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo->cpus)) {
/* Nothing to do */
g_free(old_cpu_mask);
return;
--
1.7.7.3
--
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/
[PATCH 3/4] kernel-shark: Don't check for system name for sched events
From: Vaibhav Nagarnaik
The sched tracepoint names are unique and so there is no need to check
for the subsystem name while looking up the event ID.
This helps kernel shark display the graphs correctly for trace.dat files
generated from trace collection mechanisms that don't record the subsystem.
Google-Bug-Id: 6333917
Signed-off-by: Vaibhav Nagarnaik
Signed-off-by: David Sharp
---
trace-graph.c |6 +++---
1 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 4d81219..6f72350 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -1016,7 +1016,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
found = FALSE;
event = pevent_find_event_by_name(ginfo->pevent,
- "sched", "sched_wakeup");
+ NULL, "sched_wakeup");
if (event) {
found = TRUE;
ginfo->event_wakeup_id = event->id;
@@ -1026,7 +1026,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
event = pevent_find_event_by_name(ginfo->pevent,
- "sched", "sched_wakeup_new");
+ NULL, "sched_wakeup_new");
if (event) {
found = TRUE;
ginfo->event_wakeup_new_id = event->id;
@@ -1086,7 +1086,7 @@ int trace_graph_check_sched_switch(struct graph_info
*ginfo,
if (ginfo->event_sched_switch_id < 0) {
event = pevent_find_event_by_name(ginfo->pevent,
- "sched", "sched_switch");
+ NULL, "sched_switch");
if (!event)
return 0;
--
1.7.7.3
--
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/
[PATCH 4/4] kernelshark: Full-height cursor and mark lines
"width" and "height" were swapped, causing the vertical marker and cursor lines
to be drawn with the wrong height.
Signed-off-by: David Sharp
---
trace-graph.c |8
1 files changed, 4 insertions(+), 4 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 6f72350..60e5241 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -380,7 +380,7 @@ static void draw_cursor(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo->cursor);
gdk_draw_line(ginfo->draw->window, ginfo->draw->style->mid_gc[3],
- x, 0, x, ginfo->draw->allocation.width);
+ x, 0, x, ginfo->draw->allocation.height);
}
static void draw_marka(struct graph_info *ginfo)
@@ -392,7 +392,7 @@ static void draw_marka(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo->marka_time);
gdk_draw_line(ginfo->draw->window, green,
- x, 0, x, ginfo->draw->allocation.width);
+ x, 0, x, ginfo->draw->allocation.height);
}
static void draw_markb(struct graph_info *ginfo)
@@ -404,7 +404,7 @@ static void draw_markb(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo->markb_time);
gdk_draw_line(ginfo->draw->window, red,
- x, 0, x, ginfo->draw->allocation.width);
+ x, 0, x, ginfo->draw->allocation.height);
}
static void update_with_backend(struct graph_info *ginfo,
@@ -434,7 +434,7 @@ static void
draw_line(GtkWidget *widget, gdouble x, struct graph_info *ginfo)
{
gdk_draw_line(widget->window, widget->style->black_gc,
- x, 0, x, widget->allocation.width);
+ x, 0, x, widget->allocation.height);
}
static void clear_line(struct graph_info *ginfo, gint x)
--
1.7.7.3
--
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/
[PATCH 2/4] kernel-shark: Allow unsetting of all CPUs in filter
From: Vaibhav Nagarnaik
The button "All CPUs" in CPU filter dialog allows setting of all CPUs
but doesn't clear CPUs when it is unchecked. Make sure that when the
"All CPUs" button is unchecked, all the CPUs get unchecked.
Tested: In kernelshark, go to Filter->list CPUs and uncheck "All CPUs"
button. All the CPUs should be unchecked at that point.
Signed-off-by: Vaibhav Nagarnaik
Signed-off-by: David Sharp
---
trace-filter.c | 10 --
1 files changed, 4 insertions(+), 6 deletions(-)
diff --git a/trace-filter.c b/trace-filter.c
index c657a18..89cf032 100644
--- a/trace-filter.c
+++ b/trace-filter.c
@@ -1723,12 +1723,10 @@ void cpu_toggle(gpointer data, GtkWidget *widget)
if (strcmp(label, CPU_ALL_CPUS_STR) == 0) {
cpu_helper->allcpus = active;
- if (active) {
- /* enable all toggles */
- for (cpu = 0; cpu < cpu_helper->cpus; cpu++)
-
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper->buttons[cpu]),
-TRUE);
- }
+ /* enable/disable all toggles */
+ for (cpu = 0; cpu < cpu_helper->cpus; cpu++)
+
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper->buttons[cpu]),
+active ? TRUE : FALSE);
return;
}
--
1.7.7.3
--
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/
[PATCH 3/4] kernel-shark: Don't check for system name for sched events
From: Vaibhav Nagarnaik
The sched tracepoint names are unique and so there is no need to check
for the subsystem name while looking up the event ID.
This helps kernel shark display the graphs correctly for trace.dat files
generated from trace collection mechanisms that don't record the subsystem.
Google-Bug-Id: 6333917
Signed-off-by: Vaibhav Nagarnaik
Signed-off-by: David Sharp
---
trace-graph.c |6 +++---
1 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 4d81219..6f72350 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -1016,7 +1016,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
found = FALSE;
event = pevent_find_event_by_name(ginfo->pevent,
- "sched", "sched_wakeup");
+ NULL, "sched_wakeup");
if (event) {
found = TRUE;
ginfo->event_wakeup_id = event->id;
@@ -1026,7 +1026,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
event = pevent_find_event_by_name(ginfo->pevent,
- "sched", "sched_wakeup_new");
+ NULL, "sched_wakeup_new");
if (event) {
found = TRUE;
ginfo->event_wakeup_new_id = event->id;
@@ -1086,7 +1086,7 @@ int trace_graph_check_sched_switch(struct graph_info
*ginfo,
if (ginfo->event_sched_switch_id < 0) {
event = pevent_find_event_by_name(ginfo->pevent,
- "sched", "sched_switch");
+ NULL, "sched_switch");
if (!event)
return 0;
--
1.7.7.3
--
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/
[PATCH 1/4] kernelshark: Fix bug with Plot CPU filtering
From: Venkatesh Pallipadi
Plot CPU filtering in kernelshark has the following bug:
1) Deselect CPU A from Plot CPU list
2) Plot gets updated with no CPU A
3) Deselect CPU B
4) Plot continues to have CPU B
This is due to a bug in graph_plot_cpus_update_callback(),
which seems to be checking old_all_cpus != new_all_cpus before doing any
update. This condition is true on 1, but false on 2.
Removing that check fixes the problem.
Tested:
Above sequence now does expected filtering.
Google-bug-id: 4258610
Signed-off-by: Venkatesh Pallipadi
Signed-off-by: David Sharp
---
trace-plot-cpu.c |5 ++---
1 files changed, 2 insertions(+), 3 deletions(-)
diff --git a/trace-plot-cpu.c b/trace-plot-cpu.c
index 630d6c2..bb767d3 100644
--- a/trace-plot-cpu.c
+++ b/trace-plot-cpu.c
@@ -498,9 +498,8 @@ void graph_plot_cpus_update_callback(gboolean accept,
/* Get the current status */
graph_plot_cpus_plotted(ginfo, _all_cpus, _cpu_mask);
- if (old_all_cpus == all_cpus ||
- (selected_cpu_mask &&
-cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo->cpus))) {
+ if (selected_cpu_mask &&
+cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo->cpus)) {
/* Nothing to do */
g_free(old_cpu_mask);
return;
--
1.7.7.3
--
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/
[PATCH 2/4] kernel-shark: Allow unsetting of all CPUs in filter
From: Vaibhav Nagarnaik
The button "All CPUs" in CPU filter dialog allows setting of all CPUs
but doesn't clear CPUs when it is unchecked. Make sure that when the
"All CPUs" button is unchecked, all the CPUs get unchecked.
Tested: In kernelshark, go to Filter->list CPUs and uncheck "All CPUs"
button. All the CPUs should be unchecked at that point.
Signed-off-by: Vaibhav Nagarnaik
Signed-off-by: David Sharp
---
trace-filter.c | 10 --
1 files changed, 4 insertions(+), 6 deletions(-)
diff --git a/trace-filter.c b/trace-filter.c
index c657a18..89cf032 100644
--- a/trace-filter.c
+++ b/trace-filter.c
@@ -1723,12 +1723,10 @@ void cpu_toggle(gpointer data, GtkWidget *widget)
if (strcmp(label, CPU_ALL_CPUS_STR) == 0) {
cpu_helper->allcpus = active;
- if (active) {
- /* enable all toggles */
- for (cpu = 0; cpu < cpu_helper->cpus; cpu++)
-
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper->buttons[cpu]),
-TRUE);
- }
+ /* enable/disable all toggles */
+ for (cpu = 0; cpu < cpu_helper->cpus; cpu++)
+
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper->buttons[cpu]),
+active ? TRUE : FALSE);
return;
}
--
1.7.7.3
--
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/
[PATCH 2/4] kernel-shark: Allow unsetting of all CPUs in filter
From: Vaibhav Nagarnaik vnagarn...@google.com
The button All CPUs in CPU filter dialog allows setting of all CPUs
but doesn't clear CPUs when it is unchecked. Make sure that when the
All CPUs button is unchecked, all the CPUs get unchecked.
Tested: In kernelshark, go to Filter-list CPUs and uncheck All CPUs
button. All the CPUs should be unchecked at that point.
Signed-off-by: Vaibhav Nagarnaik vnagarn...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
trace-filter.c | 10 --
1 files changed, 4 insertions(+), 6 deletions(-)
diff --git a/trace-filter.c b/trace-filter.c
index c657a18..89cf032 100644
--- a/trace-filter.c
+++ b/trace-filter.c
@@ -1723,12 +1723,10 @@ void cpu_toggle(gpointer data, GtkWidget *widget)
if (strcmp(label, CPU_ALL_CPUS_STR) == 0) {
cpu_helper-allcpus = active;
- if (active) {
- /* enable all toggles */
- for (cpu = 0; cpu cpu_helper-cpus; cpu++)
-
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper-buttons[cpu]),
-TRUE);
- }
+ /* enable/disable all toggles */
+ for (cpu = 0; cpu cpu_helper-cpus; cpu++)
+
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper-buttons[cpu]),
+active ? TRUE : FALSE);
return;
}
--
1.7.7.3
--
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/
[PATCH 1/4] kernelshark: Fix bug with Plot CPU filtering
From: Venkatesh Pallipadi ve...@google.com
Plot CPU filtering in kernelshark has the following bug:
1) Deselect CPU A from Plot CPU list
2) Plot gets updated with no CPU A
3) Deselect CPU B
4) Plot continues to have CPU B
This is due to a bug in graph_plot_cpus_update_callback(),
which seems to be checking old_all_cpus != new_all_cpus before doing any
update. This condition is true on 1, but false on 2.
Removing that check fixes the problem.
Tested:
Above sequence now does expected filtering.
Google-bug-id: 4258610
Signed-off-by: Venkatesh Pallipadi ve...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
trace-plot-cpu.c |5 ++---
1 files changed, 2 insertions(+), 3 deletions(-)
diff --git a/trace-plot-cpu.c b/trace-plot-cpu.c
index 630d6c2..bb767d3 100644
--- a/trace-plot-cpu.c
+++ b/trace-plot-cpu.c
@@ -498,9 +498,8 @@ void graph_plot_cpus_update_callback(gboolean accept,
/* Get the current status */
graph_plot_cpus_plotted(ginfo, old_all_cpus, old_cpu_mask);
- if (old_all_cpus == all_cpus ||
- (selected_cpu_mask
-cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo-cpus))) {
+ if (selected_cpu_mask
+cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo-cpus)) {
/* Nothing to do */
g_free(old_cpu_mask);
return;
--
1.7.7.3
--
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/
[PATCH 3/4] kernel-shark: Don't check for system name for sched events
From: Vaibhav Nagarnaik vnagarn...@google.com
The sched tracepoint names are unique and so there is no need to check
for the subsystem name while looking up the event ID.
This helps kernel shark display the graphs correctly for trace.dat files
generated from trace collection mechanisms that don't record the subsystem.
Google-Bug-Id: 6333917
Signed-off-by: Vaibhav Nagarnaik vnagarn...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
trace-graph.c |6 +++---
1 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 4d81219..6f72350 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -1016,7 +1016,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
found = FALSE;
event = pevent_find_event_by_name(ginfo-pevent,
- sched, sched_wakeup);
+ NULL, sched_wakeup);
if (event) {
found = TRUE;
ginfo-event_wakeup_id = event-id;
@@ -1026,7 +1026,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
event = pevent_find_event_by_name(ginfo-pevent,
- sched, sched_wakeup_new);
+ NULL, sched_wakeup_new);
if (event) {
found = TRUE;
ginfo-event_wakeup_new_id = event-id;
@@ -1086,7 +1086,7 @@ int trace_graph_check_sched_switch(struct graph_info
*ginfo,
if (ginfo-event_sched_switch_id 0) {
event = pevent_find_event_by_name(ginfo-pevent,
- sched, sched_switch);
+ NULL, sched_switch);
if (!event)
return 0;
--
1.7.7.3
--
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/
[PATCH 2/4] kernel-shark: Allow unsetting of all CPUs in filter
From: Vaibhav Nagarnaik vnagarn...@google.com
The button All CPUs in CPU filter dialog allows setting of all CPUs
but doesn't clear CPUs when it is unchecked. Make sure that when the
All CPUs button is unchecked, all the CPUs get unchecked.
Tested: In kernelshark, go to Filter-list CPUs and uncheck All CPUs
button. All the CPUs should be unchecked at that point.
Signed-off-by: Vaibhav Nagarnaik vnagarn...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
trace-filter.c | 10 --
1 files changed, 4 insertions(+), 6 deletions(-)
diff --git a/trace-filter.c b/trace-filter.c
index c657a18..89cf032 100644
--- a/trace-filter.c
+++ b/trace-filter.c
@@ -1723,12 +1723,10 @@ void cpu_toggle(gpointer data, GtkWidget *widget)
if (strcmp(label, CPU_ALL_CPUS_STR) == 0) {
cpu_helper-allcpus = active;
- if (active) {
- /* enable all toggles */
- for (cpu = 0; cpu cpu_helper-cpus; cpu++)
-
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper-buttons[cpu]),
-TRUE);
- }
+ /* enable/disable all toggles */
+ for (cpu = 0; cpu cpu_helper-cpus; cpu++)
+
gtk_toggle_button_set_active(GTK_TOGGLE_BUTTON(cpu_helper-buttons[cpu]),
+active ? TRUE : FALSE);
return;
}
--
1.7.7.3
--
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/
[PATCH 4/4] kernelshark: Full-height cursor and mark lines
width and height were swapped, causing the vertical marker and cursor lines
to be drawn with the wrong height.
Signed-off-by: David Sharp dhsh...@google.com
---
trace-graph.c |8
1 files changed, 4 insertions(+), 4 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 6f72350..60e5241 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -380,7 +380,7 @@ static void draw_cursor(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-cursor);
gdk_draw_line(ginfo-draw-window, ginfo-draw-style-mid_gc[3],
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void draw_marka(struct graph_info *ginfo)
@@ -392,7 +392,7 @@ static void draw_marka(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-marka_time);
gdk_draw_line(ginfo-draw-window, green,
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void draw_markb(struct graph_info *ginfo)
@@ -404,7 +404,7 @@ static void draw_markb(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-markb_time);
gdk_draw_line(ginfo-draw-window, red,
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void update_with_backend(struct graph_info *ginfo,
@@ -434,7 +434,7 @@ static void
draw_line(GtkWidget *widget, gdouble x, struct graph_info *ginfo)
{
gdk_draw_line(widget-window, widget-style-black_gc,
- x, 0, x, widget-allocation.width);
+ x, 0, x, widget-allocation.height);
}
static void clear_line(struct graph_info *ginfo, gint x)
--
1.7.7.3
--
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/
[PATCH 1/4] kernelshark: Fix bug with Plot CPU filtering
From: Venkatesh Pallipadi ve...@google.com
Plot CPU filtering in kernelshark has the following bug:
1) Deselect CPU A from Plot CPU list
2) Plot gets updated with no CPU A
3) Deselect CPU B
4) Plot continues to have CPU B
This is due to a bug in graph_plot_cpus_update_callback(),
which seems to be checking old_all_cpus != new_all_cpus before doing any
update. This condition is true on 1, but false on 2.
Removing that check fixes the problem.
Tested:
Above sequence now does expected filtering.
Google-bug-id: 4258610
Signed-off-by: Venkatesh Pallipadi ve...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
trace-plot-cpu.c |5 ++---
1 files changed, 2 insertions(+), 3 deletions(-)
diff --git a/trace-plot-cpu.c b/trace-plot-cpu.c
index 630d6c2..bb767d3 100644
--- a/trace-plot-cpu.c
+++ b/trace-plot-cpu.c
@@ -498,9 +498,8 @@ void graph_plot_cpus_update_callback(gboolean accept,
/* Get the current status */
graph_plot_cpus_plotted(ginfo, old_all_cpus, old_cpu_mask);
- if (old_all_cpus == all_cpus ||
- (selected_cpu_mask
-cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo-cpus))) {
+ if (selected_cpu_mask
+cpus_equal(old_cpu_mask, selected_cpu_mask, ginfo-cpus)) {
/* Nothing to do */
g_free(old_cpu_mask);
return;
--
1.7.7.3
--
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/
[PATCH 3/4] kernel-shark: Don't check for system name for sched events
From: Vaibhav Nagarnaik vnagarn...@google.com
The sched tracepoint names are unique and so there is no need to check
for the subsystem name while looking up the event ID.
This helps kernel shark display the graphs correctly for trace.dat files
generated from trace collection mechanisms that don't record the subsystem.
Google-Bug-Id: 6333917
Signed-off-by: Vaibhav Nagarnaik vnagarn...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
trace-graph.c |6 +++---
1 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 4d81219..6f72350 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -1016,7 +1016,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
found = FALSE;
event = pevent_find_event_by_name(ginfo-pevent,
- sched, sched_wakeup);
+ NULL, sched_wakeup);
if (event) {
found = TRUE;
ginfo-event_wakeup_id = event-id;
@@ -1026,7 +1026,7 @@ int trace_graph_check_sched_wakeup(struct graph_info
*ginfo,
event = pevent_find_event_by_name(ginfo-pevent,
- sched, sched_wakeup_new);
+ NULL, sched_wakeup_new);
if (event) {
found = TRUE;
ginfo-event_wakeup_new_id = event-id;
@@ -1086,7 +1086,7 @@ int trace_graph_check_sched_switch(struct graph_info
*ginfo,
if (ginfo-event_sched_switch_id 0) {
event = pevent_find_event_by_name(ginfo-pevent,
- sched, sched_switch);
+ NULL, sched_switch);
if (!event)
return 0;
--
1.7.7.3
--
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/
Re: [PATCH 1/4] kernelshark: Fix bug with Plot CPU filtering
sorry for the dups... typoed Steve's domain. On Wed, Nov 14, 2012 at 5:51 PM, David Sharp dhsh...@google.com wrote: From: Venkatesh Pallipadi ve...@google.com Plot CPU filtering in kernelshark has the following bug: 1) Deselect CPU A from Plot CPU list 2) Plot gets updated with no CPU A 3) Deselect CPU B 4) Plot continues to have CPU B This is due to a bug in graph_plot_cpus_update_callback(), which seems to be checking old_all_cpus != new_all_cpus before doing any update. This condition is true on 1, but false on 2. Removing that check fixes the problem. Tested: Above sequence now does expected filtering. Google-bug-id: 4258610 Signed-off-by: Venkatesh Pallipadi ve...@google.com Signed-off-by: David Sharp dhsh...@google.com -- 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/
[PATCH 4/4] kernelshark: Full-height cursor and mark lines
width and height were swapped, causing the vertical marker and cursor lines
to be drawn with the wrong height.
Signed-off-by: David Sharp dhsh...@google.com
---
trace-graph.c |8
1 files changed, 4 insertions(+), 4 deletions(-)
diff --git a/trace-graph.c b/trace-graph.c
index 6f72350..60e5241 100644
--- a/trace-graph.c
+++ b/trace-graph.c
@@ -380,7 +380,7 @@ static void draw_cursor(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-cursor);
gdk_draw_line(ginfo-draw-window, ginfo-draw-style-mid_gc[3],
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void draw_marka(struct graph_info *ginfo)
@@ -392,7 +392,7 @@ static void draw_marka(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-marka_time);
gdk_draw_line(ginfo-draw-window, green,
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void draw_markb(struct graph_info *ginfo)
@@ -404,7 +404,7 @@ static void draw_markb(struct graph_info *ginfo)
x = convert_time_to_x(ginfo, ginfo-markb_time);
gdk_draw_line(ginfo-draw-window, red,
- x, 0, x, ginfo-draw-allocation.width);
+ x, 0, x, ginfo-draw-allocation.height);
}
static void update_with_backend(struct graph_info *ginfo,
@@ -434,7 +434,7 @@ static void
draw_line(GtkWidget *widget, gdouble x, struct graph_info *ginfo)
{
gdk_draw_line(widget-window, widget-style-black_gc,
- x, 0, x, widget-allocation.width);
+ x, 0, x, widget-allocation.height);
}
static void clear_line(struct graph_info *ginfo, gint x)
--
1.7.7.3
--
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(_trace); + if (max_tr.buffer) + tracing_reset_online_cpus(_tr); + mutex_unlock(_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/
[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/
Re: [RFC PATCH 0/2] kvm/vmx: Output TSC offset
On Tue, Nov 13, 2012 at 6:00 PM, Steven Rostedt wrote: > On Wed, 2012-11-14 at 10:36 +0900, Yoshihiro YUNOMAE wrote: > >> To merge the data like previous pattern, we apply this patch set. Then, we >> can >> get TSC offset of the guest as follows: >> >> $ dmesg | grep kvm >> [ 57.717180] kvm: (2687) write TSC offset 18446743360465545001, now clock >> ## >> | >> PID TSC offset | >>HOST TSC value --+ >> > > Using printk to export something like this is IMO a nasty hack. > > Can't we create a /sys or /proc file to export the same thing? Since the value changes over the course of the trace, and seems to be part of the context of the trace, I think I'd include it as a tracepoint. > > -- Steve > > -- 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/
[PATCH v9 2/3] 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
Signed-off-by: David Sharp
Cc: Steven Rostedt
Cc: Masami Hiramatsu
---
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)
iter->iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter->cpu_file = cpu_file;
[PATCH v9 3/3] ftrace: Show raw time stamp on stats per cpu using counter or tsc mode for trace_clock
From: Yoshihiro YUNOMAE
Show raw time stamp values for stats per cpu if you choose counter or tsc mode
for trace_clock. Although a unit of tracing time stamp is nsec in local or
global mode,
the units in counter and TSC mode are tracing counter and cycles respectively.
Signed-off-by: Yoshihiro YUNOMAE
Cc: Steven Rostedt
Cc: Frederic Weisbecker
Cc: Ingo Molnar
Signed-off-by: David Sharp
---
kernel/trace/trace.c | 23 +--
1 files changed, 17 insertions(+), 6 deletions(-)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index d943e69..b69cc38 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4388,13 +4388,24 @@ tracing_stats_read(struct file *filp, char __user *ubuf,
cnt = ring_buffer_bytes_cpu(tr->buffer, cpu);
trace_seq_printf(s, "bytes: %ld\n", cnt);
- t = ns2usecs(ring_buffer_oldest_event_ts(tr->buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, "oldest event ts: %5llu.%06lu\n", t, usec_rem);
+ if (trace_clocks[trace_clock_id].in_ns) {
+ /* local or global for trace_clock */
+ t = ns2usecs(ring_buffer_oldest_event_ts(tr->buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, "oldest event ts: %5llu.%06lu\n",
+ t, usec_rem);
+
+ t = ns2usecs(ring_buffer_time_stamp(tr->buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, "now ts: %5llu.%06lu\n", t, usec_rem);
+ } else {
+ /* counter or tsc mode for trace_clock */
+ trace_seq_printf(s, "oldest event ts: %llu\n",
+ ring_buffer_oldest_event_ts(tr->buffer, cpu));
- t = ns2usecs(ring_buffer_time_stamp(tr->buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, "now ts: %5llu.%06lu\n", t, usec_rem);
+ trace_seq_printf(s, "now ts: %llu\n",
+ ring_buffer_time_stamp(tr->buffer, cpu));
+ }
cnt = ring_buffer_dropped_events_cpu(tr->buffer, cpu);
trace_seq_printf(s, "dropped events: %ld\n", cnt);
--
1.7.7.3
--
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/
[PATCH v9 1/3] 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 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu Cc: Ingo Molnar Cc: Thomas Gleixner Cc: "H. Peter Anvin" Acked-by: Ingo Molnar --- 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(+), 0 deletions(-) create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 include/asm-generic/trace_clock.h 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-y += module.h +generic-y += trace_clock.h diff --git a/arch/frv/include/asm/Kbuild b/arch/frv/include/asm/Kbuild index 4a159da..c5d7670
[PATCH v9 1/3] 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 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com Cc: Ingo Molnar mi...@kernel.org Cc: Thomas Gleixner t...@linutronix.de Cc: H. Peter Anvin h...@linux.intel.com Acked-by: Ingo Molnar mi...@kernel.org --- 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(+), 0 deletions(-) create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 include/asm-generic/trace_clock.h 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-y += module.h +generic-y
[PATCH v9 3/3] ftrace: Show raw time stamp on stats per cpu using counter or tsc mode for trace_clock
From: Yoshihiro YUNOMAE yoshihiro.yunomae...@hitachi.com
Show raw time stamp values for stats per cpu if you choose counter or tsc mode
for trace_clock. Although a unit of tracing time stamp is nsec in local or
global mode,
the units in counter and TSC mode are tracing counter and cycles respectively.
Signed-off-by: Yoshihiro YUNOMAE yoshihiro.yunomae...@hitachi.com
Cc: Steven Rostedt rost...@goodmis.org
Cc: Frederic Weisbecker fweis...@gmail.com
Cc: Ingo Molnar mi...@redhat.com
Signed-off-by: David Sharp dhsh...@google.com
---
kernel/trace/trace.c | 23 +--
1 files changed, 17 insertions(+), 6 deletions(-)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index d943e69..b69cc38 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4388,13 +4388,24 @@ tracing_stats_read(struct file *filp, char __user *ubuf,
cnt = ring_buffer_bytes_cpu(tr-buffer, cpu);
trace_seq_printf(s, bytes: %ld\n, cnt);
- t = ns2usecs(ring_buffer_oldest_event_ts(tr-buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, oldest event ts: %5llu.%06lu\n, t, usec_rem);
+ if (trace_clocks[trace_clock_id].in_ns) {
+ /* local or global for trace_clock */
+ t = ns2usecs(ring_buffer_oldest_event_ts(tr-buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, oldest event ts: %5llu.%06lu\n,
+ t, usec_rem);
+
+ t = ns2usecs(ring_buffer_time_stamp(tr-buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, now ts: %5llu.%06lu\n, t, usec_rem);
+ } else {
+ /* counter or tsc mode for trace_clock */
+ trace_seq_printf(s, oldest event ts: %llu\n,
+ ring_buffer_oldest_event_ts(tr-buffer, cpu));
- t = ns2usecs(ring_buffer_time_stamp(tr-buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, now ts: %5llu.%06lu\n, t, usec_rem);
+ trace_seq_printf(s, now ts: %llu\n,
+ ring_buffer_time_stamp(tr-buffer, cpu));
+ }
cnt = ring_buffer_dropped_events_cpu(tr-buffer, cpu);
trace_seq_printf(s, dropped events: %ld\n, cnt);
--
1.7.7.3
--
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/
[PATCH v9 2/3] 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
idle-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
idle-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
idle-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
idle-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
Signed-off-by: David Sharp dhsh...@google.com
Cc: Steven Rostedt rost...@goodmis.org
Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com
---
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)
iter-iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter-cpu_file = cpu_file;
iter-tr = global_trace;
mutex_init(iter-mutex);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index
Re: [RFC PATCH 0/2] kvm/vmx: Output TSC offset
On Tue, Nov 13, 2012 at 6:00 PM, Steven Rostedt rost...@goodmis.org wrote:
On Wed, 2012-11-14 at 10:36 +0900, Yoshihiro YUNOMAE wrote:
To merge the data like previous pattern, we apply this patch set. Then, we
can
get TSC offset of the guest as follows:
$ dmesg | grep kvm
[ 57.717180] kvm: (2687) write TSC offset 18446743360465545001, now clock
##
|
PID TSC offset |
HOST TSC value --+
Using printk to export something like this is IMO a nasty hack.
Can't we create a /sys or /proc file to export the same thing?
Since the value changes over the course of the trace, and seems to be
part of the context of the trace, I think I'd include it as a
tracepoint.
-- Steve
--
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: Trivial cleanup
Commit-ID: 01e3e710a9265fb7092efd67243d7b6dd6e2548a
Gitweb: http://git.kernel.org/tip/01e3e710a9265fb7092efd67243d7b6dd6e2548a
Author: David Sharp dhsh...@google.com
AuthorDate: Thu, 7 Jun 2012 16:46:24 -0700
Committer: Steven Rostedt rost...@goodmis.org
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 dhsh...@google.com
Signed-off-by: Vaibhav Nagarnaik vnagarn...@google.com
Signed-off-by: Steven Rostedt rost...@goodmis.org
---
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 dhsh...@google.com AuthorDate: Thu, 11 Oct 2012 16:27:52 -0700 Committer: Steven Rostedt rost...@goodmis.org 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 masami.hiramatsu...@hitachi.com Signed-off-by: David Sharp dhsh...@google.com Signed-off-by: Steven Rostedt rost...@goodmis.org --- 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/
[PATCH v8 3/5] 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
Signed-off-by: David Sharp
Cc: Steven Rostedt
Cc: Masami Hiramatsu
---
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 642928c..c760670 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 84aa489..64e3fe5 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -477,10 +477,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
};
@@ -2427,6 +2428,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();
@@ -3326,6 +3331,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags & TRACE_ITER_LATENCY_FMT)
iter->iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter->cpu_file = cpu_file;
[PATCH v8 3/5] 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
idle-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
idle-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
idle-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
idle-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
Signed-off-by: David Sharp dhsh...@google.com
Cc: Steven Rostedt rost...@goodmis.org
Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com
---
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 642928c..c760670 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 84aa489..64e3fe5 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -477,10 +477,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
};
@@ -2427,6 +2428,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();
@@ -3326,6 +3331,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags TRACE_ITER_LATENCY_FMT)
iter-iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter-cpu_file = cpu_file;
iter-tr = global_trace;
mutex_init(iter-mutex);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index
[PATCH v8 2/5] 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 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu --- 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 9aed7f5..84aa489 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -4017,6 +4017,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(_trace); + if (max_tr.buffer) + tracing_reset_online_cpus(_tr); + mutex_unlock(_types_lock); *fpos += cnt; -- 1.7.7.3 -- 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/
[PATCH v8 1/5] 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 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu Cc: Ingo Molnar Cc: Thomas Gleixner Cc: "H. Peter Anvin" Acked-by: Ingo Molnar --- Fixed build warnings and errors detected by kbuild test robot. 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(+), 0 deletions(-) create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 include/asm-generic/trace_clock.h 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-y += module.h +generic-y += trace_clock.h diff --git a/arch/frv
[PATCH v8 1/5] 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 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com Cc: Ingo Molnar mi...@kernel.org Cc: Thomas Gleixner t...@linutronix.de Cc: H. Peter Anvin h...@linux.intel.com Acked-by: Ingo Molnar mi...@kernel.org --- Fixed build warnings and errors detected by kbuild test robot. 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(+), 0 deletions(-) create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 include/asm-generic/trace_clock.h 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
[PATCH v8 2/5] 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 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com --- 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 9aed7f5..84aa489 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -4017,6 +4017,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; -- 1.7.7.3 -- 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/
[PATCH v7 1/5] 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 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu Cc: Ingo Molnar Cc: Thomas Gleixner Cc: "H. Peter Anvin" Acked-by: Ingo Molnar --- 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 | 16 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, 84 insertions(+), 0 deletions(-) create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 include/asm-generic/trace_clock.h 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 fe77e51..53a535a 100644 --- a/arch/arm64/include/asm/Kbuild +++ b/arch/arm64/include/asm/Kbuild @@ -44,6 +44,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-y += module.h +generic-y += trace_clock.h diff --git a/arch/frv/include/asm/Kbuild b/arch/frv/include/asm/Kbuild index 4a159da..c5d7670 100
Re: [PATCH v6 1/6] tracing,x86: Add a TSC trace_clock
On Tue, Oct 16, 2012 at 5:53 AM, David Howells wrote:
> David Sharp wrote:
>
>> > Please use the Kbuild infrastructure ("generic-y += ..." in
>> > arch/*/include/asm/Kbuild)
>> > instead of adding wrappers around the asm-generic version.
>>
>> mips apparently recencly got rid of arch/mips/include/asm/Kbuild.
>
> It didn't. However, if you use patch to create your kernel tree, then patch
> may have removed it. If you're using GIT, it should still exist. Try:
Ah, right. It's not missing, just empty.
>
> git log -- arch/mips/include/asm/Kbuild
>
>> What should I do for mips?
>
> Just create the file with a single "generic-y += ..." line in it.
Okay. Thanks.
>
> David
--
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/
Re: [PATCH v6 1/6] tracing,x86: Add a TSC trace_clock
On Tue, Oct 16, 2012 at 5:53 AM, David Howells dhowe...@redhat.com wrote: David Sharp dhsh...@google.com wrote: Please use the Kbuild infrastructure (generic-y += ... in arch/*/include/asm/Kbuild) instead of adding wrappers around the asm-generic version. mips apparently recencly got rid of arch/mips/include/asm/Kbuild. It didn't. However, if you use patch to create your kernel tree, then patch may have removed it. If you're using GIT, it should still exist. Try: Ah, right. It's not missing, just empty. git log -- arch/mips/include/asm/Kbuild What should I do for mips? Just create the file with a single generic-y += ... line in it. Okay. Thanks. David -- 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/
[PATCH v7 1/5] 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 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com Cc: Ingo Molnar mi...@kernel.org Cc: Thomas Gleixner t...@linutronix.de Cc: H. Peter Anvin h...@linux.intel.com Acked-by: Ingo Molnar mi...@kernel.org --- 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 | 16 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, 84 insertions(+), 0 deletions(-) create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 include/asm-generic/trace_clock.h 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 fe77e51..53a535a 100644 --- a/arch/arm64/include/asm/Kbuild +++ b/arch/arm64/include/asm/Kbuild @@ -44,6 +44,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-y += module.h +generic-y
Re: [PATCH v6 1/6] tracing,x86: Add a TSC trace_clock
On Thu, Oct 11, 2012 at 10:05 PM, Geert Uytterhoeven
wrote:
> On Fri, Oct 12, 2012 at 1:27 AM, David Sharp wrote:
>> +#include
>
> Please use the Kbuild infrastructure ("generic-y += ..." in
> arch/*/include/asm/Kbuild)
> instead of adding wrappers around the asm-generic version.
mips apparently recencly got rid of arch/mips/include/asm/Kbuild. What
should I do for mips?
>
> Gr{oetje,eeting}s,
>
> Geert
>
> --
> Geert Uytterhoeven -- There's lots of Linux beyond ia32 --
> ge...@linux-m68k.org
>
> In personal conversations with technical people, I call myself a hacker. But
> when I'm talking to journalists I just say "programmer" or something like
> that.
> -- Linus Torvalds
--
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/
Re: [PATCH v6 1/6] tracing,x86: Add a TSC trace_clock
On Fri, Oct 12, 2012 at 4:41 AM, Steven Rostedt wrote:
> On Fri, 2012-10-12 at 07:05 +0200, Geert Uytterhoeven wrote:
>> On Fri, Oct 12, 2012 at 1:27 AM, David Sharp wrote:
>> > +#include
>>
>> Please use the Kbuild infrastructure ("generic-y += ..." in
>> arch/*/include/asm/Kbuild)
>> instead of adding wrappers around the asm-generic version.
>
> So that's how that's done. Learn something new everyday. Too bad the one
> file I checked (div64.h) doesn't seem to do it for ia64 and others.
>
> Can we please have someone clean up all the archs and remove any *.h
> wrappers and use the kbuild infrastructure instead. That way, when
> another developer goes to look at how this is done, they wont copy the
> wrong method again. (Maybe I'll just do it :-p)
>
> David,
>
> Can you just send an update of this one patch.
Will do. Thanks for the education, Geert. :)
d#
--
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/
Re: [PATCH v6 1/6] tracing,x86: Add a TSC trace_clock
On Fri, Oct 12, 2012 at 4:41 AM, Steven Rostedt rost...@goodmis.org wrote: On Fri, 2012-10-12 at 07:05 +0200, Geert Uytterhoeven wrote: On Fri, Oct 12, 2012 at 1:27 AM, David Sharp dhsh...@google.com wrote: +#include asm-generic/trace_clock.h Please use the Kbuild infrastructure (generic-y += ... in arch/*/include/asm/Kbuild) instead of adding wrappers around the asm-generic version. So that's how that's done. Learn something new everyday. Too bad the one file I checked (div64.h) doesn't seem to do it for ia64 and others. Can we please have someone clean up all the archs and remove any *.h wrappers and use the kbuild infrastructure instead. That way, when another developer goes to look at how this is done, they wont copy the wrong method again. (Maybe I'll just do it :-p) David, Can you just send an update of this one patch. Will do. Thanks for the education, Geert. :) d# -- 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/
Re: [PATCH v6 1/6] tracing,x86: Add a TSC trace_clock
On Thu, Oct 11, 2012 at 10:05 PM, Geert Uytterhoeven
ge...@linux-m68k.org wrote:
On Fri, Oct 12, 2012 at 1:27 AM, David Sharp dhsh...@google.com wrote:
+#include asm-generic/trace_clock.h
Please use the Kbuild infrastructure (generic-y += ... in
arch/*/include/asm/Kbuild)
instead of adding wrappers around the asm-generic version.
mips apparently recencly got rid of arch/mips/include/asm/Kbuild. What
should I do for mips?
Gr{oetje,eeting}s,
Geert
--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 --
ge...@linux-m68k.org
In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say programmer or something like
that.
-- Linus Torvalds
--
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/
Re: [PATCH v6 6/6] tracing: Fix maybe-uninitialized warning in ftrace_function_set_regexp
On Thu, Oct 11, 2012 at 6:36 PM, Steven Rostedt wrote:
> On Thu, 2012-10-11 at 16:27 -0700, David Sharp wrote:
>> Compiler warning:
>>
>> kernel/trace/trace_events_filter.c: In function
>> 'ftrace_function_set_filter_cb':
>> kernel/trace/trace_events_filter.c:2074:8: error: 'ret' may be used
>> uninitialized in this function [-Werror=maybe-uninitialized]
>>
>> Signed-off-by: David Sharp
>> Cc: Steven Rostedt
>> ---
>> kernel/trace/trace_events_filter.c |3 ++-
>> 1 files changed, 2 insertions(+), 1 deletions(-)
>>
>> diff --git a/kernel/trace/trace_events_filter.c
>> b/kernel/trace/trace_events_filter.c
>> index 431dba8..ef36953 100644
>> --- a/kernel/trace/trace_events_filter.c
>> +++ b/kernel/trace/trace_events_filter.c
>> @@ -2002,9 +2002,10 @@ static int ftrace_function_set_regexp(struct
>> ftrace_ops *ops, int filter,
>> static int __ftrace_function_set_filter(int filter, char *buf, int len,
>> struct function_filter_data *data)
>> {
>> - int i, re_cnt, ret;
>> + int i, re_cnt;
>> int *reset;
>> char **re;
>> + int ret = 0;
>>
>> reset = filter ? >first_filter : >first_notrace;
>>
>
> It has already been fixed in mainline:
>
> 92d8d4a8b0f4c6eba70f6e62b48e38bd005a56e6
>
> http://marc.info/?l=linux-kernel=134012157512078
Okay, drop this one then. I haven't been rebasing.
--
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/
Re: [PATCH 1/2] tracing: trivial cleanup
On Thu, Oct 11, 2012 at 6:56 PM, Steven Rostedt wrote:
> Sorry, I know this is late, but it was pushed down in my todo list
> (never off, but something I probably wouldn't have seen for a few more
> months).
>
> On Thu, 2012-06-07 at 16:46 -0700, Vaibhav Nagarnaik wrote:
>> From: David Sharp
>
> If this is from David it needs his SOB.
Is that true even though we are working for the same company?
> -- Steve
>
>>
>> Remove ftrace_format_syscall() declaration; it is neither defined nor
>> used. Also update a comment and formatting.
>>
>> Signed-off-by: Vaibhav Nagarnaik
Signed-off-by: David Sharp
>> ---
>> 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 1d0f6a8..96c2dd1 100644
>> --- a/kernel/trace/ring_buffer.c
>> +++ b/kernel/trace/ring_buffer.c
>> @@ -1816,7 +1816,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
>> @@ -2716,8 +2716,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/
Re: [PATCH v5 1/3] tracing,x86: Add a TSC trace_clock
On Mon, Oct 8, 2012 at 7:08 PM, Yoshihiro YUNOMAE wrote: > Hi David, > > This is a nice patch set. > > I just have found something should be fixed, which related to > your work. I'll send it following this mail. > > Would you mind adding these patches as your patch series? Thanks for noticing the stats issue. Added them to my series. > > Thanks, > > Yoshihiro YUNOMAE > > (2012/10/02 12:31), David Sharp wrote: >> 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. >> > > -- > Yoshihiro YUNOMAE > Software Platform Research Dept. Linux Technology Center > Hitachi, Ltd., Yokohama Research Laboratory > E-mail: yoshihiro.yunomae...@hitachi.com > > -- 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/
[PATCH v6 3/6] 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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
Signed-off-by: David Sharp
Cc: Steven Rostedt
Cc: Masami Hiramatsu
---
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| 80 ---
5 files changed, 74 insertions(+), 33 deletions(-)
diff --git a/arch/x86/include/asm/trace_clock.h
b/arch/x86/include/asm/trace_clock.h
index 7ee0d8c..45e17f5 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 },
#endif
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 642928c..c760670 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 4e26df3..cff3427 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -476,10 +476,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
};
@@ -2425,6 +2426,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();
@@ -3324,6 +3329,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags & TRACE_ITER_LATENCY_FMT)
iter->iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter->cpu_file = cpu_file;
[PATCH v6 1/6] 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 Google-Bug-Id: 6980623 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu Cc: Ingo Molnar Cc: Thomas Gleixner Cc: "H. Peter Anvin" Acked-by: Ingo Molnar --- arch/alpha/include/asm/trace_clock.h |6 ++ arch/arm/include/asm/trace_clock.h|6 ++ arch/avr32/include/asm/trace_clock.h |6 ++ arch/blackfin/include/asm/trace_clock.h |6 ++ arch/c6x/include/asm/trace_clock.h|6 ++ arch/cris/include/asm/trace_clock.h |6 ++ arch/frv/include/asm/trace_clock.h|6 ++ arch/h8300/include/asm/trace_clock.h |6 ++ arch/hexagon/include/asm/trace_clock.h|6 ++ arch/ia64/include/asm/trace_clock.h |6 ++ arch/m32r/include/asm/trace_clock.h |6 ++ arch/m68k/include/asm/trace_clock.h |6 ++ arch/microblaze/include/asm/trace_clock.h |6 ++ arch/mips/include/asm/trace_clock.h |6 ++ arch/mn10300/include/asm/trace_clock.h|6 ++ arch/openrisc/include/asm/trace_clock.h |6 ++ arch/parisc/include/asm/trace_clock.h |6 ++ arch/powerpc/include/asm/trace_clock.h|6 ++ arch/s390/include/asm/trace_clock.h |6 ++ arch/score/include/asm/trace_clock.h |6 ++ arch/sh/include/asm/trace_clock.h |6 ++ arch/sparc/include/asm/trace_clock.h |6 ++ arch/tile/include/asm/trace_clock.h |6 ++ arch/um/include/asm/trace_clock.h |6 ++ arch/unicore32/include/asm/trace_clock.h |6 ++ arch/x86/include/asm/trace_clock.h| 16 arch/x86/kernel/Makefile |1 + arch/x86/kernel/trace_clock.c | 21 + arch/xtensa/include/asm/trace_clock.h |6 ++ include/asm-generic/trace_clock.h | 16 include/linux/trace_clock.h |2 ++ kernel/trace/trace.c |1 + 32 files changed, 213 insertions(+), 0 deletions(-) create mode 100644 arch/alpha/include/asm/trace_clock.h create mode 100644 arch/arm/include/asm/trace_clock.h create mode 100644 arch/avr32/include/asm/trace_clock.h create mode 100644 arch/blackfin/include/asm/trace_clock.h create mode 100644 arch/c6x/include/asm/trace_clock.h create mode 100644 arch/cris/include/asm/trace_clock.h create mode 100644 arch/frv/include/asm/trace_clock.h create mode 100644 arch/h8300/include/asm/trace_clock.h create mode 100644 arch/hexagon/include/asm/trace_clock.h create mode 100644 arch/ia64/include/asm/trace_clock.h create mode 100644 arch/m32r/include/asm/trace_clock.h create mode 100644 arch/m68k/include/asm/trace_clock.h create mode 100644 arch/microblaze/include/asm/trace_clock.h create mode 100644 arch/mips/include/asm/trace_clock.h create mode 100644 arch/mn10300/include/asm/trace_clock.h create mode 100644 arch/openrisc/include/asm/trace_clock.h create mode 100644 arch/parisc/include/asm/trace_clock.h create mode 100644 arch/powerpc/include/asm/trace_clock.h create mode 100644 arch/s390/include/asm/trace_clock.h create mode 100644 arch/score/include/asm/trace_clock.h create mode 100644 arch/sh/include/asm/trace_clock.h create mode 100644 arch/sparc/include/asm/trace_clock.h create mode 100644 arch/tile/include/asm/trace_clock.h create mode 100644 arch/um/include/asm/trace_clock.h create mode 100644 arch/unicore32/include/asm/trace_clock.h create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 arch/xtensa/include/asm/trace_clock.h create mode 100644 include/asm-generic/trace_clock.h diff --git a/arch/alpha/include/asm/trace_clock.h b/arch/alpha/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/alpha/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include + +#endif diff --git a/arch/arm/include/asm/trace_clock.h b/arch/arm/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/arm/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include + +#endif diff --git a/arch/avr32/include/asm/trace_clock.h b/arch/avr32/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/avr32/include/asm/trace_cl
[PATCH v6 6/6] tracing: Fix maybe-uninitialized warning in ftrace_function_set_regexp
Compiler warning:
kernel/trace/trace_events_filter.c: In function 'ftrace_function_set_filter_cb':
kernel/trace/trace_events_filter.c:2074:8: error: 'ret' may be used
uninitialized in this function [-Werror=maybe-uninitialized]
Signed-off-by: David Sharp
Cc: Steven Rostedt
---
kernel/trace/trace_events_filter.c |3 ++-
1 files changed, 2 insertions(+), 1 deletions(-)
diff --git a/kernel/trace/trace_events_filter.c
b/kernel/trace/trace_events_filter.c
index 431dba8..ef36953 100644
--- a/kernel/trace/trace_events_filter.c
+++ b/kernel/trace/trace_events_filter.c
@@ -2002,9 +2002,10 @@ static int ftrace_function_set_regexp(struct ftrace_ops
*ops, int filter,
static int __ftrace_function_set_filter(int filter, char *buf, int len,
struct function_filter_data *data)
{
- int i, re_cnt, ret;
+ int i, re_cnt;
int *reset;
char **re;
+ int ret = 0;
reset = filter ? >first_filter : >first_notrace;
--
1.7.7.3
--
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/
[PATCH v6 5/6] ftrace: Show raw time stamp on stats per cpu using counter or tsc mode for trace_clock
From: Yoshihiro YUNOMAE
Show raw time stamp values for stats per cpu if you choose counter or tsc mode
for trace_clock. Although a unit of tracing time stamp is nsec in local or
global mode,
the units in counter and TSC mode are tracing counter and cycles respectively.
Signed-off-by: Yoshihiro YUNOMAE
Cc: Steven Rostedt
Cc: Frederic Weisbecker
Cc: Ingo Molnar
Signed-off-by: David Sharp
---
kernel/trace/trace.c | 23 +--
1 files changed, 17 insertions(+), 6 deletions(-)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index cff3427..8bfa3b7 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4396,13 +4396,24 @@ tracing_stats_read(struct file *filp, char __user *ubuf,
cnt = ring_buffer_bytes_cpu(tr->buffer, cpu);
trace_seq_printf(s, "bytes: %ld\n", cnt);
- t = ns2usecs(ring_buffer_oldest_event_ts(tr->buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, "oldest event ts: %5llu.%06lu\n", t, usec_rem);
+ if (trace_clocks[trace_clock_id].in_ns) {
+ /* local or global for trace_clock */
+ t = ns2usecs(ring_buffer_oldest_event_ts(tr->buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, "oldest event ts: %5llu.%06lu\n",
+ t, usec_rem);
+
+ t = ns2usecs(ring_buffer_time_stamp(tr->buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, "now ts: %5llu.%06lu\n", t, usec_rem);
+ } else {
+ /* counter or tsc mode for trace_clock */
+ trace_seq_printf(s, "oldest event ts: %llu\n",
+ ring_buffer_oldest_event_ts(tr->buffer, cpu));
- t = ns2usecs(ring_buffer_time_stamp(tr->buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, "now ts: %5llu.%06lu\n", t, usec_rem);
+ trace_seq_printf(s, "now ts: %llu\n",
+ ring_buffer_time_stamp(tr->buffer, cpu));
+ }
count = simple_read_from_buffer(ubuf, count, ppos, s->buffer, s->len);
--
1.7.7.3
--
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/
[PATCH v6 2/6] 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 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu --- 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 92fb08e..4e26df3 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -4012,6 +4012,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(_trace); + if (max_tr.buffer) + tracing_reset_online_cpus(_tr); + mutex_unlock(_types_lock); *fpos += cnt; -- 1.7.7.3 -- 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/
[PATCH v6 0/6] TSC trace_clock
Added Yoshihiro Yonomae's patches to change the per_cpu stats to show raw timestamps when the clock is not in nanoseconds. Also added a small patch to fix a warning. David Sharp (4): tracing,x86: Add a TSC trace_clock tracing: Reset ring buffer when changing trace_clocks tracing: Format non-nanosec times from tsc clock without a decimal point. tracing: Fix maybe-uninitialized warning in ftrace_function_set_regexp Yoshihiro YUNOMAE (2): ftrace: Change unsigned long type of ring_buffer_oldest_event_ts() to u64 ftrace: Show raw time stamp on stats per cpu using counter or tsc mode for trace_clock arch/alpha/include/asm/trace_clock.h |6 ++ arch/arm/include/asm/trace_clock.h|6 ++ arch/avr32/include/asm/trace_clock.h |6 ++ arch/blackfin/include/asm/trace_clock.h |6 ++ arch/c6x/include/asm/trace_clock.h|6 ++ arch/cris/include/asm/trace_clock.h |6 ++ arch/frv/include/asm/trace_clock.h|6 ++ arch/h8300/include/asm/trace_clock.h |6 ++ arch/hexagon/include/asm/trace_clock.h|6 ++ arch/ia64/include/asm/trace_clock.h |6 ++ arch/m32r/include/asm/trace_clock.h |6 ++ arch/m68k/include/asm/trace_clock.h |6 ++ arch/microblaze/include/asm/trace_clock.h |6 ++ arch/mips/include/asm/trace_clock.h |6 ++ arch/mn10300/include/asm/trace_clock.h|6 ++ arch/openrisc/include/asm/trace_clock.h |6 ++ arch/parisc/include/asm/trace_clock.h |6 ++ arch/powerpc/include/asm/trace_clock.h|6 ++ arch/s390/include/asm/trace_clock.h |6 ++ arch/score/include/asm/trace_clock.h |6 ++ arch/sh/include/asm/trace_clock.h |6 ++ arch/sparc/include/asm/trace_clock.h |6 ++ arch/tile/include/asm/trace_clock.h |6 ++ arch/um/include/asm/trace_clock.h |6 ++ arch/unicore32/include/asm/trace_clock.h |6 ++ arch/x86/include/asm/trace_clock.h| 16 ++ arch/x86/kernel/Makefile |1 + arch/x86/kernel/trace_clock.c | 21 arch/xtensa/include/asm/trace_clock.h |6 ++ include/asm-generic/trace_clock.h | 16 ++ include/linux/ftrace_event.h |6 ++ include/linux/ring_buffer.h |2 +- include/linux/trace_clock.h |2 + kernel/trace/ring_buffer.c|4 +- kernel/trace/trace.c | 47 ++--- kernel/trace/trace.h |4 -- kernel/trace/trace_events_filter.c|3 +- kernel/trace/trace_output.c | 80 - 38 files changed, 316 insertions(+), 42 deletions(-) create mode 100644 arch/alpha/include/asm/trace_clock.h create mode 100644 arch/arm/include/asm/trace_clock.h create mode 100644 arch/avr32/include/asm/trace_clock.h create mode 100644 arch/blackfin/include/asm/trace_clock.h create mode 100644 arch/c6x/include/asm/trace_clock.h create mode 100644 arch/cris/include/asm/trace_clock.h create mode 100644 arch/frv/include/asm/trace_clock.h create mode 100644 arch/h8300/include/asm/trace_clock.h create mode 100644 arch/hexagon/include/asm/trace_clock.h create mode 100644 arch/ia64/include/asm/trace_clock.h create mode 100644 arch/m32r/include/asm/trace_clock.h create mode 100644 arch/m68k/include/asm/trace_clock.h create mode 100644 arch/microblaze/include/asm/trace_clock.h create mode 100644 arch/mips/include/asm/trace_clock.h create mode 100644 arch/mn10300/include/asm/trace_clock.h create mode 100644 arch/openrisc/include/asm/trace_clock.h create mode 100644 arch/parisc/include/asm/trace_clock.h create mode 100644 arch/powerpc/include/asm/trace_clock.h create mode 100644 arch/s390/include/asm/trace_clock.h create mode 100644 arch/score/include/asm/trace_clock.h create mode 100644 arch/sh/include/asm/trace_clock.h create mode 100644 arch/sparc/include/asm/trace_clock.h create mode 100644 arch/tile/include/asm/trace_clock.h create mode 100644 arch/um/include/asm/trace_clock.h create mode 100644 arch/unicore32/include/asm/trace_clock.h create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 arch/xtensa/include/asm/trace_clock.h create mode 100644 include/asm-generic/trace_clock.h -- 1.7.7.3 -- 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/
[PATCH v6 4/6] ftrace: Change unsigned long type of ring_buffer_oldest_event_ts() to u64
From: Yoshihiro YUNOMAE
ring_buffer_oldest_event_ts() should return a value of u64 type, because
ring_buffer_per_cpu->buffer_page->buffer_data_page->time_stamp is u64 type.
Signed-off-by: Yoshihiro YUNOMAE
Cc: Steven Rostedt
Cc: Frederic Weisbecker
Cc: Ingo Molnar
Cc: Vaibhav Nagarnaik
Signed-off-by: David Sharp
---
include/linux/ring_buffer.h |2 +-
kernel/trace/ring_buffer.c |4 ++--
2 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/include/linux/ring_buffer.h b/include/linux/ring_buffer.h
index 6c8835f..c68a09a 100644
--- a/include/linux/ring_buffer.h
+++ b/include/linux/ring_buffer.h
@@ -159,7 +159,7 @@ int ring_buffer_record_is_on(struct ring_buffer *buffer);
void ring_buffer_record_disable_cpu(struct ring_buffer *buffer, int cpu);
void ring_buffer_record_enable_cpu(struct ring_buffer *buffer, int cpu);
-unsigned long ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu);
+u64 ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu);
unsigned long ring_buffer_bytes_cpu(struct ring_buffer *buffer, int cpu);
unsigned long ring_buffer_entries(struct ring_buffer *buffer);
unsigned long ring_buffer_overruns(struct ring_buffer *buffer);
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 49491fa..db3806e 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -2925,12 +2925,12 @@ rb_num_of_entries(struct ring_buffer_per_cpu
*cpu_buffer)
* @buffer: The ring buffer
* @cpu: The per CPU buffer to read from.
*/
-unsigned long ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu)
+u64 ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu)
{
unsigned long flags;
struct ring_buffer_per_cpu *cpu_buffer;
struct buffer_page *bpage;
- unsigned long ret;
+ u64 ret;
if (!cpumask_test_cpu(cpu, buffer->cpumask))
return 0;
--
1.7.7.3
--
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/
Re: [PATCH v5 3/3] tracing: Format non-nanosec times from tsc clock without a decimal point.
On Thu, Oct 11, 2012 at 1:43 PM, Steven Rostedt wrote:
> On Mon, 2012-10-01 at 20:31 -0700, David Sharp wrote:
>
>> static int
>> -lat_print_timestamp(struct trace_seq *s, u64 abs_usecs,
>> - unsigned long rel_usecs)
>> +lat_print_timestamp(struct trace_iterator *iter, u64 next_ts)
>> {
>> - return trace_seq_printf(s, " %4lldus%c: ", abs_usecs,
>> - rel_usecs > preempt_mark_thresh ? '!' :
>> - rel_usecs > 1 ? '+' : ' ');
>> + unsigned long verbose = trace_flags & TRACE_ITER_VERBOSE;
>> + unsigned long in_ns = iter->iter_flags & TRACE_FILE_TIME_IN_NS;
>> + unsigned long long abs_ts = iter->ts - iter->tr->time_start;
>> + unsigned long long rel_ts = next_ts - iter->ts;
>> + struct trace_seq *s = >seq;
>> + unsigned long mark_thresh;
>> + int ret;
>> +
>> + if (in_ns) {
>> + abs_ts = ns2usecs(abs_ts);
>> + rel_ts = ns2usecs(rel_ts);
>> + }
>> +
>> + if (verbose && in_ns) {
>> + unsigned long abs_msec = abs_ts;
>> + unsigned long abs_usec = do_div(abs_msec, USEC_PER_MSEC);
>> + unsigned long rel_msec = rel_ts;
>> + unsigned long rel_usec = do_div(rel_msec, USEC_PER_MSEC);
>> +
>> + ret = trace_seq_printf(
>> + s, "[%08llx] %ld.%03ldms (+%ld.%03ldms): ",
>> + ns2usecs(iter->ts),
>> + abs_msec, abs_usec,
>> + rel_msec, rel_usec);
>> + } else if (verbose && !in_ns) {
>> + ret = trace_seq_printf(
>> + s, "[%016llx] %lld (+%lld): ",
>> + iter->ts, abs_ts, rel_ts);
>> + } else if (!verbose && in_ns) {
>> + ret = trace_seq_printf(
>> + s, " %4lldus: ",
>
> Missing %c.
>
>> + abs_ts,
>> + rel_ts > preempt_mark_thresh_us ? '!' :
>> + rel_ts > 1 ? '+' : ' ');
>> + } else { /* !verbose && !in_ns */
>> + ret = trace_seq_printf(s, " %4lld%s%c: ", abs_ts);
>
> Um, "%s%c" with no matching arguments.
Sorry for being so sloppy on these patches... Wonder why I didn't see
the printf warnings.
I'll send out an new patchset with this fixed, and include Yoshihiro
Yunomae's patches.
>
> -- Steve
>
>> + }
>> + return ret;
>> }
>>
>
>
--
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/
Re: [PATCH v5 3/3] tracing: Format non-nanosec times from tsc clock without a decimal point.
On Thu, Oct 11, 2012 at 1:43 PM, Steven Rostedt rost...@goodmis.org wrote:
On Mon, 2012-10-01 at 20:31 -0700, David Sharp wrote:
static int
-lat_print_timestamp(struct trace_seq *s, u64 abs_usecs,
- unsigned long rel_usecs)
+lat_print_timestamp(struct trace_iterator *iter, u64 next_ts)
{
- return trace_seq_printf(s, %4lldus%c: , abs_usecs,
- rel_usecs preempt_mark_thresh ? '!' :
- rel_usecs 1 ? '+' : ' ');
+ unsigned long verbose = trace_flags TRACE_ITER_VERBOSE;
+ unsigned long in_ns = iter-iter_flags TRACE_FILE_TIME_IN_NS;
+ unsigned long long abs_ts = iter-ts - iter-tr-time_start;
+ unsigned long long rel_ts = next_ts - iter-ts;
+ struct trace_seq *s = iter-seq;
+ unsigned long mark_thresh;
+ int ret;
+
+ if (in_ns) {
+ abs_ts = ns2usecs(abs_ts);
+ rel_ts = ns2usecs(rel_ts);
+ }
+
+ if (verbose in_ns) {
+ unsigned long abs_msec = abs_ts;
+ unsigned long abs_usec = do_div(abs_msec, USEC_PER_MSEC);
+ unsigned long rel_msec = rel_ts;
+ unsigned long rel_usec = do_div(rel_msec, USEC_PER_MSEC);
+
+ ret = trace_seq_printf(
+ s, [%08llx] %ld.%03ldms (+%ld.%03ldms): ,
+ ns2usecs(iter-ts),
+ abs_msec, abs_usec,
+ rel_msec, rel_usec);
+ } else if (verbose !in_ns) {
+ ret = trace_seq_printf(
+ s, [%016llx] %lld (+%lld): ,
+ iter-ts, abs_ts, rel_ts);
+ } else if (!verbose in_ns) {
+ ret = trace_seq_printf(
+ s, %4lldus: ,
Missing %c.
+ abs_ts,
+ rel_ts preempt_mark_thresh_us ? '!' :
+ rel_ts 1 ? '+' : ' ');
+ } else { /* !verbose !in_ns */
+ ret = trace_seq_printf(s, %4lld%s%c: , abs_ts);
Um, %s%c with no matching arguments.
Sorry for being so sloppy on these patches... Wonder why I didn't see
the printf warnings.
I'll send out an new patchset with this fixed, and include Yoshihiro
Yunomae's patches.
-- Steve
+ }
+ return ret;
}
--
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/
[PATCH v6 4/6] ftrace: Change unsigned long type of ring_buffer_oldest_event_ts() to u64
From: Yoshihiro YUNOMAE yoshihiro.yunomae...@hitachi.com
ring_buffer_oldest_event_ts() should return a value of u64 type, because
ring_buffer_per_cpu-buffer_page-buffer_data_page-time_stamp is u64 type.
Signed-off-by: Yoshihiro YUNOMAE yoshihiro.yunomae...@hitachi.com
Cc: Steven Rostedt rost...@goodmis.org
Cc: Frederic Weisbecker fweis...@gmail.com
Cc: Ingo Molnar mi...@redhat.com
Cc: Vaibhav Nagarnaik vnagarn...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
include/linux/ring_buffer.h |2 +-
kernel/trace/ring_buffer.c |4 ++--
2 files changed, 3 insertions(+), 3 deletions(-)
diff --git a/include/linux/ring_buffer.h b/include/linux/ring_buffer.h
index 6c8835f..c68a09a 100644
--- a/include/linux/ring_buffer.h
+++ b/include/linux/ring_buffer.h
@@ -159,7 +159,7 @@ int ring_buffer_record_is_on(struct ring_buffer *buffer);
void ring_buffer_record_disable_cpu(struct ring_buffer *buffer, int cpu);
void ring_buffer_record_enable_cpu(struct ring_buffer *buffer, int cpu);
-unsigned long ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu);
+u64 ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu);
unsigned long ring_buffer_bytes_cpu(struct ring_buffer *buffer, int cpu);
unsigned long ring_buffer_entries(struct ring_buffer *buffer);
unsigned long ring_buffer_overruns(struct ring_buffer *buffer);
diff --git a/kernel/trace/ring_buffer.c b/kernel/trace/ring_buffer.c
index 49491fa..db3806e 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -2925,12 +2925,12 @@ rb_num_of_entries(struct ring_buffer_per_cpu
*cpu_buffer)
* @buffer: The ring buffer
* @cpu: The per CPU buffer to read from.
*/
-unsigned long ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu)
+u64 ring_buffer_oldest_event_ts(struct ring_buffer *buffer, int cpu)
{
unsigned long flags;
struct ring_buffer_per_cpu *cpu_buffer;
struct buffer_page *bpage;
- unsigned long ret;
+ u64 ret;
if (!cpumask_test_cpu(cpu, buffer-cpumask))
return 0;
--
1.7.7.3
--
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/
[PATCH v6 0/6] TSC trace_clock
Added Yoshihiro Yonomae's patches to change the per_cpu stats to show raw timestamps when the clock is not in nanoseconds. Also added a small patch to fix a warning. David Sharp (4): tracing,x86: Add a TSC trace_clock tracing: Reset ring buffer when changing trace_clocks tracing: Format non-nanosec times from tsc clock without a decimal point. tracing: Fix maybe-uninitialized warning in ftrace_function_set_regexp Yoshihiro YUNOMAE (2): ftrace: Change unsigned long type of ring_buffer_oldest_event_ts() to u64 ftrace: Show raw time stamp on stats per cpu using counter or tsc mode for trace_clock arch/alpha/include/asm/trace_clock.h |6 ++ arch/arm/include/asm/trace_clock.h|6 ++ arch/avr32/include/asm/trace_clock.h |6 ++ arch/blackfin/include/asm/trace_clock.h |6 ++ arch/c6x/include/asm/trace_clock.h|6 ++ arch/cris/include/asm/trace_clock.h |6 ++ arch/frv/include/asm/trace_clock.h|6 ++ arch/h8300/include/asm/trace_clock.h |6 ++ arch/hexagon/include/asm/trace_clock.h|6 ++ arch/ia64/include/asm/trace_clock.h |6 ++ arch/m32r/include/asm/trace_clock.h |6 ++ arch/m68k/include/asm/trace_clock.h |6 ++ arch/microblaze/include/asm/trace_clock.h |6 ++ arch/mips/include/asm/trace_clock.h |6 ++ arch/mn10300/include/asm/trace_clock.h|6 ++ arch/openrisc/include/asm/trace_clock.h |6 ++ arch/parisc/include/asm/trace_clock.h |6 ++ arch/powerpc/include/asm/trace_clock.h|6 ++ arch/s390/include/asm/trace_clock.h |6 ++ arch/score/include/asm/trace_clock.h |6 ++ arch/sh/include/asm/trace_clock.h |6 ++ arch/sparc/include/asm/trace_clock.h |6 ++ arch/tile/include/asm/trace_clock.h |6 ++ arch/um/include/asm/trace_clock.h |6 ++ arch/unicore32/include/asm/trace_clock.h |6 ++ arch/x86/include/asm/trace_clock.h| 16 ++ arch/x86/kernel/Makefile |1 + arch/x86/kernel/trace_clock.c | 21 arch/xtensa/include/asm/trace_clock.h |6 ++ include/asm-generic/trace_clock.h | 16 ++ include/linux/ftrace_event.h |6 ++ include/linux/ring_buffer.h |2 +- include/linux/trace_clock.h |2 + kernel/trace/ring_buffer.c|4 +- kernel/trace/trace.c | 47 ++--- kernel/trace/trace.h |4 -- kernel/trace/trace_events_filter.c|3 +- kernel/trace/trace_output.c | 80 - 38 files changed, 316 insertions(+), 42 deletions(-) create mode 100644 arch/alpha/include/asm/trace_clock.h create mode 100644 arch/arm/include/asm/trace_clock.h create mode 100644 arch/avr32/include/asm/trace_clock.h create mode 100644 arch/blackfin/include/asm/trace_clock.h create mode 100644 arch/c6x/include/asm/trace_clock.h create mode 100644 arch/cris/include/asm/trace_clock.h create mode 100644 arch/frv/include/asm/trace_clock.h create mode 100644 arch/h8300/include/asm/trace_clock.h create mode 100644 arch/hexagon/include/asm/trace_clock.h create mode 100644 arch/ia64/include/asm/trace_clock.h create mode 100644 arch/m32r/include/asm/trace_clock.h create mode 100644 arch/m68k/include/asm/trace_clock.h create mode 100644 arch/microblaze/include/asm/trace_clock.h create mode 100644 arch/mips/include/asm/trace_clock.h create mode 100644 arch/mn10300/include/asm/trace_clock.h create mode 100644 arch/openrisc/include/asm/trace_clock.h create mode 100644 arch/parisc/include/asm/trace_clock.h create mode 100644 arch/powerpc/include/asm/trace_clock.h create mode 100644 arch/s390/include/asm/trace_clock.h create mode 100644 arch/score/include/asm/trace_clock.h create mode 100644 arch/sh/include/asm/trace_clock.h create mode 100644 arch/sparc/include/asm/trace_clock.h create mode 100644 arch/tile/include/asm/trace_clock.h create mode 100644 arch/um/include/asm/trace_clock.h create mode 100644 arch/unicore32/include/asm/trace_clock.h create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 arch/xtensa/include/asm/trace_clock.h create mode 100644 include/asm-generic/trace_clock.h -- 1.7.7.3 -- 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/
[PATCH v6 2/6] 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 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com --- 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 92fb08e..4e26df3 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -4012,6 +4012,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; -- 1.7.7.3 -- 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/
[PATCH v6 5/6] ftrace: Show raw time stamp on stats per cpu using counter or tsc mode for trace_clock
From: Yoshihiro YUNOMAE yoshihiro.yunomae...@hitachi.com
Show raw time stamp values for stats per cpu if you choose counter or tsc mode
for trace_clock. Although a unit of tracing time stamp is nsec in local or
global mode,
the units in counter and TSC mode are tracing counter and cycles respectively.
Signed-off-by: Yoshihiro YUNOMAE yoshihiro.yunomae...@hitachi.com
Cc: Steven Rostedt rost...@goodmis.org
Cc: Frederic Weisbecker fweis...@gmail.com
Cc: Ingo Molnar mi...@redhat.com
Signed-off-by: David Sharp dhsh...@google.com
---
kernel/trace/trace.c | 23 +--
1 files changed, 17 insertions(+), 6 deletions(-)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index cff3427..8bfa3b7 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -4396,13 +4396,24 @@ tracing_stats_read(struct file *filp, char __user *ubuf,
cnt = ring_buffer_bytes_cpu(tr-buffer, cpu);
trace_seq_printf(s, bytes: %ld\n, cnt);
- t = ns2usecs(ring_buffer_oldest_event_ts(tr-buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, oldest event ts: %5llu.%06lu\n, t, usec_rem);
+ if (trace_clocks[trace_clock_id].in_ns) {
+ /* local or global for trace_clock */
+ t = ns2usecs(ring_buffer_oldest_event_ts(tr-buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, oldest event ts: %5llu.%06lu\n,
+ t, usec_rem);
+
+ t = ns2usecs(ring_buffer_time_stamp(tr-buffer, cpu));
+ usec_rem = do_div(t, USEC_PER_SEC);
+ trace_seq_printf(s, now ts: %5llu.%06lu\n, t, usec_rem);
+ } else {
+ /* counter or tsc mode for trace_clock */
+ trace_seq_printf(s, oldest event ts: %llu\n,
+ ring_buffer_oldest_event_ts(tr-buffer, cpu));
- t = ns2usecs(ring_buffer_time_stamp(tr-buffer, cpu));
- usec_rem = do_div(t, USEC_PER_SEC);
- trace_seq_printf(s, now ts: %5llu.%06lu\n, t, usec_rem);
+ trace_seq_printf(s, now ts: %llu\n,
+ ring_buffer_time_stamp(tr-buffer, cpu));
+ }
count = simple_read_from_buffer(ubuf, count, ppos, s-buffer, s-len);
--
1.7.7.3
--
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/
[PATCH v6 6/6] tracing: Fix maybe-uninitialized warning in ftrace_function_set_regexp
Compiler warning:
kernel/trace/trace_events_filter.c: In function 'ftrace_function_set_filter_cb':
kernel/trace/trace_events_filter.c:2074:8: error: 'ret' may be used
uninitialized in this function [-Werror=maybe-uninitialized]
Signed-off-by: David Sharp dhsh...@google.com
Cc: Steven Rostedt rost...@goodmis.org
---
kernel/trace/trace_events_filter.c |3 ++-
1 files changed, 2 insertions(+), 1 deletions(-)
diff --git a/kernel/trace/trace_events_filter.c
b/kernel/trace/trace_events_filter.c
index 431dba8..ef36953 100644
--- a/kernel/trace/trace_events_filter.c
+++ b/kernel/trace/trace_events_filter.c
@@ -2002,9 +2002,10 @@ static int ftrace_function_set_regexp(struct ftrace_ops
*ops, int filter,
static int __ftrace_function_set_filter(int filter, char *buf, int len,
struct function_filter_data *data)
{
- int i, re_cnt, ret;
+ int i, re_cnt;
int *reset;
char **re;
+ int ret = 0;
reset = filter ? data-first_filter : data-first_notrace;
--
1.7.7.3
--
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/
[PATCH v6 1/6] 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 Google-Bug-Id: 6980623 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com Cc: Ingo Molnar mi...@kernel.org Cc: Thomas Gleixner t...@linutronix.de Cc: H. Peter Anvin h...@linux.intel.com Acked-by: Ingo Molnar mi...@kernel.org --- arch/alpha/include/asm/trace_clock.h |6 ++ arch/arm/include/asm/trace_clock.h|6 ++ arch/avr32/include/asm/trace_clock.h |6 ++ arch/blackfin/include/asm/trace_clock.h |6 ++ arch/c6x/include/asm/trace_clock.h|6 ++ arch/cris/include/asm/trace_clock.h |6 ++ arch/frv/include/asm/trace_clock.h|6 ++ arch/h8300/include/asm/trace_clock.h |6 ++ arch/hexagon/include/asm/trace_clock.h|6 ++ arch/ia64/include/asm/trace_clock.h |6 ++ arch/m32r/include/asm/trace_clock.h |6 ++ arch/m68k/include/asm/trace_clock.h |6 ++ arch/microblaze/include/asm/trace_clock.h |6 ++ arch/mips/include/asm/trace_clock.h |6 ++ arch/mn10300/include/asm/trace_clock.h|6 ++ arch/openrisc/include/asm/trace_clock.h |6 ++ arch/parisc/include/asm/trace_clock.h |6 ++ arch/powerpc/include/asm/trace_clock.h|6 ++ arch/s390/include/asm/trace_clock.h |6 ++ arch/score/include/asm/trace_clock.h |6 ++ arch/sh/include/asm/trace_clock.h |6 ++ arch/sparc/include/asm/trace_clock.h |6 ++ arch/tile/include/asm/trace_clock.h |6 ++ arch/um/include/asm/trace_clock.h |6 ++ arch/unicore32/include/asm/trace_clock.h |6 ++ arch/x86/include/asm/trace_clock.h| 16 arch/x86/kernel/Makefile |1 + arch/x86/kernel/trace_clock.c | 21 + arch/xtensa/include/asm/trace_clock.h |6 ++ include/asm-generic/trace_clock.h | 16 include/linux/trace_clock.h |2 ++ kernel/trace/trace.c |1 + 32 files changed, 213 insertions(+), 0 deletions(-) create mode 100644 arch/alpha/include/asm/trace_clock.h create mode 100644 arch/arm/include/asm/trace_clock.h create mode 100644 arch/avr32/include/asm/trace_clock.h create mode 100644 arch/blackfin/include/asm/trace_clock.h create mode 100644 arch/c6x/include/asm/trace_clock.h create mode 100644 arch/cris/include/asm/trace_clock.h create mode 100644 arch/frv/include/asm/trace_clock.h create mode 100644 arch/h8300/include/asm/trace_clock.h create mode 100644 arch/hexagon/include/asm/trace_clock.h create mode 100644 arch/ia64/include/asm/trace_clock.h create mode 100644 arch/m32r/include/asm/trace_clock.h create mode 100644 arch/m68k/include/asm/trace_clock.h create mode 100644 arch/microblaze/include/asm/trace_clock.h create mode 100644 arch/mips/include/asm/trace_clock.h create mode 100644 arch/mn10300/include/asm/trace_clock.h create mode 100644 arch/openrisc/include/asm/trace_clock.h create mode 100644 arch/parisc/include/asm/trace_clock.h create mode 100644 arch/powerpc/include/asm/trace_clock.h create mode 100644 arch/s390/include/asm/trace_clock.h create mode 100644 arch/score/include/asm/trace_clock.h create mode 100644 arch/sh/include/asm/trace_clock.h create mode 100644 arch/sparc/include/asm/trace_clock.h create mode 100644 arch/tile/include/asm/trace_clock.h create mode 100644 arch/um/include/asm/trace_clock.h create mode 100644 arch/unicore32/include/asm/trace_clock.h create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 arch/xtensa/include/asm/trace_clock.h create mode 100644 include/asm-generic/trace_clock.h diff --git a/arch/alpha/include/asm/trace_clock.h b/arch/alpha/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/alpha/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include asm-generic/trace_clock.h + +#endif diff --git a/arch/arm/include/asm/trace_clock.h b/arch/arm/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/arm/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include asm-generic/trace_clock.h + +#endif diff --git a/arch/avr32/include/asm
[PATCH v6 3/6] 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_enabled ; sleep 0.0005 ; echo 0 tracing_enabled
$ cat trace
idle-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
idle-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_enabled ; sleep 0.0005 ; echo 0 tracing_enabled
$ echo 0 options/latency-format
$ cat trace
idle-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
idle-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
Signed-off-by: David Sharp dhsh...@google.com
Cc: Steven Rostedt rost...@goodmis.org
Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com
---
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| 80 ---
5 files changed, 74 insertions(+), 33 deletions(-)
diff --git a/arch/x86/include/asm/trace_clock.h
b/arch/x86/include/asm/trace_clock.h
index 7ee0d8c..45e17f5 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 },
#endif
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 642928c..c760670 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 4e26df3..cff3427 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -476,10 +476,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
};
@@ -2425,6 +2426,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();
@@ -3324,6 +3329,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags TRACE_ITER_LATENCY_FMT)
iter-iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter-cpu_file = cpu_file;
iter-tr = global_trace;
mutex_init(iter-mutex);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index
Re: [PATCH v5 1/3] tracing,x86: Add a TSC trace_clock
On Mon, Oct 8, 2012 at 7:08 PM, Yoshihiro YUNOMAE yoshihiro.yunomae...@hitachi.com wrote: Hi David, This is a nice patch set. I just have found something should be fixed, which related to your work. I'll send it following this mail. Would you mind adding these patches as your patch series? Thanks for noticing the stats issue. Added them to my series. Thanks, Yoshihiro YUNOMAE (2012/10/02 12:31), David Sharp wrote: 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. -- Yoshihiro YUNOMAE Software Platform Research Dept. Linux Technology Center Hitachi, Ltd., Yokohama Research Laboratory E-mail: yoshihiro.yunomae...@hitachi.com -- 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/
Re: [PATCH 1/2] tracing: trivial cleanup
On Thu, Oct 11, 2012 at 6:56 PM, Steven Rostedt rost...@goodmis.org wrote:
Sorry, I know this is late, but it was pushed down in my todo list
(never off, but something I probably wouldn't have seen for a few more
months).
On Thu, 2012-06-07 at 16:46 -0700, Vaibhav Nagarnaik wrote:
From: David Sharp dhsh...@google.com
If this is from David it needs his SOB.
Is that true even though we are working for the same company?
-- Steve
Remove ftrace_format_syscall() declaration; it is neither defined nor
used. Also update a comment and formatting.
Signed-off-by: Vaibhav Nagarnaik vnagarn...@google.com
Signed-off-by: David Sharp dhsh...@google.com
---
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 1d0f6a8..96c2dd1 100644
--- a/kernel/trace/ring_buffer.c
+++ b/kernel/trace/ring_buffer.c
@@ -1816,7 +1816,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
@@ -2716,8 +2716,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/
Re: [PATCH v6 6/6] tracing: Fix maybe-uninitialized warning in ftrace_function_set_regexp
On Thu, Oct 11, 2012 at 6:36 PM, Steven Rostedt rost...@goodmis.org wrote:
On Thu, 2012-10-11 at 16:27 -0700, David Sharp wrote:
Compiler warning:
kernel/trace/trace_events_filter.c: In function
'ftrace_function_set_filter_cb':
kernel/trace/trace_events_filter.c:2074:8: error: 'ret' may be used
uninitialized in this function [-Werror=maybe-uninitialized]
Signed-off-by: David Sharp dhsh...@google.com
Cc: Steven Rostedt rost...@goodmis.org
---
kernel/trace/trace_events_filter.c |3 ++-
1 files changed, 2 insertions(+), 1 deletions(-)
diff --git a/kernel/trace/trace_events_filter.c
b/kernel/trace/trace_events_filter.c
index 431dba8..ef36953 100644
--- a/kernel/trace/trace_events_filter.c
+++ b/kernel/trace/trace_events_filter.c
@@ -2002,9 +2002,10 @@ static int ftrace_function_set_regexp(struct
ftrace_ops *ops, int filter,
static int __ftrace_function_set_filter(int filter, char *buf, int len,
struct function_filter_data *data)
{
- int i, re_cnt, ret;
+ int i, re_cnt;
int *reset;
char **re;
+ int ret = 0;
reset = filter ? data-first_filter : data-first_notrace;
It has already been fixed in mainline:
92d8d4a8b0f4c6eba70f6e62b48e38bd005a56e6
http://marc.info/?l=linux-kernelm=134012157512078
Okay, drop this one then. I haven't been rebasing.
--
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/
[PATCH v5 3/3] 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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
Signed-off-by: David Sharp
Cc: Steven Rostedt
Cc: Masami Hiramatsu
---
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| 81 +---
5 files changed, 75 insertions(+), 33 deletions(-)
diff --git a/arch/x86/include/asm/trace_clock.h
b/arch/x86/include/asm/trace_clock.h
index 7ee0d8c..45e17f5 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 },
#endif
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 642928c..c760670 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 4e26df3..cff3427 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -476,10 +476,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
};
@@ -2425,6 +2426,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();
@@ -3324,6 +3329,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags & TRACE_ITER_LATENCY_FMT)
iter->iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter->cpu_file = cpu_file;
[PATCH v5 2/3] 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 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu --- 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 92fb08e..4e26df3 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -4012,6 +4012,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(_trace); + if (max_tr.buffer) + tracing_reset_online_cpus(_tr); + mutex_unlock(_types_lock); *fpos += cnt; -- 1.7.7.3 -- 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/
[PATCH v5 1/3] 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 Google-Bug-Id: 6980623 Signed-off-by: David Sharp Cc: Steven Rostedt Cc: Masami Hiramatsu Cc: Ingo Molnar Cc: Thomas Gleixner Cc: "H. Peter Anvin" Acked-by: Ingo Molnar --- arch/alpha/include/asm/trace_clock.h |6 ++ arch/arm/include/asm/trace_clock.h|6 ++ arch/avr32/include/asm/trace_clock.h |6 ++ arch/blackfin/include/asm/trace_clock.h |6 ++ arch/c6x/include/asm/trace_clock.h|6 ++ arch/cris/include/asm/trace_clock.h |6 ++ arch/frv/include/asm/trace_clock.h|6 ++ arch/h8300/include/asm/trace_clock.h |6 ++ arch/hexagon/include/asm/trace_clock.h|6 ++ arch/ia64/include/asm/trace_clock.h |6 ++ arch/m32r/include/asm/trace_clock.h |6 ++ arch/m68k/include/asm/trace_clock.h |6 ++ arch/microblaze/include/asm/trace_clock.h |6 ++ arch/mips/include/asm/trace_clock.h |6 ++ arch/mn10300/include/asm/trace_clock.h|6 ++ arch/openrisc/include/asm/trace_clock.h |6 ++ arch/parisc/include/asm/trace_clock.h |6 ++ arch/powerpc/include/asm/trace_clock.h|6 ++ arch/s390/include/asm/trace_clock.h |6 ++ arch/score/include/asm/trace_clock.h |6 ++ arch/sh/include/asm/trace_clock.h |6 ++ arch/sparc/include/asm/trace_clock.h |6 ++ arch/tile/include/asm/trace_clock.h |6 ++ arch/um/include/asm/trace_clock.h |6 ++ arch/unicore32/include/asm/trace_clock.h |6 ++ arch/x86/include/asm/trace_clock.h| 16 arch/x86/kernel/Makefile |1 + arch/x86/kernel/trace_clock.c | 21 + arch/xtensa/include/asm/trace_clock.h |6 ++ include/asm-generic/trace_clock.h | 16 include/linux/trace_clock.h |2 ++ kernel/trace/trace.c |1 + 32 files changed, 213 insertions(+), 0 deletions(-) create mode 100644 arch/alpha/include/asm/trace_clock.h create mode 100644 arch/arm/include/asm/trace_clock.h create mode 100644 arch/avr32/include/asm/trace_clock.h create mode 100644 arch/blackfin/include/asm/trace_clock.h create mode 100644 arch/c6x/include/asm/trace_clock.h create mode 100644 arch/cris/include/asm/trace_clock.h create mode 100644 arch/frv/include/asm/trace_clock.h create mode 100644 arch/h8300/include/asm/trace_clock.h create mode 100644 arch/hexagon/include/asm/trace_clock.h create mode 100644 arch/ia64/include/asm/trace_clock.h create mode 100644 arch/m32r/include/asm/trace_clock.h create mode 100644 arch/m68k/include/asm/trace_clock.h create mode 100644 arch/microblaze/include/asm/trace_clock.h create mode 100644 arch/mips/include/asm/trace_clock.h create mode 100644 arch/mn10300/include/asm/trace_clock.h create mode 100644 arch/openrisc/include/asm/trace_clock.h create mode 100644 arch/parisc/include/asm/trace_clock.h create mode 100644 arch/powerpc/include/asm/trace_clock.h create mode 100644 arch/s390/include/asm/trace_clock.h create mode 100644 arch/score/include/asm/trace_clock.h create mode 100644 arch/sh/include/asm/trace_clock.h create mode 100644 arch/sparc/include/asm/trace_clock.h create mode 100644 arch/tile/include/asm/trace_clock.h create mode 100644 arch/um/include/asm/trace_clock.h create mode 100644 arch/unicore32/include/asm/trace_clock.h create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 arch/xtensa/include/asm/trace_clock.h create mode 100644 include/asm-generic/trace_clock.h diff --git a/arch/alpha/include/asm/trace_clock.h b/arch/alpha/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/alpha/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include + +#endif diff --git a/arch/arm/include/asm/trace_clock.h b/arch/arm/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/arm/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include + +#endif diff --git a/arch/avr32/include/asm/trace_clock.h b/arch/avr32/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/avr32/include/asm/trace_cl
Re: [PATCH v3 1/3] tracing,x86: add a TSC trace_clock
On Fri, Sep 28, 2012 at 8:15 PM, Steven Rostedt wrote: > On Thu, 2012-09-20 at 15:52 -0700, David Sharp wrote: > >> diff --git a/include/asm-generic/trace_clock.h >> b/include/asm-generic/trace_clock.h >> new file mode 100644 >> index 000..6726f1b >> --- /dev/null >> +++ b/include/asm-generic/trace_clock.h >> @@ -0,0 +1,16 @@ >> +#ifndef _ASM_GENERIC_TRACE_CLOCK_H >> +#define _ASM_GENERIC_TRACE_CLOCK_H >> +/* >> + * Arch-specific trace clocks. >> + */ >> + >> +/* >> + * Additional trace clocks added to the trace_clocks >> + * array in kernel/trace/trace.c >> + * None if the architecture has not defined it. >> + */ >> +#ifndef ARCH_TRACE_CLOCKS >> +# define ARCH_TRACE_CLOCKS >> +#endif >> + >> +#endif /* _ASM_GENERIC_TRACE_CLOCK_H */ > > Unfortunately this isn't enough. You need to add a stub in all > arch/*/include/asm/ directories. That has: Oh really? Okay. Sorry, I really don't know the mechanics of the arch trees. I'll work on that now, and then send you a new series since I forgot to send out my last update. > > --- trace_clock.h: > #ifndef _ASM_TRACE_CLOCK_H > #define _ASM_TRACE_CLOCK_H > > #include > > #endif > --- > > > Because running this against my cross-compile test, failed on all archs > but x86. > > -- Steve > > -- 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/
Re: [PATCH v3 1/3] tracing,x86: add a TSC trace_clock
On Fri, Sep 28, 2012 at 8:15 PM, Steven Rostedt rost...@goodmis.org wrote: On Thu, 2012-09-20 at 15:52 -0700, David Sharp wrote: diff --git a/include/asm-generic/trace_clock.h b/include/asm-generic/trace_clock.h new file mode 100644 index 000..6726f1b --- /dev/null +++ b/include/asm-generic/trace_clock.h @@ -0,0 +1,16 @@ +#ifndef _ASM_GENERIC_TRACE_CLOCK_H +#define _ASM_GENERIC_TRACE_CLOCK_H +/* + * Arch-specific trace clocks. + */ + +/* + * Additional trace clocks added to the trace_clocks + * array in kernel/trace/trace.c + * None if the architecture has not defined it. + */ +#ifndef ARCH_TRACE_CLOCKS +# define ARCH_TRACE_CLOCKS +#endif + +#endif /* _ASM_GENERIC_TRACE_CLOCK_H */ Unfortunately this isn't enough. You need to add a stub in all arch/*/include/asm/ directories. That has: Oh really? Okay. Sorry, I really don't know the mechanics of the arch trees. I'll work on that now, and then send you a new series since I forgot to send out my last update. --- trace_clock.h: #ifndef _ASM_TRACE_CLOCK_H #define _ASM_TRACE_CLOCK_H #include asm-generic/trace_clock.h #endif --- Because running this against my cross-compile test, failed on all archs but x86. -- Steve -- 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/
[PATCH v5 1/3] 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 Google-Bug-Id: 6980623 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com Cc: Ingo Molnar mi...@kernel.org Cc: Thomas Gleixner t...@linutronix.de Cc: H. Peter Anvin h...@linux.intel.com Acked-by: Ingo Molnar mi...@kernel.org --- arch/alpha/include/asm/trace_clock.h |6 ++ arch/arm/include/asm/trace_clock.h|6 ++ arch/avr32/include/asm/trace_clock.h |6 ++ arch/blackfin/include/asm/trace_clock.h |6 ++ arch/c6x/include/asm/trace_clock.h|6 ++ arch/cris/include/asm/trace_clock.h |6 ++ arch/frv/include/asm/trace_clock.h|6 ++ arch/h8300/include/asm/trace_clock.h |6 ++ arch/hexagon/include/asm/trace_clock.h|6 ++ arch/ia64/include/asm/trace_clock.h |6 ++ arch/m32r/include/asm/trace_clock.h |6 ++ arch/m68k/include/asm/trace_clock.h |6 ++ arch/microblaze/include/asm/trace_clock.h |6 ++ arch/mips/include/asm/trace_clock.h |6 ++ arch/mn10300/include/asm/trace_clock.h|6 ++ arch/openrisc/include/asm/trace_clock.h |6 ++ arch/parisc/include/asm/trace_clock.h |6 ++ arch/powerpc/include/asm/trace_clock.h|6 ++ arch/s390/include/asm/trace_clock.h |6 ++ arch/score/include/asm/trace_clock.h |6 ++ arch/sh/include/asm/trace_clock.h |6 ++ arch/sparc/include/asm/trace_clock.h |6 ++ arch/tile/include/asm/trace_clock.h |6 ++ arch/um/include/asm/trace_clock.h |6 ++ arch/unicore32/include/asm/trace_clock.h |6 ++ arch/x86/include/asm/trace_clock.h| 16 arch/x86/kernel/Makefile |1 + arch/x86/kernel/trace_clock.c | 21 + arch/xtensa/include/asm/trace_clock.h |6 ++ include/asm-generic/trace_clock.h | 16 include/linux/trace_clock.h |2 ++ kernel/trace/trace.c |1 + 32 files changed, 213 insertions(+), 0 deletions(-) create mode 100644 arch/alpha/include/asm/trace_clock.h create mode 100644 arch/arm/include/asm/trace_clock.h create mode 100644 arch/avr32/include/asm/trace_clock.h create mode 100644 arch/blackfin/include/asm/trace_clock.h create mode 100644 arch/c6x/include/asm/trace_clock.h create mode 100644 arch/cris/include/asm/trace_clock.h create mode 100644 arch/frv/include/asm/trace_clock.h create mode 100644 arch/h8300/include/asm/trace_clock.h create mode 100644 arch/hexagon/include/asm/trace_clock.h create mode 100644 arch/ia64/include/asm/trace_clock.h create mode 100644 arch/m32r/include/asm/trace_clock.h create mode 100644 arch/m68k/include/asm/trace_clock.h create mode 100644 arch/microblaze/include/asm/trace_clock.h create mode 100644 arch/mips/include/asm/trace_clock.h create mode 100644 arch/mn10300/include/asm/trace_clock.h create mode 100644 arch/openrisc/include/asm/trace_clock.h create mode 100644 arch/parisc/include/asm/trace_clock.h create mode 100644 arch/powerpc/include/asm/trace_clock.h create mode 100644 arch/s390/include/asm/trace_clock.h create mode 100644 arch/score/include/asm/trace_clock.h create mode 100644 arch/sh/include/asm/trace_clock.h create mode 100644 arch/sparc/include/asm/trace_clock.h create mode 100644 arch/tile/include/asm/trace_clock.h create mode 100644 arch/um/include/asm/trace_clock.h create mode 100644 arch/unicore32/include/asm/trace_clock.h create mode 100644 arch/x86/include/asm/trace_clock.h create mode 100644 arch/x86/kernel/trace_clock.c create mode 100644 arch/xtensa/include/asm/trace_clock.h create mode 100644 include/asm-generic/trace_clock.h diff --git a/arch/alpha/include/asm/trace_clock.h b/arch/alpha/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/alpha/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include asm-generic/trace_clock.h + +#endif diff --git a/arch/arm/include/asm/trace_clock.h b/arch/arm/include/asm/trace_clock.h new file mode 100644 index 000..f35fab8 --- /dev/null +++ b/arch/arm/include/asm/trace_clock.h @@ -0,0 +1,6 @@ +#ifndef _ASM_TRACE_CLOCK_H +#define _ASM_TRACE_CLOCK_H + +#include asm-generic/trace_clock.h + +#endif diff --git a/arch/avr32/include/asm
[PATCH v5 2/3] 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 Signed-off-by: David Sharp dhsh...@google.com Cc: Steven Rostedt rost...@goodmis.org Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com --- 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 92fb08e..4e26df3 100644 --- a/kernel/trace/trace.c +++ b/kernel/trace/trace.c @@ -4012,6 +4012,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; -- 1.7.7.3 -- 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/
[PATCH v5 3/3] 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_enabled ; sleep 0.0005 ; echo 0 tracing_enabled
$ cat trace
idle-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
idle-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_enabled ; sleep 0.0005 ; echo 0 tracing_enabled
$ echo 0 options/latency-format
$ cat trace
idle-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
idle-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
Signed-off-by: David Sharp dhsh...@google.com
Cc: Steven Rostedt rost...@goodmis.org
Cc: Masami Hiramatsu masami.hiramatsu...@hitachi.com
---
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| 81 +---
5 files changed, 75 insertions(+), 33 deletions(-)
diff --git a/arch/x86/include/asm/trace_clock.h
b/arch/x86/include/asm/trace_clock.h
index 7ee0d8c..45e17f5 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 },
#endif
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 642928c..c760670 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 4e26df3..cff3427 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -476,10 +476,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
};
@@ -2425,6 +2426,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();
@@ -3324,6 +3329,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags TRACE_ITER_LATENCY_FMT)
iter-iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter-cpu_file = cpu_file;
iter-tr = global_trace;
mutex_init(iter-mutex);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index
Re: [PATCH v4 3/3] tracing: format non-nanosec times from tsc clock without a decimal point.
On Wed, Sep 26, 2012 at 11:30 AM, Steven Rostedt wrote:
> On Tue, 2012-09-25 at 15:29 -0700, David Sharp wrote:
>
>> static int
>> -lat_print_timestamp(struct trace_seq *s, u64 abs_usecs,
>> - unsigned long rel_usecs)
>> +lat_print_timestamp(struct trace_iterator *iter, u64 next_ts)
>> {
>> - return trace_seq_printf(s, " %4lldus%c: ", abs_usecs,
>> - rel_usecs > preempt_mark_thresh ? '!' :
>> - rel_usecs > 1 ? '+' : ' ');
>> + unsigned long verbose = trace_flags & TRACE_ITER_VERBOSE;
>> + unsigned long in_ns = iter->iter_flags & TRACE_FILE_TIME_IN_NS;
>> + unsigned long long abs_ts = iter->ts - iter->tr->time_start;
>> + unsigned long long rel_ts = next_ts - iter->ts;
>> + struct trace_seq *s = >seq;
>> + unsigned long mark_thresh;
>> + int ret;
>> +
>> + if (in_ns) {
>> + abs_ts = ns2usecs(abs_ts);
>> + rel_ts = ns2usecs(rel_ts);
>> + mark_thresh = preempt_mark_thresh_us;
>> + } else
>> + mark_thresh = preempt_mark_thresh_cycles;
>> +
>> + if (verbose && in_ns) {
>> + unsigned long abs_msec = abs_ts;
>> + unsigned long abs_usec = do_div(abs_msec, USEC_PER_MSEC);
>> + unsigned long rel_msec = rel_ts;
>> + unsigned long rel_usec = do_div(rel_msec, USEC_PER_MSEC);
>> +
>> + ret = trace_seq_printf(
>> + s, "[%08llx] %ld.%03ldms (+%ld.%03ldms): ",
>> + ns2usecs(iter->ts),
>> + abs_msec, abs_usec,
>> + rel_msec, rel_usec);
>> + } else if (verbose && !in_ns) {
>> + ret = trace_seq_printf(
>> + s, "[%016llx] %lld (+%lld): ",
>> + iter->ts, abs_ts, rel_ts);
>> + } else { /* !verbose */
>> + ret = trace_seq_printf(
>> + s, " %4lld%s%c: ",
>> + abs_ts,
>> + in_ns ? "us" : "",
>> + rel_ts > mark_thresh ? '!' :
>> + rel_ts > 1 ? '+' : ' ');
>
> I still think the annotations are meaningless for counters. Even if the
> counter is a timer like the tsc, as it does not coincide with real time
> (us), I say just don't print it for counters.
Sounds fine to me, as that's the easiest modification anyway. Done.
>
> This is not helpful:
>
>
Agreed. The other way to fix it would have been to change the "+"
threshold from 1 to ~2000.
>
>
>> + }
>> + return ret;
>> }
>>
>> int trace_print_context(struct trace_iterator *iter)
>> {
>> struct trace_seq *s = >seq;
>> struct trace_entry *entry = iter->ent;
>> - unsigned long long t = ns2usecs(iter->ts);
>> - unsigned long usec_rem = do_div(t, USEC_PER_SEC);
>> - unsigned long secs = (unsigned long)t;
>> + unsigned long long t;
>> + unsigned long secs, usec_rem;
>> char comm[TASK_COMM_LEN];
>> int ret;
>>
>> @@ -644,8 +680,13 @@ int trace_print_context(struct trace_iterator *iter)
>> return 0;
>> }
>>
>> - return trace_seq_printf(s, " %5lu.%06lu: ",
>> - secs, usec_rem);
>> + if (iter->iter_flags & TRACE_FILE_TIME_IN_NS) {
>> + t = ns2usecs(iter->ts);
>> + usec_rem = do_div(t, USEC_PER_SEC);
>> + secs = (unsigned long)t;
>> + return trace_seq_printf(s, "%5lu.%06lu: ", secs, usec_rem);
>
> You took away the space before %5.
>
>> + } else
>> + return trace_seq_printf(s, "%12llu: ", iter->ts);
>
> here too.
Don't know why I would have changed that... Fixed.
>> }
>>
>> int trace_print_lat_context(struct trace_iterator *iter)
>> @@ -659,36 +700,29 @@ int trace_print_lat_context(struct trace_iterator
>> *iter)
>> *next_entry = trace_find_next_entry(iter, NULL,
>> _ts);
>> unsigned long verbose = (trace_flags & TRACE_ITER_VERBOSE);
>> - unsigned long abs_usecs = ns2usecs(iter->ts - iter->tr->time_start);
>> - unsigned long rel_usecs;
>>
>> /* Restore the original ent_size */
>> iter->ent_size = ent_size;
>>
>> if (!next_entry)
>> next_ts = iter->ts;
>> - rel_usecs = ns2usecs(next_ts - iter->ts);
>
>
--
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/
Re: [PATCH v4 3/3] tracing: format non-nanosec times from tsc clock without a decimal point.
On Wed, Sep 26, 2012 at 11:30 AM, Steven Rostedt rost...@goodmis.org wrote:
On Tue, 2012-09-25 at 15:29 -0700, David Sharp wrote:
static int
-lat_print_timestamp(struct trace_seq *s, u64 abs_usecs,
- unsigned long rel_usecs)
+lat_print_timestamp(struct trace_iterator *iter, u64 next_ts)
{
- return trace_seq_printf(s, %4lldus%c: , abs_usecs,
- rel_usecs preempt_mark_thresh ? '!' :
- rel_usecs 1 ? '+' : ' ');
+ unsigned long verbose = trace_flags TRACE_ITER_VERBOSE;
+ unsigned long in_ns = iter-iter_flags TRACE_FILE_TIME_IN_NS;
+ unsigned long long abs_ts = iter-ts - iter-tr-time_start;
+ unsigned long long rel_ts = next_ts - iter-ts;
+ struct trace_seq *s = iter-seq;
+ unsigned long mark_thresh;
+ int ret;
+
+ if (in_ns) {
+ abs_ts = ns2usecs(abs_ts);
+ rel_ts = ns2usecs(rel_ts);
+ mark_thresh = preempt_mark_thresh_us;
+ } else
+ mark_thresh = preempt_mark_thresh_cycles;
+
+ if (verbose in_ns) {
+ unsigned long abs_msec = abs_ts;
+ unsigned long abs_usec = do_div(abs_msec, USEC_PER_MSEC);
+ unsigned long rel_msec = rel_ts;
+ unsigned long rel_usec = do_div(rel_msec, USEC_PER_MSEC);
+
+ ret = trace_seq_printf(
+ s, [%08llx] %ld.%03ldms (+%ld.%03ldms): ,
+ ns2usecs(iter-ts),
+ abs_msec, abs_usec,
+ rel_msec, rel_usec);
+ } else if (verbose !in_ns) {
+ ret = trace_seq_printf(
+ s, [%016llx] %lld (+%lld): ,
+ iter-ts, abs_ts, rel_ts);
+ } else { /* !verbose */
+ ret = trace_seq_printf(
+ s, %4lld%s%c: ,
+ abs_ts,
+ in_ns ? us : ,
+ rel_ts mark_thresh ? '!' :
+ rel_ts 1 ? '+' : ' ');
I still think the annotations are meaningless for counters. Even if the
counter is a timer like the tsc, as it does not coincide with real time
(us), I say just don't print it for counters.
Sounds fine to me, as that's the easiest modification anyway. Done.
This is not helpful:
snip
Agreed. The other way to fix it would have been to change the +
threshold from 1 to ~2000.
+ }
+ return ret;
}
int trace_print_context(struct trace_iterator *iter)
{
struct trace_seq *s = iter-seq;
struct trace_entry *entry = iter-ent;
- unsigned long long t = ns2usecs(iter-ts);
- unsigned long usec_rem = do_div(t, USEC_PER_SEC);
- unsigned long secs = (unsigned long)t;
+ unsigned long long t;
+ unsigned long secs, usec_rem;
char comm[TASK_COMM_LEN];
int ret;
@@ -644,8 +680,13 @@ int trace_print_context(struct trace_iterator *iter)
return 0;
}
- return trace_seq_printf(s, %5lu.%06lu: ,
- secs, usec_rem);
+ if (iter-iter_flags TRACE_FILE_TIME_IN_NS) {
+ t = ns2usecs(iter-ts);
+ usec_rem = do_div(t, USEC_PER_SEC);
+ secs = (unsigned long)t;
+ return trace_seq_printf(s, %5lu.%06lu: , secs, usec_rem);
You took away the space before %5.
+ } else
+ return trace_seq_printf(s, %12llu: , iter-ts);
here too.
Don't know why I would have changed that... Fixed.
}
int trace_print_lat_context(struct trace_iterator *iter)
@@ -659,36 +700,29 @@ int trace_print_lat_context(struct trace_iterator
*iter)
*next_entry = trace_find_next_entry(iter, NULL,
next_ts);
unsigned long verbose = (trace_flags TRACE_ITER_VERBOSE);
- unsigned long abs_usecs = ns2usecs(iter-ts - iter-tr-time_start);
- unsigned long rel_usecs;
/* Restore the original ent_size */
iter-ent_size = ent_size;
if (!next_entry)
next_ts = iter-ts;
- rel_usecs = ns2usecs(next_ts - iter-ts);
--
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/
Re: [PATCH v4 3/3] tracing: format non-nanosec times from tsc clock without a decimal point.
On Tue, Sep 25, 2012 at 4:36 PM, Steven Rostedt wrote:
> On Tue, 2012-09-25 at 15:29 -0700, David Sharp wrote:
>
>
>> >> + ret = trace_seq_printf(
>> >> + s, "[%08llx] %ld.%03ldms (+%ld.%03ldms): ",
>> >> + ns2usecs(iter->ts),
>> >> + abs_msec, abs_usec,
>> >> + rel_msec, rel_usec);
>> >> + } else if (verbose && !in_ns) {
>> >> + ret = trace_seq_printf(
>> >> + s, "[%016llx] %lld (+%lld): ",
>> >> + iter->ts, abs_ts, rel_ts);
>> >> + } else { /* !verbose */
>> >> + ret = trace_seq_printf(
>> >> + s, " %4lld%s%c: ",
>> >> + abs_ts,
>> >> + in_ns ? "us" : "",
>> >> + rel_ts > mark_thresh ? '!' :
>> >> + rel_ts > 1 ? '+' : ' ');
>>
>> I just noticed something about this: with x86-tsc clock, this will
>> always print a '+'. Does it matter? Also, is the 200k cycle threshold
>> for '!' okay? I guess the counter clock will always end up with rel_ts
>> == 1, so marks should never appear.
>>
>
> Actually, I'm thinking that counters should not add those annotations.
> As it just doesn't make sense.
Right. But they won't appear anyway, since the delta will always be 1.
wait, by "counters" are you including TSC? Surely that makes sense,
since it is a measurement of time.
Eh... sorry I brought it up. I don't really want to change it. I never
use the latency tracer, so I mostly just don't want to break it.
--
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/
[PATCH v4 3/3] 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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
Signed-off-by: David Sharp
Cc: Steven Rostedt
Cc: Masami Hiramatsu
---
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| 84 +---
5 files changed, 78 insertions(+), 33 deletions(-)
diff --git a/arch/x86/include/asm/trace_clock.h
b/arch/x86/include/asm/trace_clock.h
index 7ee0d8c..45e17f5 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 },
#endif
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 642928c..c760670 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 4e26df3..cff3427 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -476,10 +476,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
};
@@ -2425,6 +2426,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();
@@ -3324,6 +3329,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags & TRACE_ITER_LATENCY_FMT)
iter->iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter->cpu_file = cpu_file;
Re: [PATCH v4 3/3] tracing: format non-nanosec times from tsc clock without a decimal point.
On Tue, Sep 25, 2012 at 2:42 PM, Steven Rostedt wrote:
> Sorry, I should have been more picky before. I haven't totally tested
> this yet.
>
> On Tue, 2012-09-25 at 13:49 -0700, David Sharp wrote:
>> 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
>> $ 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
>> $ 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
>> Signed-off-by: David Sharp
>> Cc: Steven Rostedt
>> Cc: Masami Hiramatsu
>> ---
>> 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| 84
>> +---
>> 5 files changed, 78 insertions(+), 33 deletions(-)
>>
>> diff --git a/arch/x86/include/asm/trace_clock.h
>> b/arch/x86/include/asm/trace_clock.h
>> index 7ee0d8c..45e17f5 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 },
>>
>> #endif
>>
>> diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
>> index 642928c..c760670 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 4e26df3..3fe4c5b 100644
>> --- a/kernel/trace/trace.c
>> +++ b/kernel/trace/trace.c
>> @@ -476,10 +476,11 @@ static const char *trace_options[] = {
>> static struct {
>> u64 (*func)(void);
>> const char *name;
>> + int in_ns; /* is this clock in nanoseconds? */
>
> Add a few tabs between the ns; and /*
Done.
>
>
>> } trace_clocks[] = {
>> - { trace_clock_local,"local" },
>> - { trace_clock_global, &qu
[PATCH v4 3/3] 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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_enabled ; sleep 0.0005 ; echo 0 > tracing_enabled
$ 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
Signed-off-by: David Sharp
Cc: Steven Rostedt
Cc: Masami Hiramatsu
---
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| 84 +---
5 files changed, 78 insertions(+), 33 deletions(-)
diff --git a/arch/x86/include/asm/trace_clock.h
b/arch/x86/include/asm/trace_clock.h
index 7ee0d8c..45e17f5 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 },
#endif
diff --git a/include/linux/ftrace_event.h b/include/linux/ftrace_event.h
index 642928c..c760670 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 4e26df3..3fe4c5b 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -476,10 +476,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
};
@@ -2425,6 +2426,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();
@@ -3324,6 +3329,10 @@ static int tracing_open_pipe(struct inode *inode, struct
file *filp)
if (trace_flags & TRACE_ITER_LATENCY_FMT)
iter->iter_flags |= TRACE_FILE_LAT_FMT;
+ /* 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;
+
iter->cpu_file = cpu_file;
iter-&g
Re: [PATCH v3 3/3] tracing: format non-nanosec times from tsc clock without a decimal point.
On Mon, Sep 24, 2012 at 8:27 PM, Steven Rostedt wrote:
> On Thu, 2012-09-20 at 15:52 -0700, David Sharp wrote:
>> 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.
>
> I got this:
>
> /work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
> undefined reference to `__umoddi3'
> /work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
> undefined reference to `__udivdi3'
> /work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
> undefined reference to `__umoddi3'
> /work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
> undefined reference to `__umoddi3'
> /work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
> undefined reference to `__udivdi3'
> /work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
> undefined reference to `__umoddi3'
> /work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
> undefined reference to `__udivdi3'
>
> when building for x86_32.
>
>> + int ret;
>> + struct trace_seq *s = >seq;
>> + unsigned long verbose = trace_flags & TRACE_ITER_VERBOSE;
>> + unsigned long in_ns = iter->iter_flags & TRACE_FILE_TIME_IN_NS;
>> + unsigned long long abs_ts = iter->ts - iter->tr->time_start;
>> + unsigned long long rel_ts = next_ts - iter->ts;
>> + unsigned long mark_thresh;
>> +
>> + if (in_ns) {
>> + abs_ts = ns2usecs(abs_ts);
>> + rel_ts = ns2usecs(rel_ts);
>> + mark_thresh = preempt_mark_thresh_us;
>> + } else
>> + mark_thresh = preempt_mark_thresh_cycles;
>> +
>> + if (verbose && in_ns) {
>> + ret = trace_seq_printf(
>> + s, "[%08llx] %lld.%03lldms (+%lld.%03lldms): ",
>> + ns2usecs(iter->ts),
>> + abs_ts / USEC_PER_MSEC,
>> + abs_ts % USEC_PER_MSEC,
>> + rel_ts / USEC_PER_MSEC,
>
> You can't divide 64 bit numbers in the kernel. It breaks on 32bit archs.
I didn't realize that. Sorry. Not sure why I changed them to long long
in the first place.
Although, that does mean that it is currently overflowing every 4.29
seconds. I may as well fix that.
>
> -- Steve
>
>> + rel_ts % USEC_PER_MSEC);
>> + } else if (verbose && !in_ns) {
>> + ret = trace_seq_printf(
>> + s, "[%016llx] %lld (+%lld): ",
>> + iter->ts, abs_ts, rel_ts);
>> + } else { /* !verbose */
>> + ret = trace_seq_printf(
>> + s, " %4lld%s%c: ",
>> + abs_ts,
>> + in_ns ? "us" : "",
>> + rel_ts > mark_thresh ? '!' :
>> + rel_ts > 1 ? '+' : ' ');
>> + }
>> + return ret;
>> }
>>
>> int trace_print_context(struct trace_iterator *iter)
>> {
>> struct trace_seq *s = >seq;
>> struct trace_entry *entry = iter->ent;
>> - unsigned long long t = ns2usecs(iter->ts);
>> - unsigned long usec_rem = do_div(t, USEC_PER_SEC);
>> - unsigned long secs = (unsigned long)t;
>> + unsigned long long t;
>> + unsigned long secs, usec_rem;
>> char comm[TASK_COMM_LEN];
>> int ret;
>>
>> @@ -644,8 +677,13 @@ int trace_print_context(struct trace_iterator *iter)
>> return 0;
>> }
>>
>> - return trace_seq_printf(s, " %5lu.%06lu: ",
>> - secs, usec_rem);
>> + if (iter->iter_flags & TRACE_FILE_TIME_IN_NS) {
>> + t = ns2usecs(iter->ts);
>> + usec_rem = do_div(t, USEC_PER_SEC);
>> + secs = (unsigned long)t;
>> + return trace_seq_printf(s, "%5lu.%06lu: ", secs, usec_rem);
>> + } else
>> + return trace_seq_printf(s, "%12llu: ", iter->ts);
>> }
>>
>> int trace_print_lat_context(struct trace_iterator *iter)
>> @@ -659,36 +697,30 @@ int trace_print_lat_context(struct trace_iterator
>> *iter)
>> *next_entry = trace_find_next_
Re: [PATCH v3 3/3] tracing: format non-nanosec times from tsc clock without a decimal point.
On Mon, Sep 24, 2012 at 8:27 PM, Steven Rostedt rost...@goodmis.org wrote:
On Thu, 2012-09-20 at 15:52 -0700, David Sharp wrote:
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.
I got this:
/work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
undefined reference to `__umoddi3'
/work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
undefined reference to `__udivdi3'
/work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
undefined reference to `__umoddi3'
/work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
undefined reference to `__umoddi3'
/work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
undefined reference to `__udivdi3'
/work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
undefined reference to `__umoddi3'
/work/autotest/nobackup/linux-test.git/kernel/trace/trace_output.c:636:
undefined reference to `__udivdi3'
when building for x86_32.
+ int ret;
+ struct trace_seq *s = iter-seq;
+ unsigned long verbose = trace_flags TRACE_ITER_VERBOSE;
+ unsigned long in_ns = iter-iter_flags TRACE_FILE_TIME_IN_NS;
+ unsigned long long abs_ts = iter-ts - iter-tr-time_start;
+ unsigned long long rel_ts = next_ts - iter-ts;
+ unsigned long mark_thresh;
+
+ if (in_ns) {
+ abs_ts = ns2usecs(abs_ts);
+ rel_ts = ns2usecs(rel_ts);
+ mark_thresh = preempt_mark_thresh_us;
+ } else
+ mark_thresh = preempt_mark_thresh_cycles;
+
+ if (verbose in_ns) {
+ ret = trace_seq_printf(
+ s, [%08llx] %lld.%03lldms (+%lld.%03lldms): ,
+ ns2usecs(iter-ts),
+ abs_ts / USEC_PER_MSEC,
+ abs_ts % USEC_PER_MSEC,
+ rel_ts / USEC_PER_MSEC,
You can't divide 64 bit numbers in the kernel. It breaks on 32bit archs.
I didn't realize that. Sorry. Not sure why I changed them to long long
in the first place.
Although, that does mean that it is currently overflowing every 4.29
seconds. I may as well fix that.
-- Steve
+ rel_ts % USEC_PER_MSEC);
+ } else if (verbose !in_ns) {
+ ret = trace_seq_printf(
+ s, [%016llx] %lld (+%lld): ,
+ iter-ts, abs_ts, rel_ts);
+ } else { /* !verbose */
+ ret = trace_seq_printf(
+ s, %4lld%s%c: ,
+ abs_ts,
+ in_ns ? us : ,
+ rel_ts mark_thresh ? '!' :
+ rel_ts 1 ? '+' : ' ');
+ }
+ return ret;
}
int trace_print_context(struct trace_iterator *iter)
{
struct trace_seq *s = iter-seq;
struct trace_entry *entry = iter-ent;
- unsigned long long t = ns2usecs(iter-ts);
- unsigned long usec_rem = do_div(t, USEC_PER_SEC);
- unsigned long secs = (unsigned long)t;
+ unsigned long long t;
+ unsigned long secs, usec_rem;
char comm[TASK_COMM_LEN];
int ret;
@@ -644,8 +677,13 @@ int trace_print_context(struct trace_iterator *iter)
return 0;
}
- return trace_seq_printf(s, %5lu.%06lu: ,
- secs, usec_rem);
+ if (iter-iter_flags TRACE_FILE_TIME_IN_NS) {
+ t = ns2usecs(iter-ts);
+ usec_rem = do_div(t, USEC_PER_SEC);
+ secs = (unsigned long)t;
+ return trace_seq_printf(s, %5lu.%06lu: , secs, usec_rem);
+ } else
+ return trace_seq_printf(s, %12llu: , iter-ts);
}
int trace_print_lat_context(struct trace_iterator *iter)
@@ -659,36 +697,30 @@ int trace_print_lat_context(struct trace_iterator
*iter)
*next_entry = trace_find_next_entry(iter, NULL,
next_ts);
unsigned long verbose = (trace_flags TRACE_ITER_VERBOSE);
- unsigned long abs_usecs = ns2usecs(iter-ts - iter-tr-time_start);
- unsigned long rel_usecs;
+
/* Restore the original ent_size */
iter-ent_size = ent_size;
if (!next_entry)
next_ts = iter-ts;
- rel_usecs = ns2usecs(next_ts - iter-ts);
if (verbose) {
char comm[TASK_COMM_LEN];
trace_find_cmdline(entry-pid, comm);
- ret = trace_seq_printf(s, %16s %5d %3d %d %08x %08lx [%08llx]
- %ld.%03ldms (+%ld.%03ldms): , comm,
-entry-pid, iter-cpu, entry-flags,
-entry-preempt_count, iter-idx
