* [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp
@ 2013-04-24 23:12 Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 1/3] trace-cmd: Define general functions for outputting/inputting saved_cmdlines Yoshihiro YUNOMAE
` (3 more replies)
0 siblings, 4 replies; 6+ messages in thread
From: Yoshihiro YUNOMAE @ 2013-04-24 23:12 UTC (permalink / raw)
To: Steven Rostedt
Cc: Hidehiro Kawai, Masami Hiramatsu, linux-kernel, yrl.pp-manager.tt
Hi Steven,
This patch series extracts the trace_clock file for switching outputting format
of timestamp. This patch series uses the options feature, so trace-cmd keeps
backward compatibility.
In tsc or counter modes, trace-cmd should output timestamp not in the sec.usec
format but in the raw format. For example, we will show results in trace-cmd
report mode as follows by applying this patch series:
<for local or global mode>
bash-9022 [000] 34984.109846: sched_wakeup: comm=migration/3 pid=23 prio=0 success=1 target_cpu=003
<idle>-0 [002] 34984.109847: cpu_idle: state=4294967295 cpu_id=2
bash-9022 [000] 34984.109848: sched_switch: prev_comm=bash prev_pid=9022 prev_prio=120 prev_state=R ==> next_comm=migration/0 next_pid=8 next_prio=0
<idle>-0 [002] 34984.109849: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=migration/2 next_pid=18 next_prio=0
<for tsc or counter mode>
bash-9022 [000] 34984109846: sched_wakeup: comm=migration/3 pid=23 prio=0 success=1 target_cpu=003
<idle>-0 [002] 34984109847: cpu_idle: state=4294967295 cpu_id=2
bash-9022 [000] 34984109848: sched_switch: prev_comm=bash prev_pid=9022 prev_prio=120 prev_state=R ==> next_comm=migration/0 next_pid=8 next_prio=0
<idle>-0 [002] 34984109849: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=migration/2 next_pid=18 next_prio=0
v2:
- Separate input/output patches (2/3 and 3/3)
- Define TRACECMD_OPTION_TRACECLOCK for extracting trace_clock (2/3)
- Check whether TRACECMD_OPTION_TRACECLOCK exists or not in trace.dat (3/3)
v3:
- a file variable in save_tracing_file_data() is freed when operation is failed
(1/3)
- check the return value of get_tracing_file() in save_tracing_file_data()
(1/3)
Thank you,
---
Yoshihiro YUNOMAE (3):
trace-cmd: Define general functions for outputting/inputting saved_cmdlines
trace-cmd: Add recording to trace_clock
trace-cmd: Add support for extracting trace_clock in report
event-parse.c | 50 ++++++++++++++++++++++++++++-------
event-parse.h | 6 ++++
trace-cmd.h | 3 ++
trace-input.c | 79 ++++++++++++++++++++++++++++++++++++++++++++++----------
trace-output.c | 71 +++++++++++++++++++++++++++++++-------------------
trace-read.c | 4 ++-
trace-record.c | 3 ++
trace-util.c | 26 ++++++++++++++++++
8 files changed, 188 insertions(+), 54 deletions(-)
--
Yoshihiro YUNOMAE
Software Platform Research Dept. Linux Technology Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: yoshihiro.yunomae.ez@hitachi.com
^ permalink raw reply [flat|nested] 6+ messages in thread
* [PATCH V3 1/3] trace-cmd: Define general functions for outputting/inputting saved_cmdlines
2013-04-24 23:12 [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
@ 2013-04-24 23:13 ` Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 2/3] trace-cmd: Add recording to trace_clock Yoshihiro YUNOMAE
` (2 subsequent siblings)
3 siblings, 0 replies; 6+ messages in thread
From: Yoshihiro YUNOMAE @ 2013-04-24 23:13 UTC (permalink / raw)
To: Steven Rostedt
Cc: Hidehiro Kawai, Masami Hiramatsu, linux-kernel, yrl.pp-manager.tt
Currently, trace-cmd outputs data of saved_cmdlines to a trace.dat file
in create_file_fd() and inputs the data from the file in tracecmd_init_data().
On the other hand, trace-cmd will also output and input data of trace_clock in
those functions in the patch "trace-cmd: Add recording to trace_clock" and
"Add support for extracting trace_clock in report".
The source code of the output/input of saved_cmdlines data can be reused when
extract trace_clock, so we define general functions for outputting/inputting a
file on debugfs.
Change in v3:
- a file variable in save_tracing_file_data() is freed when operation is failed
- check the return value of get_tracing_file() in save_tracing_file_data()
Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez@hitachi.com>
---
trace-input.c | 46 ++++++++++++++++++++++++++------------
trace-output.c | 68 ++++++++++++++++++++++++++++++++++----------------------
2 files changed, 73 insertions(+), 41 deletions(-)
diff --git a/trace-input.c b/trace-input.c
index 56a8e8d..232015a 100644
--- a/trace-input.c
+++ b/trace-input.c
@@ -1870,6 +1870,37 @@ static int read_cpu_data(struct tracecmd_input *handle)
}
+static int read_data_and_size(struct tracecmd_input *handle,
+ char **data, unsigned long long *size)
+{
+ *size = read8(handle);
+ if (*size < 0)
+ return -1;
+ *data = malloc(*size + 1);
+ if (!*data)
+ return -1;
+ if (do_read_check(handle, *data, *size)) {
+ free(*data);
+ return -1;
+ }
+
+ return 0;
+}
+
+static int read_and_parse_cmdlines(struct tracecmd_input *handle,
+ struct pevent *pevent)
+{
+ unsigned long long size;
+ char *cmdlines;
+
+ if (read_data_and_size(handle, &cmdlines, &size) < 0)
+ return -1;
+ cmdlines[size] = 0;
+ parse_cmdlines(pevent, cmdlines, size);
+ free(cmdlines);
+ return 0;
+}
+
/**
* tracecmd_init_data - prepare reading the data from trace.dat
* @handle: input handle for the trace.dat file
@@ -1880,23 +1911,10 @@ static int read_cpu_data(struct tracecmd_input *handle)
int tracecmd_init_data(struct tracecmd_input *handle)
{
struct pevent *pevent = handle->pevent;
- unsigned long long size;
- char *cmdlines;
int ret;
- size = read8(handle);
- if (size < 0)
- return -1;
- cmdlines = malloc(size + 1);
- if (!cmdlines)
+ if (read_and_parse_cmdlines(handle, pevent) < 0)
return -1;
- if (do_read_check(handle, cmdlines, size)) {
- free(cmdlines);
- return -1;
- }
- cmdlines[size] = 0;
- parse_cmdlines(pevent, cmdlines, size);
- free(cmdlines);
handle->cpus = read4(handle);
if (handle->cpus < 0)
diff --git a/trace-output.c b/trace-output.c
index 460b773..cc71adf 100644
--- a/trace-output.c
+++ b/trace-output.c
@@ -687,6 +687,45 @@ static int read_ftrace_printk(struct tracecmd_output *handle)
return -1;
}
+static int save_tracing_file_data(struct tracecmd_output *handle,
+ const char *filename)
+{
+ unsigned long long endian8;
+ char *file = NULL;
+ struct stat st;
+ off64_t check_size;
+ off64_t size;
+ int ret = -1;
+
+ file = get_tracing_file(handle, filename);
+ if (!file)
+ return -1;
+
+ ret = stat(file, &st);
+ if (ret >= 0) {
+ size = get_size(file);
+ endian8 = convert_endian_8(handle, size);
+ if (do_write_check(handle, &endian8, 8))
+ goto out_free;
+ check_size = copy_file(handle, file);
+ if (size != check_size) {
+ errno = EINVAL;
+ warning("error in size of file '%s'", file);
+ goto out_free;
+ }
+ } else {
+ size = 0;
+ endian8 = convert_endian_8(handle, size);
+ if (do_write_check(handle, &endian8, 8))
+ goto out_free;
+ }
+ ret = 0;
+
+out_free:
+ put_tracing_file(file);
+ return ret;
+}
+
static struct tracecmd_output *
create_file_fd(int fd, struct tracecmd_input *ihandle,
const char *tracing_dir,
@@ -694,15 +733,9 @@ create_file_fd(int fd, struct tracecmd_input *ihandle,
struct tracecmd_event_list *list)
{
struct tracecmd_output *handle;
- unsigned long long endian8;
struct pevent *pevent;
char buf[BUFSIZ];
- char *file = NULL;
- struct stat st;
- off64_t check_size;
- off64_t size;
int endian4;
- int ret;
handle = malloc(sizeof(*handle));
if (!handle)
@@ -775,27 +808,8 @@ create_file_fd(int fd, struct tracecmd_input *ihandle,
/*
* Save the command lines;
*/
- file = get_tracing_file(handle, "saved_cmdlines");
- ret = stat(file, &st);
- if (ret >= 0) {
- size = get_size(file);
- endian8 = convert_endian_8(handle, size);
- if (do_write_check(handle, &endian8, 8))
- goto out_free;
- check_size = copy_file(handle, file);
- if (size != check_size) {
- errno = EINVAL;
- warning("error in size of file '%s'", file);
- goto out_free;
- }
- } else {
- size = 0;
- endian8 = convert_endian_8(handle, size);
- if (do_write_check(handle, &endian8, 8))
- goto out_free;
- }
- put_tracing_file(file);
- file = NULL;
+ if (save_tracing_file_data(handle, "saved_cmdlines") < 0)
+ goto out_free;
return handle;
^ permalink raw reply related [flat|nested] 6+ messages in thread
* [PATCH V3 2/3] trace-cmd: Add recording to trace_clock
2013-04-24 23:12 [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 1/3] trace-cmd: Define general functions for outputting/inputting saved_cmdlines Yoshihiro YUNOMAE
@ 2013-04-24 23:13 ` Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 3/3] trace-cmd: Add support for extracting trace_clock in report Yoshihiro YUNOMAE
2013-05-07 2:03 ` [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
3 siblings, 0 replies; 6+ messages in thread
From: Yoshihiro YUNOMAE @ 2013-04-24 23:13 UTC (permalink / raw)
To: Steven Rostedt
Cc: Hidehiro Kawai, Masami Hiramatsu, linux-kernel, yrl.pp-manager.tt
In this patch, trace-cmd reads trace_clock on debugfs in the record mode and
outputs the data to trace.dat file. This patch defines a flag
TRACECMD_OPTION_TRACECLOCK for using the option feature. For supporting
multiple buffers, this patch doesn't store data of trace_clock when trace-cmd
adds the flag to trace.dat. This is because the flag is globally used, but
trace_clock can be changed for each buffer. So, this patch stores data of
trace_clock after adding data information of each CPU. The binary format
of trace.data is changed as follows:
<Current binary format>
...
"flyrecord" -----+
[total cpu numer] |
[file offset and size of cpu0] |
... +--- info. of normal buffer
[file offset and size of cpuX] |
--skip-- |
[data of CPU0] |
... -----+
--skip--
"flyrecord" -----+
[total cpu numer] |
[file offset and size of cpu0] |
... +--- info. of sub-buffer
[file offset and size of cpuX] |
--skip-- |
[data of CPU0] |
... -----+
<Changed binary format>
...
"flyrecord" -----+
[total cpu numer] |
[file offset and size of cpu0] |
... +--- info. of normal buffer
[file offset and size of cpuX] |
[size of trace_clock] <== add |
[trace_clock contents] <== add |
--skip-- |
[data of CPU0] |
... -----+
--skip--
"flyrecord" -----+
[total cpu numer] |
[file offset and size of cpu0] |
... +--- info. of sub-buffer
[file offset and size of cpuX] |
[size of trace_clock] <== add |
[trace_clock contents] <== add |
--skip-- |
[data of CPU0] |
... -----+
Changes in v2:
- Define TRACECMD_OPTION_TRACECLOCK for extracting trace_clock
Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez@hitachi.com>
---
trace-cmd.h | 1 +
trace-output.c | 3 +++
trace-record.c | 3 +++
3 files changed, 7 insertions(+)
diff --git a/trace-cmd.h b/trace-cmd.h
index 116c2f6..0745dad 100644
--- a/trace-cmd.h
+++ b/trace-cmd.h
@@ -81,6 +81,7 @@ enum {
TRACECMD_OPTION_DATE,
TRACECMD_OPTION_CPUSTAT,
TRACECMD_OPTION_BUFFER,
+ TRACECMD_OPTION_TRACECLOCK,
};
enum {
diff --git a/trace-output.c b/trace-output.c
index cc71adf..bdb478d 100644
--- a/trace-output.c
+++ b/trace-output.c
@@ -1067,6 +1067,9 @@ static int __tracecmd_append_cpu_data(struct tracecmd_output *handle,
goto out_free;
}
+ if (save_tracing_file_data(handle, "trace_clock") < 0)
+ goto out_free;
+
for (i = 0; i < cpus; i++) {
fprintf(stderr, "CPU%d data recorded at offset=0x%llx\n",
i, (unsigned long long) offsets[i]);
diff --git a/trace-record.c b/trace-record.c
index 0025cf3..407576f 100644
--- a/trace-record.c
+++ b/trace-record.c
@@ -1804,6 +1804,9 @@ static void record_data(char *date2ts, struct trace_seq *s)
tracecmd_add_option(handle, TRACECMD_OPTION_CPUSTAT,
s[i].len+1, s[i].buffer);
+ tracecmd_add_option(handle, TRACECMD_OPTION_TRACECLOCK,
+ 0, NULL);
+
if (buffers) {
buffer_options = malloc_or_die(sizeof(*buffer_options) * buffers);
i = 0;
^ permalink raw reply related [flat|nested] 6+ messages in thread
* [PATCH V3 3/3] trace-cmd: Add support for extracting trace_clock in report
2013-04-24 23:12 [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 1/3] trace-cmd: Define general functions for outputting/inputting saved_cmdlines Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 2/3] trace-cmd: Add recording to trace_clock Yoshihiro YUNOMAE
@ 2013-04-24 23:13 ` Yoshihiro YUNOMAE
2013-11-04 20:22 ` [tip:perf/core] tools lib traceevent: " tip-bot for Yoshihiro YUNOMAE
2013-05-07 2:03 ` [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
3 siblings, 1 reply; 6+ messages in thread
From: Yoshihiro YUNOMAE @ 2013-04-24 23:13 UTC (permalink / raw)
To: Steven Rostedt
Cc: Hidehiro Kawai, Masami Hiramatsu, linux-kernel, yrl.pp-manager.tt
If trace-cmd extracts trace_clock, trace-cmd reads trace_clock data from
the trace.dat and switches outputting format of timestamp for each trace_clock.
Changed in v2:
- Check whether TRACECMD_OPTION_TRACECLOCK exists or not in trace.dat
Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez@hitachi.com>
---
event-parse.c | 50 +++++++++++++++++++++++++++++++++++++++-----------
event-parse.h | 6 +++++-
trace-cmd.h | 2 ++
trace-input.c | 33 +++++++++++++++++++++++++++++++++
trace-read.c | 4 +++-
trace-util.c | 26 ++++++++++++++++++++++++++
6 files changed, 108 insertions(+), 13 deletions(-)
diff --git a/event-parse.c b/event-parse.c
index a18a493..a188c0e 100644
--- a/event-parse.c
+++ b/event-parse.c
@@ -305,6 +305,11 @@ int pevent_register_comm(struct pevent *pevent, const char *comm, int pid)
return 0;
}
+void pevent_register_trace_clock(struct pevent *pevent, char *trace_clock)
+{
+ pevent->trace_clock = trace_clock;
+}
+
struct func_map {
unsigned long long addr;
char *func;
@@ -4409,8 +4414,21 @@ void pevent_event_info(struct trace_seq *s, struct event_format *event,
trace_seq_terminate(s);
}
+static bool is_timestamp_in_us(char *trace_clock, bool use_trace_clock)
+{
+ if (!use_trace_clock)
+ return true;
+
+ if (!strcmp(trace_clock, "local") || !strcmp(trace_clock, "global")
+ || !strcmp(trace_clock, "uptime") || !strcmp(trace_clock, "perf"))
+ return true;
+
+ /* trace_clock is setting in tsc or counter mode */
+ return false;
+}
+
void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
- struct pevent_record *record)
+ struct pevent_record *record, bool use_trace_clock)
{
static char *spaces = " "; /* 20 spaces */
struct event_format *event;
@@ -4423,9 +4441,14 @@ void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
int pid;
int len;
int p;
+ bool use_usec_format;
- secs = record->ts / NSECS_PER_SEC;
- nsecs = record->ts - secs * NSECS_PER_SEC;
+ use_usec_format = is_timestamp_in_us(pevent->trace_clock,
+ use_trace_clock);
+ if (use_usec_format) {
+ secs = record->ts / NSECS_PER_SEC;
+ nsecs = record->ts - secs * NSECS_PER_SEC;
+ }
if (record->size < 0) {
do_warning("ug! negative record size %d", record->size);
@@ -4450,15 +4473,20 @@ void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
} else
trace_seq_printf(s, "%16s-%-5d [%03d]", comm, pid, record->cpu);
- if (pevent->flags & PEVENT_NSEC_OUTPUT) {
- usecs = nsecs;
- p = 9;
- } else {
- usecs = (nsecs + 500) / NSECS_PER_USEC;
- p = 6;
- }
+ if (use_usec_format) {
+ if (pevent->flags & PEVENT_NSEC_OUTPUT) {
+ usecs = nsecs;
+ p = 9;
+ } else {
+ usecs = (nsecs + 500) / NSECS_PER_USEC;
+ p = 6;
+ }
- trace_seq_printf(s, " %5lu.%0*lu: %s: ", secs, p, usecs, event->name);
+ trace_seq_printf(s, " %5lu.%0*lu: %s: ",
+ secs, p, usecs, event->name);
+ } else
+ trace_seq_printf(s, " %12llu: %s: ",
+ record->ts, event->name);
/* Space out the event names evenly. */
len = strlen(event->name);
diff --git a/event-parse.h b/event-parse.h
index 05e99fa..cd9f244 100644
--- a/event-parse.h
+++ b/event-parse.h
@@ -20,6 +20,7 @@
#ifndef _PARSE_EVENTS_H
#define _PARSE_EVENTS_H
+#include <stdbool.h>
#include <stdarg.h>
#include <regex.h>
@@ -456,6 +457,8 @@ struct pevent {
/* cache */
struct event_format *last_event;
+
+ char *trace_clock;
};
static inline void pevent_set_flag(struct pevent *pevent, int flag)
@@ -533,6 +536,7 @@ enum trace_flag_type {
};
int pevent_register_comm(struct pevent *pevent, const char *comm, int pid);
+void pevent_register_trace_clock(struct pevent *pevent, char *trace_clock);
int pevent_register_function(struct pevent *pevent, char *name,
unsigned long long addr, char *mod);
int pevent_register_print_string(struct pevent *pevent, const char *fmt,
@@ -540,7 +544,7 @@ int pevent_register_print_string(struct pevent *pevent, const char *fmt,
int pevent_pid_is_registered(struct pevent *pevent, int pid);
void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
- struct pevent_record *record);
+ struct pevent_record *record, bool use_trace_clock);
int pevent_parse_header_page(struct pevent *pevent, char *buf, unsigned long size,
int long_size);
diff --git a/trace-cmd.h b/trace-cmd.h
index 0745dad..bae4cc1 100644
--- a/trace-cmd.h
+++ b/trace-cmd.h
@@ -30,6 +30,7 @@
#define TRACECMD_PTR2ERR(ptr) ((unisgned long)(ptr) & ~TRACECMD_ERR_MSK)
void parse_cmdlines(struct pevent *pevent, char *file, int size);
+void parse_trace_clock(struct pevent *pevent, char *file, int size);
void parse_proc_kallsyms(struct pevent *pevent, char *file, unsigned int size);
void parse_ftrace_printk(struct pevent *pevent, char *file, unsigned int size);
@@ -171,6 +172,7 @@ tracecmd_get_cursor(struct tracecmd_input *handle, int cpu);
int tracecmd_ftrace_overrides(struct tracecmd_input *handle, struct tracecmd_ftrace *finfo);
struct pevent *tracecmd_get_pevent(struct tracecmd_input *handle);
+bool tracecmd_get_use_trace_clock(struct tracecmd_input *handle);
char *tracecmd_get_tracing_file(const char *name);
void tracecmd_put_tracing_file(char *name);
diff --git a/trace-input.c b/trace-input.c
index 232015a..369ad58 100644
--- a/trace-input.c
+++ b/trace-input.c
@@ -19,6 +19,7 @@
*/
#define _LARGEFILE64_SOURCE
#include <dirent.h>
+#include <stdbool.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
@@ -89,6 +90,7 @@ struct tracecmd_input {
int cpus;
int ref;
int nr_buffers; /* buffer instances */
+ bool use_trace_clock;
struct cpu_data *cpu_data;
unsigned long long ts_offset;
char * cpustats;
@@ -1767,6 +1769,9 @@ static int handle_options(struct tracecmd_input *handle)
offset = *(unsigned long long *)buf;
buffer->offset = __data2host8(handle->pevent, offset);
break;
+ case TRACECMD_OPTION_TRACECLOCK:
+ handle->use_trace_clock = true;
+ break;
default:
warning("unknown option %d", option);
break;
@@ -1901,6 +1906,20 @@ static int read_and_parse_cmdlines(struct tracecmd_input *handle,
return 0;
}
+static int read_and_parse_trace_clock(struct tracecmd_input *handle,
+ struct pevent *pevent)
+{
+ unsigned long long size;
+ char *trace_clock;
+
+ if (read_data_and_size(handle, &trace_clock, &size) < 0)
+ return -1;
+ trace_clock[size] = 0;
+ parse_trace_clock(pevent, trace_clock, size);
+ free(trace_clock);
+ return 0;
+}
+
/**
* tracecmd_init_data - prepare reading the data from trace.dat
* @handle: input handle for the trace.dat file
@@ -1927,6 +1946,11 @@ int tracecmd_init_data(struct tracecmd_input *handle)
if (ret < 0)
return ret;
+ if (handle->use_trace_clock) {
+ if (read_and_parse_trace_clock(handle, pevent) < 0)
+ return -1;
+ }
+
tracecmd_blk_hack(handle);
return ret;
@@ -2563,3 +2587,12 @@ struct pevent *tracecmd_get_pevent(struct tracecmd_input *handle)
{
return handle->pevent;
}
+
+/**
+ * tracecmd_get_use_trace_clock - return use_trace_clock
+ * @handle: input handle for the trace.dat file
+ */
+bool tracecmd_get_use_trace_clock(struct tracecmd_input *handle)
+{
+ return handle->use_trace_clock;
+}
diff --git a/trace-read.c b/trace-read.c
index 7fc9a7f..2e84d78 100644
--- a/trace-read.c
+++ b/trace-read.c
@@ -655,6 +655,7 @@ static void show_data(struct tracecmd_input *handle,
{
struct pevent *pevent;
struct trace_seq s;
+ bool use_trace_clock;
if (filter_record(handle, record))
return;
@@ -674,7 +675,8 @@ static void show_data(struct tracecmd_input *handle,
trace_seq_printf(&s, "CPU:%d [SUBBUFFER START]\n",
record->cpu);
- pevent_print_event(pevent, &s, record);
+ use_trace_clock = tracecmd_get_use_trace_clock(handle);
+ pevent_print_event(pevent, &s, record, use_trace_clock);
if (s.len && *(s.buffer + s.len - 1) == '\n')
s.len--;
trace_seq_do_printf(&s);
diff --git a/trace-util.c b/trace-util.c
index 9b26d1f..d6c1e29 100644
--- a/trace-util.c
+++ b/trace-util.c
@@ -375,6 +375,32 @@ void parse_cmdlines(struct pevent *pevent,
}
}
+static void extract_trace_clock(struct pevent *pevent, char *line)
+{
+ char *data;
+ char *clock;
+ char *next = NULL;
+
+ data = strtok_r(line, "[]", &next);
+ sscanf(data, "%ms", &clock);
+ pevent_register_trace_clock(pevent, clock);
+}
+
+void parse_trace_clock(struct pevent *pevent,
+ char *file, int size __maybe_unused)
+{
+ char *line;
+ char *next = NULL;
+
+ line = strtok_r(file, " ", &next);
+ while (line) {
+ /* current trace_clock is shown as "[local]". */
+ if (*line == '[')
+ return extract_trace_clock(pevent, line);
+ line = strtok_r(NULL, " ", &next);
+ }
+}
+
void parse_proc_kallsyms(struct pevent *pevent,
char *file, unsigned int size __maybe_unused)
{
^ permalink raw reply related [flat|nested] 6+ messages in thread
* Re: [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp
2013-04-24 23:12 [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
` (2 preceding siblings ...)
2013-04-24 23:13 ` [PATCH V3 3/3] trace-cmd: Add support for extracting trace_clock in report Yoshihiro YUNOMAE
@ 2013-05-07 2:03 ` Yoshihiro YUNOMAE
3 siblings, 0 replies; 6+ messages in thread
From: Yoshihiro YUNOMAE @ 2013-05-07 2:03 UTC (permalink / raw)
To: Steven Rostedt
Cc: Hidehiro Kawai, Masami Hiramatsu, linux-kernel, yrl.pp-manager.tt
Hi Steven,
Would you review this patch for trace-cmd?
Thanks,
Yoshihiro YUNOMAE
(2013/04/25 8:12), Yoshihiro YUNOMAE wrote:
> Hi Steven,
>
> This patch series extracts the trace_clock file for switching outputting format
> of timestamp. This patch series uses the options feature, so trace-cmd keeps
> backward compatibility.
>
> In tsc or counter modes, trace-cmd should output timestamp not in the sec.usec
> format but in the raw format. For example, we will show results in trace-cmd
> report mode as follows by applying this patch series:
>
> <for local or global mode>
> bash-9022 [000] 34984.109846: sched_wakeup: comm=migration/3 pid=23 prio=0 success=1 target_cpu=003
> <idle>-0 [002] 34984.109847: cpu_idle: state=4294967295 cpu_id=2
> bash-9022 [000] 34984.109848: sched_switch: prev_comm=bash prev_pid=9022 prev_prio=120 prev_state=R ==> next_comm=migration/0 next_pid=8 next_prio=0
> <idle>-0 [002] 34984.109849: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=migration/2 next_pid=18 next_prio=0
>
> <for tsc or counter mode>
> bash-9022 [000] 34984109846: sched_wakeup: comm=migration/3 pid=23 prio=0 success=1 target_cpu=003
> <idle>-0 [002] 34984109847: cpu_idle: state=4294967295 cpu_id=2
> bash-9022 [000] 34984109848: sched_switch: prev_comm=bash prev_pid=9022 prev_prio=120 prev_state=R ==> next_comm=migration/0 next_pid=8 next_prio=0
> <idle>-0 [002] 34984109849: sched_switch: prev_comm=swapper/2 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=migration/2 next_pid=18 next_prio=0
>
> v2:
> - Separate input/output patches (2/3 and 3/3)
> - Define TRACECMD_OPTION_TRACECLOCK for extracting trace_clock (2/3)
> - Check whether TRACECMD_OPTION_TRACECLOCK exists or not in trace.dat (3/3)
>
> v3:
> - a file variable in save_tracing_file_data() is freed when operation is failed
> (1/3)
> - check the return value of get_tracing_file() in save_tracing_file_data()
> (1/3)
>
> Thank you,
>
> ---
>
> Yoshihiro YUNOMAE (3):
> trace-cmd: Define general functions for outputting/inputting saved_cmdlines
> trace-cmd: Add recording to trace_clock
> trace-cmd: Add support for extracting trace_clock in report
>
>
> event-parse.c | 50 ++++++++++++++++++++++++++++-------
> event-parse.h | 6 ++++
> trace-cmd.h | 3 ++
> trace-input.c | 79 ++++++++++++++++++++++++++++++++++++++++++++++----------
> trace-output.c | 71 +++++++++++++++++++++++++++++++-------------------
> trace-read.c | 4 ++-
> trace-record.c | 3 ++
> trace-util.c | 26 ++++++++++++++++++
> 8 files changed, 188 insertions(+), 54 deletions(-)
>
--
Yoshihiro YUNOMAE
Software Platform Research Dept. Linux Technology Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: yoshihiro.yunomae.ez@hitachi.com
^ permalink raw reply [flat|nested] 6+ messages in thread
* [tip:perf/core] tools lib traceevent: Add support for extracting trace_clock in report
2013-04-24 23:13 ` [PATCH V3 3/3] trace-cmd: Add support for extracting trace_clock in report Yoshihiro YUNOMAE
@ 2013-11-04 20:22 ` tip-bot for Yoshihiro YUNOMAE
0 siblings, 0 replies; 6+ messages in thread
From: tip-bot for Yoshihiro YUNOMAE @ 2013-11-04 20:22 UTC (permalink / raw)
To: linux-tip-commits
Cc: acme, linux-kernel, hpa, mingo, yoshihiro.yunomae.ez, namhyung,
fweisbec, rostedt, akpm, tglx
Commit-ID: 1b372ca52a02cc97520c13d79bdfb0a7ff81b772
Gitweb: http://git.kernel.org/tip/1b372ca52a02cc97520c13d79bdfb0a7ff81b772
Author: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez@hitachi.com>
AuthorDate: Fri, 1 Nov 2013 17:53:53 -0400
Committer: Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Mon, 4 Nov 2013 14:33:12 -0300
tools lib traceevent: Add support for extracting trace_clock in report
If trace-cmd extracts trace_clock, trace-cmd reads trace_clock data from
the trace.dat and switches outputting format of timestamp for each
trace_clock.
Signed-off-by: Yoshihiro YUNOMAE <yoshihiro.yunomae.ez@hitachi.com>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Ingo Molnar <mingo@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/r/20130424231305.14877.86147.stgit@yunodevel
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
tools/lib/traceevent/event-parse.c | 50 +++++++++++++++++++++++++++++---------
tools/lib/traceevent/event-parse.h | 6 ++++-
2 files changed, 44 insertions(+), 12 deletions(-)
diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c
index d1c2a6a..deedff9 100644
--- a/tools/lib/traceevent/event-parse.c
+++ b/tools/lib/traceevent/event-parse.c
@@ -305,6 +305,11 @@ int pevent_register_comm(struct pevent *pevent, const char *comm, int pid)
return 0;
}
+void pevent_register_trace_clock(struct pevent *pevent, char *trace_clock)
+{
+ pevent->trace_clock = trace_clock;
+}
+
struct func_map {
unsigned long long addr;
char *func;
@@ -4443,8 +4448,21 @@ void pevent_event_info(struct trace_seq *s, struct event_format *event,
trace_seq_terminate(s);
}
+static bool is_timestamp_in_us(char *trace_clock, bool use_trace_clock)
+{
+ if (!use_trace_clock)
+ return true;
+
+ if (!strcmp(trace_clock, "local") || !strcmp(trace_clock, "global")
+ || !strcmp(trace_clock, "uptime") || !strcmp(trace_clock, "perf"))
+ return true;
+
+ /* trace_clock is setting in tsc or counter mode */
+ return false;
+}
+
void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
- struct pevent_record *record)
+ struct pevent_record *record, bool use_trace_clock)
{
static const char *spaces = " "; /* 20 spaces */
struct event_format *event;
@@ -4457,9 +4475,14 @@ void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
int pid;
int len;
int p;
+ bool use_usec_format;
- secs = record->ts / NSECS_PER_SEC;
- nsecs = record->ts - secs * NSECS_PER_SEC;
+ use_usec_format = is_timestamp_in_us(pevent->trace_clock,
+ use_trace_clock);
+ if (use_usec_format) {
+ secs = record->ts / NSECS_PER_SEC;
+ nsecs = record->ts - secs * NSECS_PER_SEC;
+ }
if (record->size < 0) {
do_warning("ug! negative record size %d", record->size);
@@ -4484,15 +4507,20 @@ void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
} else
trace_seq_printf(s, "%16s-%-5d [%03d]", comm, pid, record->cpu);
- if (pevent->flags & PEVENT_NSEC_OUTPUT) {
- usecs = nsecs;
- p = 9;
- } else {
- usecs = (nsecs + 500) / NSECS_PER_USEC;
- p = 6;
- }
+ if (use_usec_format) {
+ if (pevent->flags & PEVENT_NSEC_OUTPUT) {
+ usecs = nsecs;
+ p = 9;
+ } else {
+ usecs = (nsecs + 500) / NSECS_PER_USEC;
+ p = 6;
+ }
- trace_seq_printf(s, " %5lu.%0*lu: %s: ", secs, p, usecs, event->name);
+ trace_seq_printf(s, " %5lu.%0*lu: %s: ",
+ secs, p, usecs, event->name);
+ } else
+ trace_seq_printf(s, " %12llu: %s: ",
+ record->ts, event->name);
/* Space out the event names evenly. */
len = strlen(event->name);
diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h
index c37b202..7503edf 100644
--- a/tools/lib/traceevent/event-parse.h
+++ b/tools/lib/traceevent/event-parse.h
@@ -20,6 +20,7 @@
#ifndef _PARSE_EVENTS_H
#define _PARSE_EVENTS_H
+#include <stdbool.h>
#include <stdarg.h>
#include <regex.h>
@@ -450,6 +451,8 @@ struct pevent {
/* cache */
struct event_format *last_event;
+
+ char *trace_clock;
};
static inline void pevent_set_flag(struct pevent *pevent, int flag)
@@ -527,6 +530,7 @@ enum trace_flag_type {
};
int pevent_register_comm(struct pevent *pevent, const char *comm, int pid);
+void pevent_register_trace_clock(struct pevent *pevent, char *trace_clock);
int pevent_register_function(struct pevent *pevent, char *name,
unsigned long long addr, char *mod);
int pevent_register_print_string(struct pevent *pevent, char *fmt,
@@ -534,7 +538,7 @@ int pevent_register_print_string(struct pevent *pevent, char *fmt,
int pevent_pid_is_registered(struct pevent *pevent, int pid);
void pevent_print_event(struct pevent *pevent, struct trace_seq *s,
- struct pevent_record *record);
+ struct pevent_record *record, bool use_trace_clock);
int pevent_parse_header_page(struct pevent *pevent, char *buf, unsigned long size,
int long_size);
^ permalink raw reply related [flat|nested] 6+ messages in thread
end of thread, other threads:[~2013-11-04 20:22 UTC | newest]
Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2013-04-24 23:12 [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 1/3] trace-cmd: Define general functions for outputting/inputting saved_cmdlines Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 2/3] trace-cmd: Add recording to trace_clock Yoshihiro YUNOMAE
2013-04-24 23:13 ` [PATCH V3 3/3] trace-cmd: Add support for extracting trace_clock in report Yoshihiro YUNOMAE
2013-11-04 20:22 ` [tip:perf/core] tools lib traceevent: " tip-bot for Yoshihiro YUNOMAE
2013-05-07 2:03 ` [PATCH V3 0/3] trace-cmd: Support a raw format for outputting timestamp Yoshihiro YUNOMAE
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).