diff options
Diffstat (limited to 'tools/lib/traceevent/event-parse.c')
| -rw-r--r-- | tools/lib/traceevent/event-parse.c | 411 |
1 files changed, 253 insertions, 158 deletions
diff --git a/tools/lib/traceevent/event-parse.c b/tools/lib/traceevent/event-parse.c index b36b536a9fcb..d948475585ce 100644 --- a/tools/lib/traceevent/event-parse.c +++ b/tools/lib/traceevent/event-parse.c @@ -142,6 +142,25 @@ static int cmdline_cmp(const void *a, const void *b) return 0; } +/* Looking for where to place the key */ +static int cmdline_slot_cmp(const void *a, const void *b) +{ + const struct tep_cmdline *ca = a; + const struct tep_cmdline *cb = b; + const struct tep_cmdline *cb1 = cb + 1; + + if (ca->pid < cb->pid) + return -1; + + if (ca->pid > cb->pid) { + if (ca->pid <= cb1->pid) + return 0; + return 1; + } + + return 0; +} + struct cmdline_list { struct cmdline_list *next; char *comm; @@ -239,6 +258,7 @@ static int add_new_comm(struct tep_handle *tep, struct tep_cmdline *cmdline; struct tep_cmdline key; char *new_comm; + int cnt; if (!pid) return 0; @@ -269,21 +289,43 @@ static int add_new_comm(struct tep_handle *tep, errno = ENOMEM; return -1; } + tep->cmdlines = cmdlines; - cmdlines[tep->cmdline_count].comm = strdup(comm); - if (!cmdlines[tep->cmdline_count].comm) { - free(cmdlines); + key.comm = strdup(comm); + if (!key.comm) { errno = ENOMEM; return -1; } - cmdlines[tep->cmdline_count].pid = pid; - - if (cmdlines[tep->cmdline_count].comm) + if (!tep->cmdline_count) { + /* no entries yet */ + tep->cmdlines[0] = key; tep->cmdline_count++; + return 0; + } - qsort(cmdlines, tep->cmdline_count, sizeof(*cmdlines), cmdline_cmp); - tep->cmdlines = cmdlines; + /* Now find where we want to store the new cmdline */ + cmdline = bsearch(&key, tep->cmdlines, tep->cmdline_count - 1, + sizeof(*tep->cmdlines), cmdline_slot_cmp); + + cnt = tep->cmdline_count; + if (cmdline) { + /* cmdline points to the one before the spot we want */ + cmdline++; + cnt -= cmdline - tep->cmdlines; + + } else { + /* The new entry is either before or after the list */ + if (key.pid > tep->cmdlines[tep->cmdline_count - 1].pid) { + tep->cmdlines[tep->cmdline_count++] = key; + return 0; + } + cmdline = &tep->cmdlines[0]; + } + memmove(cmdline + 1, cmdline, (cnt * sizeof(*cmdline))); + *cmdline = key; + + tep->cmdline_count++; return 0; } @@ -351,16 +393,6 @@ int tep_override_comm(struct tep_handle *tep, const char *comm, int pid) return _tep_register_comm(tep, comm, pid, true); } -int tep_register_trace_clock(struct tep_handle *tep, const char *trace_clock) -{ - tep->trace_clock = strdup(trace_clock); - if (!tep->trace_clock) { - errno = ENOMEM; - return -1; - } - return 0; -} - struct func_map { unsigned long long addr; char *func; @@ -4335,10 +4367,20 @@ static struct tep_print_arg *make_bprint_args(char *fmt, void *data, int size, s switch (*ptr) { case 's': case 'S': - case 'f': - case 'F': case 'x': break; + case 'f': + case 'F': + /* + * Pre-5.5 kernels use %pf and + * %pF for printing symbols + * while kernels since 5.5 use + * %pfw for fwnodes. So check + * %p[fF] isn't followed by 'w'. + */ + if (ptr[1] != 'w') + break; + /* fall through */ default: /* * Older kernels do not process @@ -4455,12 +4497,12 @@ get_bprint_format(void *data, int size __maybe_unused, printk = find_printk(tep, addr); if (!printk) { - if (asprintf(&format, "%%pf: (NO FORMAT FOUND at %llx)\n", addr) < 0) + if (asprintf(&format, "%%ps: (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", "%ps", printk->printk) < 0) return NULL; return format; @@ -5170,24 +5212,20 @@ out_failed: } } -/** - * tep_data_latency_format - parse the data for the latency format - * @tep: a handle to the trace event parser context - * @s: the trace_seq to write to - * @record: the record to read from - * +/* * This parses out the Latency format (interrupts disabled, * need rescheduling, in hard/soft interrupt, preempt count * and lock depth) and places it into the trace_seq. */ -void tep_data_latency_format(struct tep_handle *tep, - struct trace_seq *s, struct tep_record *record) +static void data_latency_format(struct tep_handle *tep, struct trace_seq *s, + char *format, struct tep_record *record) { static int check_lock_depth = 1; static int check_migrate_disable = 1; static int lock_depth_exists; static int migrate_disable_exists; unsigned int lat_flags; + struct trace_seq sq; unsigned int pc; int lock_depth = 0; int migrate_disable = 0; @@ -5195,6 +5233,7 @@ void tep_data_latency_format(struct tep_handle *tep, int softirq; void *data = record->data; + trace_seq_init(&sq); lat_flags = parse_common_flags(tep, data); pc = parse_common_pc(tep, data); /* lock_depth may not always exist */ @@ -5222,7 +5261,7 @@ void tep_data_latency_format(struct tep_handle *tep, hardirq = lat_flags & TRACE_FLAG_HARDIRQ; softirq = lat_flags & TRACE_FLAG_SOFTIRQ; - trace_seq_printf(s, "%c%c%c", + trace_seq_printf(&sq, "%c%c%c", (lat_flags & TRACE_FLAG_IRQS_OFF) ? 'd' : (lat_flags & TRACE_FLAG_IRQS_NOSUPPORT) ? 'X' : '.', @@ -5232,24 +5271,32 @@ void tep_data_latency_format(struct tep_handle *tep, hardirq ? 'h' : softirq ? 's' : '.'); if (pc) - trace_seq_printf(s, "%x", pc); + trace_seq_printf(&sq, "%x", pc); else - trace_seq_putc(s, '.'); + trace_seq_printf(&sq, "."); if (migrate_disable_exists) { if (migrate_disable < 0) - trace_seq_putc(s, '.'); + trace_seq_printf(&sq, "."); else - trace_seq_printf(s, "%d", migrate_disable); + trace_seq_printf(&sq, "%d", migrate_disable); } if (lock_depth_exists) { if (lock_depth < 0) - trace_seq_putc(s, '.'); + trace_seq_printf(&sq, "."); else - trace_seq_printf(s, "%d", lock_depth); + trace_seq_printf(&sq, "%d", lock_depth); + } + + if (sq.state == TRACE_SEQ__MEM_ALLOC_FAILED) { + s->state = TRACE_SEQ__MEM_ALLOC_FAILED; + return; } + trace_seq_terminate(&sq); + trace_seq_puts(s, sq.buffer); + trace_seq_destroy(&sq); trace_seq_terminate(s); } @@ -5410,21 +5457,16 @@ int tep_cmdline_pid(struct tep_handle *tep, struct tep_cmdline *cmdline) return cmdline->pid; } -/** - * tep_event_info - parse the data into the print format - * @s: the trace_seq to write to - * @event: the handle to the event - * @record: the record to read from - * +/* * This parses the raw @data using the given @event information and * writes the print format into the trace_seq. */ -void tep_event_info(struct trace_seq *s, struct tep_event *event, - struct tep_record *record) +static void print_event_info(struct trace_seq *s, char *format, bool raw, + struct tep_event *event, struct tep_record *record) { int print_pretty = 1; - if (event->tep->print_raw || (event->flags & TEP_EVENT_FL_PRINTRAW)) + if (raw || (event->flags & TEP_EVENT_FL_PRINTRAW)) tep_print_fields(s, record->data, record->size, event); else { @@ -5439,20 +5481,6 @@ void tep_event_info(struct trace_seq *s, struct tep_event *event, trace_seq_terminate(s); } -static bool is_timestamp_in_us(char *trace_clock, bool use_trace_clock) -{ - if (!trace_clock || !use_trace_clock) - return true; - - if (!strcmp(trace_clock, "local") || !strcmp(trace_clock, "global") - || !strcmp(trace_clock, "uptime") || !strcmp(trace_clock, "perf") - || !strncmp(trace_clock, "mono", 4)) - return true; - - /* trace_clock is setting in tsc or counter mode */ - return false; -} - /** * tep_find_event_by_record - return the event from a given record * @tep: a handle to the trace event parser context @@ -5476,129 +5504,197 @@ tep_find_event_by_record(struct tep_handle *tep, struct tep_record *record) return tep_find_event(tep, type); } -/** - * tep_print_event_task - Write the event task comm, pid and CPU - * @tep: a handle to the trace event parser context - * @s: the trace_seq to write to - * @event: the handle to the record's event - * @record: The record to get the event from - * - * Writes the tasks comm, pid and CPU to @s. +/* + * Writes the timestamp of the record into @s. Time divisor and precision can be + * specified as part of printf @format string. Example: + * "%3.1000d" - divide the time by 1000 and print the first 3 digits + * before the dot. Thus, the timestamp "123456000" will be printed as + * "123.456" */ -void tep_print_event_task(struct tep_handle *tep, struct trace_seq *s, - struct tep_event *event, - struct tep_record *record) +static void print_event_time(struct tep_handle *tep, struct trace_seq *s, + char *format, struct tep_event *event, + struct tep_record *record) +{ + unsigned long long time; + char *divstr; + int prec = 0, pr; + int div = 0; + int p10 = 1; + + if (isdigit(*(format + 1))) + prec = atoi(format + 1); + divstr = strchr(format, '.'); + if (divstr && isdigit(*(divstr + 1))) + div = atoi(divstr + 1); + time = record->ts; + if (div) { + time += div / 2; + time /= div; + } + pr = prec; + while (pr--) + p10 *= 10; + + if (p10 > 1 && p10 < time) + trace_seq_printf(s, "%5llu.%0*llu", time / p10, prec, time % p10); + else + trace_seq_printf(s, "%12llu\n", time); +} + +struct print_event_type { + enum { + EVENT_TYPE_INT = 1, + EVENT_TYPE_STRING, + EVENT_TYPE_UNKNOWN, + } type; + char format[32]; +}; + +static void print_string(struct tep_handle *tep, struct trace_seq *s, + struct tep_record *record, struct tep_event *event, + const char *arg, struct print_event_type *type) { - void *data = record->data; const char *comm; int pid; - pid = parse_common_pid(tep, data); - comm = find_cmdline(tep, pid); + if (strncmp(arg, TEP_PRINT_LATENCY, strlen(TEP_PRINT_LATENCY)) == 0) { + data_latency_format(tep, s, type->format, record); + } else if (strncmp(arg, TEP_PRINT_COMM, strlen(TEP_PRINT_COMM)) == 0) { + pid = parse_common_pid(tep, record->data); + comm = find_cmdline(tep, pid); + trace_seq_printf(s, type->format, comm); + } else if (strncmp(arg, TEP_PRINT_INFO_RAW, strlen(TEP_PRINT_INFO_RAW)) == 0) { + print_event_info(s, type->format, true, event, record); + } else if (strncmp(arg, TEP_PRINT_INFO, strlen(TEP_PRINT_INFO)) == 0) { + print_event_info(s, type->format, false, event, record); + } else if (strncmp(arg, TEP_PRINT_NAME, strlen(TEP_PRINT_NAME)) == 0) { + trace_seq_printf(s, type->format, event->name); + } else { + trace_seq_printf(s, "[UNKNOWN TEP TYPE %s]", arg); + } - if (tep->latency_format) - trace_seq_printf(s, "%8.8s-%-5d %3d", comm, pid, record->cpu); - else - trace_seq_printf(s, "%16s-%-5d [%03d]", comm, pid, record->cpu); } -/** - * tep_print_event_time - Write the event timestamp - * @tep: a handle to the trace event parser context - * @s: the trace_seq to write to - * @event: the handle to the record's event - * @record: The record to get the event from - * @use_trace_clock: Set to parse according to the @tep->trace_clock - * - * Writes the timestamp of the record into @s. - */ -void tep_print_event_time(struct tep_handle *tep, struct trace_seq *s, - struct tep_event *event, - struct tep_record *record, - bool use_trace_clock) +static void print_int(struct tep_handle *tep, struct trace_seq *s, + struct tep_record *record, struct tep_event *event, + int arg, struct print_event_type *type) { - unsigned long secs; - unsigned long usecs; - unsigned long nsecs; - int p; - bool use_usec_format; + int param; - use_usec_format = is_timestamp_in_us(tep->trace_clock, use_trace_clock); - if (use_usec_format) { - secs = record->ts / NSEC_PER_SEC; - nsecs = record->ts - secs * NSEC_PER_SEC; + switch (arg) { + case TEP_PRINT_CPU: + param = record->cpu; + break; + case TEP_PRINT_PID: + param = parse_common_pid(tep, record->data); + break; + case TEP_PRINT_TIME: + return print_event_time(tep, s, type->format, event, record); + default: + return; } + trace_seq_printf(s, type->format, param); +} - if (tep->latency_format) { - tep_data_latency_format(tep, s, record); - } +static int tep_print_event_param_type(char *format, + struct print_event_type *type) +{ + char *str = format + 1; + int i = 1; - if (use_usec_format) { - if (tep->flags & TEP_NSEC_OUTPUT) { - usecs = nsecs; - p = 9; - } else { - usecs = (nsecs + 500) / NSEC_PER_USEC; - /* To avoid usecs larger than 1 sec */ - if (usecs >= USEC_PER_SEC) { - usecs -= USEC_PER_SEC; - secs++; - } - p = 6; + type->type = EVENT_TYPE_UNKNOWN; + while (*str) { + switch (*str) { + case 'd': + case 'u': + case 'i': + case 'x': + case 'X': + case 'o': + type->type = EVENT_TYPE_INT; + break; + case 's': + type->type = EVENT_TYPE_STRING; + break; } - - trace_seq_printf(s, " %5lu.%0*lu:", secs, p, usecs); - } else - trace_seq_printf(s, " %12llu:", record->ts); + str++; + i++; + if (type->type != EVENT_TYPE_UNKNOWN) + break; + } + memset(type->format, 0, 32); + memcpy(type->format, format, i < 32 ? i : 31); + return i; } /** - * tep_print_event_data - Write the event data section + * tep_print_event - Write various event information * @tep: a handle to the trace event parser context * @s: the trace_seq to write to - * @event: the handle to the record's event * @record: The record to get the event from - * - * Writes the parsing of the record's data to @s. + * @format: a printf format string. Supported event fileds: + * TEP_PRINT_PID, "%d" - event PID + * TEP_PRINT_CPU, "%d" - event CPU + * TEP_PRINT_COMM, "%s" - event command string + * TEP_PRINT_NAME, "%s" - event name + * TEP_PRINT_LATENCY, "%s" - event latency + * TEP_PRINT_TIME, %d - event time stamp. A divisor and precision + * can be specified as part of this format string: + * "%precision.divisord". Example: + * "%3.1000d" - divide the time by 1000 and print the first + * 3 digits before the dot. Thus, the time stamp + * "123456000" will be printed as "123.456" + * TEP_PRINT_INFO, "%s" - event information. If any width is specified in + * the format string, the event information will be printed + * in raw format. + * Writes the specified event information into @s. */ -void tep_print_event_data(struct tep_handle *tep, struct trace_seq *s, - struct tep_event *event, - struct tep_record *record) -{ - static const char *spaces = " "; /* 20 spaces */ - int len; - - trace_seq_printf(s, " %s: ", event->name); - - /* Space out the event names evenly. */ - len = strlen(event->name); - if (len < 20) - trace_seq_printf(s, "%.*s", 20 - len, spaces); - - tep_event_info(s, event, record); -} - void tep_print_event(struct tep_handle *tep, struct trace_seq *s, - struct tep_record *record, bool use_trace_clock) -{ + struct tep_record *record, const char *fmt, ...) +{ + struct print_event_type type; + char *format = strdup(fmt); + char *current = format; + char *str = format; + int offset; + va_list args; struct tep_event *event; - event = tep_find_event_by_record(tep, record); - if (!event) { - int i; - int type = trace_parse_common_type(tep, record->data); - - do_warning("ug! no event found for type %d", type); - trace_seq_printf(s, "[UNKNOWN TYPE %d]", type); - for (i = 0; i < record->size; i++) - trace_seq_printf(s, " %02x", - ((unsigned char *)record->data)[i]); + if (!format) return; - } - tep_print_event_task(tep, s, event, record); - tep_print_event_time(tep, s, event, record, use_trace_clock); - tep_print_event_data(tep, s, event, record); + event = tep_find_event_by_record(tep, record); + va_start(args, fmt); + while (*current) { + current = strchr(str, '%'); + if (!current) { + trace_seq_puts(s, str); + break; + } + memset(&type, 0, sizeof(type)); + offset = tep_print_event_param_type(current, &type); + *current = '\0'; + trace_seq_puts(s, str); + current += offset; + switch (type.type) { + case EVENT_TYPE_STRING: + print_string(tep, s, record, event, + va_arg(args, char*), &type); + break; + case EVENT_TYPE_INT: + print_int(tep, s, record, event, + va_arg(args, int), &type); + break; + case EVENT_TYPE_UNKNOWN: + default: + trace_seq_printf(s, "[UNKNOWN TYPE]"); + break; + } + str = current; + + } + va_end(args); + free(format); } static int events_id_cmp(const void *a, const void *b) @@ -6963,7 +7059,6 @@ void tep_free(struct tep_handle *tep) free_handler(handle); } - free(tep->trace_clock); free(tep->events); free(tep->sort_events); free(tep->func_resolver); |