From 1b372ca52a02cc97520c13d79bdfb0a7ff81b772 Mon Sep 17 00:00:00 2001 From: Yoshihiro YUNOMAE Date: Fri, 1 Nov 2013 17:53:53 -0400 Subject: 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 Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Link: http://lkml.kernel.org/r/20130424231305.14877.86147.stgit@yunodevel Signed-off-by: Steven Rostedt Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 50 +++++++++++++++++++++++++++++--------- 1 file changed, 39 insertions(+), 11 deletions(-) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index d1c2a6a4cd3..deedff9d06a 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); -- cgit v1.2.3-70-g09d2 From 18900af8292180151c82f0762506fa0740aa54a5 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Red Hat)" Date: Fri, 1 Nov 2013 17:53:54 -0400 Subject: tools lib traceevent: Update printk formats when entered Instead of cropping off the '"' and '\n"' from a printk format every time it is referenced, do it when it's added. This makes it easier to reference a printk_map and should speed things up a little. Signed-off-by: Steven Rostedt Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Link: http://lkml.kernel.org/r/20131101215500.495619312@goodmis.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 29 ++++++++++++++--------------- tools/lib/traceevent/event-parse.h | 2 +- 2 files changed, 15 insertions(+), 16 deletions(-) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index deedff9d06a..856b79105ab 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -604,10 +604,11 @@ find_printk(struct pevent *pevent, unsigned long long addr) * This registers a string by the address it was stored in the kernel. * The @fmt passed in is duplicated. */ -int pevent_register_print_string(struct pevent *pevent, char *fmt, +int pevent_register_print_string(struct pevent *pevent, const char *fmt, unsigned long long addr) { struct printk_list *item = malloc(sizeof(*item)); + char *p; if (!item) return -1; @@ -615,10 +616,21 @@ int pevent_register_print_string(struct pevent *pevent, char *fmt, item->next = pevent->printklist; item->addr = addr; + /* Strip off quotes and '\n' from the end */ + if (fmt[0] == '"') + fmt++; item->printk = strdup(fmt); if (!item->printk) goto out_free; + p = item->printk + strlen(item->printk) - 1; + if (*p == '"') + *p = 0; + + p -= 2; + if (strcmp(p, "\\n") == 0) + *p = 0; + pevent->printklist = item; pevent->printk_count++; @@ -3887,7 +3899,6 @@ get_bprint_format(void *data, int size __maybe_unused, struct format_field *field; struct printk_map *printk; char *format; - char *p; field = pevent->bprint_fmt_field; @@ -3909,20 +3920,8 @@ get_bprint_format(void *data, int size __maybe_unused, return format; } - p = printk->printk; - /* Remove any quotes. */ - if (*p == '"') - p++; - if (asprintf(&format, "%s : %s", "%pf", p) < 0) + if (asprintf(&format, "%s : %s", "%pf", printk->printk) < 0) return NULL; - /* remove ending quotes and new line since we will add one too */ - p = format + strlen(format) - 1; - if (*p == '"') - *p = 0; - - p -= 2; - if (strcmp(p, "\\n") == 0) - *p = 0; return format; } diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h index 7503edf5ac6..9ab6367f2fe 100644 --- a/tools/lib/traceevent/event-parse.h +++ b/tools/lib/traceevent/event-parse.h @@ -533,7 +533,7 @@ 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, +int pevent_register_print_string(struct pevent *pevent, const char *fmt, unsigned long long addr); int pevent_pid_is_registered(struct pevent *pevent, int pid); -- cgit v1.2.3-70-g09d2 From 0970b5f438261216afcd0ccaa2fcfffc83df7ca2 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Red Hat)" Date: Fri, 1 Nov 2013 17:53:55 -0400 Subject: tools lib traceevent: If %s is a pointer, check printk formats If the format string of TP_printk() contains a %s, and the argument is not a string, check if the argument is a pointer that might match the printk_formats that were stored. Signed-off-by: Steven Rostedt Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Link: http://lkml.kernel.org/r/20131101215500.698924777@goodmis.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 8 +++++++- 1 file changed, 7 insertions(+), 1 deletion(-) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index 856b79105ab..013c8d3db80 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -3505,6 +3505,7 @@ static void print_str_arg(struct trace_seq *s, void *data, int size, struct pevent *pevent = event->pevent; struct print_flag_sym *flag; struct format_field *field; + struct printk_map *printk; unsigned long long val, fval; unsigned long addr; char *str; @@ -3540,7 +3541,12 @@ static void print_str_arg(struct trace_seq *s, void *data, int size, if (!(field->flags & FIELD_IS_ARRAY) && field->size == pevent->long_size) { addr = *(unsigned long *)(data + field->offset); - trace_seq_printf(s, "%lx", addr); + /* Check if it matches a print format */ + printk = find_printk(pevent, addr); + if (printk) + trace_seq_puts(s, printk->printk); + else + trace_seq_printf(s, "%lx", addr); break; } str = malloc(len + 1); -- cgit v1.2.3-70-g09d2 From b30f75eba27a9ab0704cbc501e9be3b025ce56fe Mon Sep 17 00:00:00 2001 From: Howard Cochran Date: Fri, 1 Nov 2013 17:53:56 -0400 Subject: tools lib traceevent: Handle __print_hex(__get_dynamic_array(fieldname), len) The kernel has a few events with a format similar to this excerpt: field:unsigned int len; offset:12; size:4; signed:0; field:__data_loc unsigned char[] data_array; offset:16; size:4; signed:0; print fmt: "%s", __print_hex(__get_dynamic_array(data_array), REC->len) trace-cmd could already parse that arg correctly, but print_str_arg() was unable to handle the first parameter being a dynamic array. (It just printed a "field not found" warning). Teach print_str_arg's PRINT_HEX case to handle the nested PRINT_DYNAMIC_ARRAY correctly. The output now matches the kernel's own formatting for this case. Signed-off-by: Howard Cochran Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Link: http://lkml.kernel.org/r/1381503349-12271-1-git-send-email-hcochran@lexmark.com [ Removed "polish compare", we don't do that here ] Signed-off-by: Steven Rostedt Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 24 ++++++++++++++++-------- 1 file changed, 16 insertions(+), 8 deletions(-) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index 013c8d3db80..0a1ffe07de3 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -3588,15 +3588,23 @@ static void print_str_arg(struct trace_seq *s, void *data, int size, } break; case PRINT_HEX: - field = arg->hex.field->field.field; - if (!field) { - str = arg->hex.field->field.name; - field = pevent_find_any_field(event, str); - if (!field) - goto out_warning_field; - arg->hex.field->field.field = field; + if (arg->hex.field->type == PRINT_DYNAMIC_ARRAY) { + unsigned long offset; + offset = pevent_read_number(pevent, + data + arg->hex.field->dynarray.field->offset, + arg->hex.field->dynarray.field->size); + hex = data + (offset & 0xffff); + } else { + field = arg->hex.field->field.field; + if (!field) { + str = arg->hex.field->field.name; + field = pevent_find_any_field(event, str); + if (!field) + goto out_warning_field; + arg->hex.field->field.field = field; + } + hex = data + field->offset; } - hex = data + field->offset; len = eval_num_arg(data, size, event, arg->hex.size); for (i = 0; i < len; i++) { if (i) -- cgit v1.2.3-70-g09d2 From 0883d9d730fc294c3d90ebd190b94e5782ead316 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Red Hat)" Date: Fri, 1 Nov 2013 17:53:57 -0400 Subject: tools lib traceevent: Have bprintk output the same as the kernel does The trace_bprintk() in the kernel looks like: ring_buffer_producer_thread: Missed: 0 ring_buffer_producer_thread: Hit: 62174350 ring_buffer_producer_thread: Entries per millisec: 6296 ring_buffer_producer_thread: 158 ns per entry ring_buffer_producer_thread: Sleeping for 10 secs ring_buffer_producer_thread: Starting ring buffer hammer ring_buffer_producer_thread: End ring buffer hammer But the current output looks like this: ring_buffer_producer_thread : Time: 9407018 (usecs) ring_buffer_producer_thread : Overruns: 43285485 ring_buffer_producer_thread : Read: 4405365 (by events) ring_buffer_producer_thread : Entries: 0 ring_buffer_producer_thread : Total: 47690850 ring_buffer_producer_thread : Missed: 0 ring_buffer_producer_thread : Hit: 47690850 Remove the space between the function and the colon. Signed-off-by: Steven Rostedt Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Link: http://lkml.kernel.org/r/20131101215501.272654481@goodmis.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index 0a1ffe07de3..e1c743c5283 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -3802,8 +3802,8 @@ static struct print_arg *make_bprint_args(char *fmt, void *data, int size, struc if (asprintf(&arg->atom.atom, "%lld", ip) < 0) goto out_free; - /* skip the first "%pf : " */ - for (ptr = fmt + 6, bptr = data + field->offset; + /* skip the first "%pf: " */ + for (ptr = fmt + 5, bptr = data + field->offset; bptr < data + size && *ptr; ptr++) { int ls = 0; @@ -3929,12 +3929,12 @@ get_bprint_format(void *data, int size __maybe_unused, printk = find_printk(pevent, addr); if (!printk) { - if (asprintf(&format, "%%pf : (NO FORMAT FOUND at %llx)\n", addr) < 0) + if (asprintf(&format, "%%pf: (NO FORMAT FOUND at %llx)\n", addr) < 0) return NULL; return format; } - if (asprintf(&format, "%s : %s", "%pf", printk->printk) < 0) + if (asprintf(&format, "%s: %s", "%pf", printk->printk) < 0) return NULL; return format; -- cgit v1.2.3-70-g09d2 From 5efb9fbd5f1bfe4435bd0a3ea5f0e187875509c2 Mon Sep 17 00:00:00 2001 From: "Steven Rostedt (Red Hat)" Date: Fri, 1 Nov 2013 17:53:58 -0400 Subject: tools lib traceevent: Check for spaces in character array Currently when using the raw format for fields, when looking at a character array, to determine if it is a string or not, we make sure all characters are "isprint()". If not, then we consider it a numeric array, and print the hex numbers of the characters instead. But it seems that '\n' fails the isprint() check! Add isspace() to the check as well, such that if all characters pass isprint() or isspace() it will assume the character array is a string. Reported-by: Xenia Ragiadakou Signed-off-by: Steven Rostedt Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Cc: Xenia Ragiadakou Link: http://lkml.kernel.org/r/20131101215501.465091682@goodmis.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index e1c743c5283..85cbbddb688 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -3981,7 +3981,7 @@ static int is_printable_array(char *p, unsigned int len) unsigned int i; for (i = 0; i < len && p[i]; i++) - if (!isprint(p[i])) + if (!isprint(p[i]) && !isspace(p[i])) return 0; return 1; } -- cgit v1.2.3-70-g09d2 From c6c2b960b7a4105f096499fba3df65d6c0272a20 Mon Sep 17 00:00:00 2001 From: Steven Rostedt Date: Fri, 1 Nov 2013 17:53:59 -0400 Subject: tools lib traceevent: Add flags NOHANDLE and PRINTRAW to individual events Add the flags EVENT_FL_NOHANDLE and EVENT_FL_PRINTRAW to the event flags to have the event either ignore the register handler or to ignore the handler and also print the raw format respectively. This allows a tool to force a raw format or non handle for an event. Signed-off-by: Steven Rostedt Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Link: http://lkml.kernel.org/r/20131101215501.655258742@goodmis.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 4 ++-- tools/lib/traceevent/event-parse.h | 2 ++ 2 files changed, 4 insertions(+), 2 deletions(-) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index 85cbbddb688..fc6f35f591f 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -4446,11 +4446,11 @@ void pevent_event_info(struct trace_seq *s, struct event_format *event, { int print_pretty = 1; - if (event->pevent->print_raw) + if (event->pevent->print_raw || (event->flags & EVENT_FL_PRINTRAW)) print_event_fields(s, record->data, record->size, event); else { - if (event->handler) + if (event->handler && !(event->flags & EVENT_FL_NOHANDLE)) print_pretty = event->handler(s, record, event, event->context); diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h index 9ab6367f2fe..dc8539ee948 100644 --- a/tools/lib/traceevent/event-parse.h +++ b/tools/lib/traceevent/event-parse.h @@ -308,6 +308,8 @@ enum { EVENT_FL_ISBPRINT = 0x04, EVENT_FL_ISFUNCENT = 0x10, EVENT_FL_ISFUNCRET = 0x20, + EVENT_FL_NOHANDLE = 0x40, + EVENT_FL_PRINTRAW = 0x80, EVENT_FL_FAILED = 0x80000000 }; -- cgit v1.2.3-70-g09d2 From 6d862b8c14ba539c7c87ffc77f2e1d6dc9630c4d Mon Sep 17 00:00:00 2001 From: Steven Rostedt Date: Fri, 1 Nov 2013 17:54:00 -0400 Subject: tools lib traceevent: Add pevent_print_func_field() helper function Add the pevent_print_func_field() that will look up a field that is expected to be a function pointer, and it will print the function name and offset of the address given by the field. Signed-off-by: Steven Rostedt Cc: Andrew Morton Cc: Frederic Weisbecker Cc: Ingo Molnar Cc: Namhyung Kim Link: http://lkml.kernel.org/r/20131101215501.869542711@goodmis.org Signed-off-by: Arnaldo Carvalho de Melo --- tools/lib/traceevent/event-parse.c | 42 ++++++++++++++++++++++++++++++++++++++ tools/lib/traceevent/event-parse.h | 4 ++++ 2 files changed, 46 insertions(+) (limited to 'tools/lib/traceevent/event-parse.c') diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index fc6f35f591f..8f450adaa9c 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -5367,6 +5367,48 @@ int pevent_print_num_field(struct trace_seq *s, const char *fmt, return -1; } +/** + * pevent_print_func_field - print a field and a format for function pointers + * @s: The seq to print to + * @fmt: The printf format to print the field with. + * @event: the event that the field is for + * @name: The name of the field + * @record: The record with the field name. + * @err: print default error if failed. + * + * Returns: 0 on success, -1 field not found, or 1 if buffer is full. + */ +int pevent_print_func_field(struct trace_seq *s, const char *fmt, + struct event_format *event, const char *name, + struct pevent_record *record, int err) +{ + struct format_field *field = pevent_find_field(event, name); + struct pevent *pevent = event->pevent; + unsigned long long val; + struct func_map *func; + char tmp[128]; + + if (!field) + goto failed; + + if (pevent_read_number_field(field, record->data, &val)) + goto failed; + + func = find_func(pevent, val); + + if (func) + snprintf(tmp, 128, "%s/0x%llx", func->func, func->addr - val); + else + sprintf(tmp, "0x%08llx", val); + + return trace_seq_printf(s, fmt, tmp); + + failed: + if (err) + trace_seq_printf(s, "CAN'T FIND FIELD \"%s\"", name); + return -1; +} + static void free_func_handle(struct pevent_function_handler *func) { struct pevent_func_params *params; diff --git a/tools/lib/traceevent/event-parse.h b/tools/lib/traceevent/event-parse.h index dc8539ee948..8d73d2594f6 100644 --- a/tools/lib/traceevent/event-parse.h +++ b/tools/lib/traceevent/event-parse.h @@ -569,6 +569,10 @@ int pevent_print_num_field(struct trace_seq *s, const char *fmt, struct event_format *event, const char *name, struct pevent_record *record, int err); +int pevent_print_func_field(struct trace_seq *s, const char *fmt, + struct event_format *event, const char *name, + struct pevent_record *record, int err); + int pevent_register_event_handler(struct pevent *pevent, int id, const char *sys_name, const char *event_name, pevent_event_handler_func func, void *context); -- cgit v1.2.3-70-g09d2