trace: Improve "trace show" command
The code were also applied to:
git://github.com/laijs/tracing-extension-module-for-crash.git Documents and man pages will/may be added in two weeks. Dave Anderson, could you add a "Requires" entry to its RPM.spec, it requires trace-cmd RPM after this patch applied. Thanks, Lai Subject: [PATCH] trace: Improve "trace show" command Use trace-cmd to implement "trace show" command and remove the related code. It is not a good idea to maintain another set of code with the same functional. trace-cmd is better and mature. How the new "trace show" works: 1) build trace.dat from the core file and dump it to /tmp. 2) exec "trace-cmd report" upon the trace.dat 3) splice the output of trace-cmd to user and unlink the temp file. Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com> --- trace.c | 1566 ++-------------------------------------------------------------- 1 file changed, 50 insertions(+), 1516 deletions(-) diff --git a/extensions/trace.c b/extensions/trace.c index 714765e..057459b 100755 --- a/extensions/trace.c +++ b/extensions/trace.c @@ -96,8 +96,6 @@ static const char *current_tracer_name; static void ftrace_destroy_event_types(void); static int ftrace_init_event_types(void); -static int ftrace_show_init(void); -static void ftrace_show_destroy(void); /* at = ((struct *)ptr)->member */ #define read_value(at, ptr, struct, member) @@ -489,13 +487,8 @@ static int ftrace_init(void) if (ftrace_init_current_tracer() < 0) goto out_2; - if (ftrace_show_init() < 0) - goto out_3; - return 0; -out_3: - free(current_tracer_name); out_2: ftrace_destroy_event_types(); out_1: @@ -511,7 +504,6 @@ out_0: static void ftrace_destroy(void) { - ftrace_show_destroy(); free(current_tracer_name); ftrace_destroy_event_types(); @@ -611,37 +603,21 @@ out_fail: return -1; } -typedef uint64_t u64; -typedef int64_t s64; -typedef uint32_t u32; - #define MAX_CACHE_ID 256 -struct ftrace_field; -typedef u64 (*access_op)(struct ftrace_field *aop, void *data); -static void ftrace_field_access_init(struct ftrace_field *f); - struct ftrace_field { const char *name; const char *type; - access_op op; int offset; int size; int is_signed; }; -struct event_type; -struct format_context; -typedef void (*event_printer)(struct event_type *t, struct format_context *fc); - - /* SIGH, we cann't get "print fmt" from core-file */ - struct event_type { struct event_type *next; const char *system; const char *name; int plugin; - event_printer printer; const char *print_fmt; int id; int nfields; @@ -655,16 +631,6 @@ static int nr_event_types; static struct ftrace_field *ftrace_common_fields; static int ftrace_common_fields_count; -/* - * TODO: implement event_generic_print_fmt_print() when the print fmt - * in tracing/events/$SYSTEM/$TRACE/format becomes a will-defined - * language. - */ -static void event_generic_print_fmt_print(struct event_type *t, - struct format_context *fc); -static void event_default_print(struct event_type *t, - struct format_context *fc); - static int syscall_get_enter_fields(ulong call, ulong *fields) { static int inited; @@ -887,7 +853,6 @@ static int ftrace_init_event_fields(ulong fields_head, int *pnfields, goto out_fail; } - ftrace_field_access_init(&fields[nfields]); nfields++; /* Advance to the next field */ @@ -1186,7 +1151,6 @@ static int ftrace_init_event_types(void) aevent_type->plugin = 1; else aevent_type->plugin = 0; - aevent_type->printer = event_default_print; /* Add a event type */ event_types[nr_event_types++] = aevent_type; @@ -1212,57 +1176,6 @@ out_fail: return -1; } -static -struct ftrace_field *find_event_field(struct event_type *t, const char *name) -{ - int i; - struct ftrace_field *f; - - for (i = 0; i < ftrace_common_fields_count; i++) { - f = ftrace_common_fields + i; - if (!strcmp(name, f->name)) - return f; - } - - for (i = 0; i < t->nfields; i++) { - f = &t->fields[i]; - if (!strcmp(name, f->name)) - return f; - } - - return NULL; -} - -static struct event_type *find_event_type(int id) -{ - int i; - - if ((unsigned int)id < MAX_CACHE_ID) - return event_type_cache[id]; - - for (i = 0; i < nr_event_types; i++) { - if (event_types[i]->id == id) - return event_types[i]; - } - - return NULL; -} - -static -struct event_type *find_event_type_by_name(const char *system, const char *name) -{ - int i; - - for (i = 0; i < nr_event_types; i++) { - if (system && strcmp(system, event_types[i]->system)) - continue; - if (!strcmp(name, event_types[i]->name)) - return event_types[i]; - } - - return NULL; -} - #define default_common_field_count 5 static int ftrace_dump_event_type(struct event_type *t, const char *path) @@ -1364,381 +1277,6 @@ static int ftrace_dump_event_types(const char *events_path) return 0; } -struct ring_buffer_per_cpu_stream { - struct ring_buffer_per_cpu *cpu_buffer; - void *curr_page; - int curr_page_indx; - - uint64_t ts; - uint32_t *offset; - uint32_t *commit; -}; - -static -int ring_buffer_per_cpu_stream_init(struct ring_buffer_per_cpu *cpu_buffer, - unsigned pages, struct ring_buffer_per_cpu_stream *s) -{ - s->cpu_buffer = cpu_buffer; - s->curr_page = malloc(PAGESIZE()); - if (s->curr_page == NULL) - return -1; - - s->curr_page_indx = -1; - return 0; -} - -static -void ring_buffer_per_cpu_stream_destroy(struct ring_buffer_per_cpu_stream *s) -{ - free(s->curr_page); -} - -struct ftrace_event { - uint64_t ts; - int length; - void *data; -}; - -struct event { - u32 type_len:5, time_delta:27; -}; - -#define RINGBUF_TYPE_PADDING 29 -#define RINGBUF_TYPE_TIME_EXTEND 30 -#define RINGBUF_TYPE_TIME_STAMP 31 -#define RINGBUF_TYPE_DATA 0 ... 28 - -#define sizeof_local_t (sizeof(ulong)) -#define PAGE_HEADER_LEN (8 + sizeof_local_t) - -static -int ring_buffer_per_cpu_stream_get_page(struct ring_buffer_per_cpu_stream *s) -{ - ulong raw_page; - - read_value(raw_page, s->cpu_buffer->linear_pages[s->curr_page_indx], - buffer_page, page); - - if (!readmem(raw_page, KVADDR, s->curr_page, PAGESIZE(), - "get page context", RETURN_ON_ERROR)) - return -1; - - s->ts = *(u64 *)s->curr_page; - s->offset = s->curr_page + PAGE_HEADER_LEN; - s->commit = s->offset + *(ulong *)(s->curr_page + 8) / 4; - - return 0; - -out_fail: - return -1; -} - -static -int ring_buffer_per_cpu_stream_pop_event(struct ring_buffer_per_cpu_stream *s, - struct ftrace_event *res) -{ - struct event *event; - - res->data = NULL; - - if (s->curr_page_indx >= s->cpu_buffer->nr_linear_pages) - return -1; - -again: - if ((s->curr_page_indx == -1) || (s->offset >= s->commit)) { - s->curr_page_indx++; - - if (s->curr_page_indx == s->cpu_buffer->nr_linear_pages) - return -1; - - if (ring_buffer_per_cpu_stream_get_page(s) < 0) { - s->curr_page_indx = s->cpu_buffer->nr_linear_pages; - return -1; - } - - if (s->offset >= s->commit) - goto again; - } - - event = (void *)s->offset; - - switch (event->type_len) { - case RINGBUF_TYPE_PADDING: - if (event->time_delta) - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); - else - s->offset = s->commit; - goto again; - - case RINGBUF_TYPE_TIME_EXTEND: - s->ts +=event->time_delta; - s->ts += ((u64)*(s->offset + 1)) << 27; - s->offset += 2; - goto again; - - case RINGBUF_TYPE_TIME_STAMP: - /* FIXME: not implemented */ - s->offset += 4; - goto again; - - case RINGBUF_TYPE_DATA: - if (!event->type_len) { - res->data = s->offset + 2; - res->length = *(s->offset + 1) - 4; - - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); - } else { - res->data = s->offset + 1; - res->length = event->type_len * 4; - - s->offset += 1 + event->type_len; - } - - if (s->offset > s->commit) { - fprintf(fp, "corrupt "); - res->data = NULL; - goto again; - } - - s->ts += event->time_delta; - res->ts = s->ts; - - return 0; - - default:; - } - - return -1; -} - -struct ring_buffer_stream { - struct ring_buffer_per_cpu_stream *ss; - struct ftrace_event *es; - u64 ts; - int popped_cpu; - int pushed; -}; - -static void __rbs_destroy(struct ring_buffer_stream *s, int *cpulist, int nr) -{ - int cpu; - - for (cpu = 0; cpu < nr; cpu++) { - if (!s->ss[cpu].cpu_buffer) - continue; - - ring_buffer_per_cpu_stream_destroy(s->ss + cpu); - } - - free(s->ss); - free(s->es); -} - -static -int ring_buffer_stream_init(struct ring_buffer_stream *s, int *cpulist) -{ - int cpu; - - s->ss = malloc(sizeof(*s->ss) * nr_cpu_ids); - if (s->ss == NULL) - return -1; - - s->es = malloc(sizeof(*s->es) * nr_cpu_ids); - if (s->es == NULL) { - free(s->ss); - return -1; - } - - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { - s->ss[cpu].cpu_buffer = NULL; - s->es[cpu].data = NULL; - - if (!global_buffers[cpu].kaddr) - continue; - - if (cpulist && !cpulist[cpu]) - continue; - - if (ring_buffer_per_cpu_stream_init(global_buffers + cpu, - global_pages, s->ss + cpu) < 0) { - __rbs_destroy(s, cpulist, cpu); - return -1; - } - } - - s->ts = 0; - s->popped_cpu = nr_cpu_ids; - s->pushed = 0; - - return 0; -} - -static -void ring_buffer_stream_destroy(struct ring_buffer_stream *s, int *cpulist) -{ - __rbs_destroy(s, cpulist, nr_cpu_ids); -} - -/* make current event be returned again at next pop */ -static void ring_buffer_stream_push_current_event(struct ring_buffer_stream *s) -{ - if ((s->popped_cpu < 0) || (s->popped_cpu == nr_cpu_ids)) - return; - - s->pushed = 1; -} - -/* return the cpu# of this event */ -static int ring_buffer_stream_pop_event(struct ring_buffer_stream *s, - struct ftrace_event *res) -{ - int cpu, min_cpu = -1; - u64 ts, min_ts; - - res->data = NULL; - - if (s->popped_cpu < 0) - return -1; - - if (s->popped_cpu == nr_cpu_ids) { - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { - if (!s->ss[cpu].cpu_buffer) - continue; - - ring_buffer_per_cpu_stream_pop_event(s->ss + cpu, - s->es + cpu); - - if (s->es[cpu].data == NULL) - continue; - - /* - * We do not have start point of time, - * determine the min_ts with heuristic way. - */ - ts = s->es[cpu].ts; - if (min_cpu < 0 || (s64)(ts - min_ts) < 0) { - min_ts = ts; - min_cpu = cpu; - } - } - - s->pushed = 0; - goto done; - } - - if (s->pushed) { - s->pushed = 0; - *res = s->es[s->popped_cpu]; - return s->popped_cpu; - } - - ring_buffer_per_cpu_stream_pop_event(&s->ss[s->popped_cpu], - &s->es[s->popped_cpu]); - - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { - if (s->es[cpu].data == NULL) - continue; - - /* we have start point of time(s->ts) */ - ts = s->es[cpu].ts - s->ts; - if (min_cpu < 0 || ts < min_ts) { - min_ts = ts; - min_cpu = cpu; - } - } - -done: - s->popped_cpu = min_cpu; - - if (min_cpu < 0) - return -1; - - s->ts = s->es[min_cpu].ts; - *res = s->es[min_cpu]; - - return min_cpu; -} - -static u64 access_error(struct ftrace_field *f, void *data) -{ - return 0; -} - -static u64 access_8(struct ftrace_field *f, void *data) -{ - return *(int8_t *)(data + f->offset); -} - -static u64 access_16(struct ftrace_field *f, void *data) -{ - return *(int16_t *)(data + f->offset); -} - -static u64 access_32(struct ftrace_field *f, void *data) -{ - return *(int32_t *)(data + f->offset); -} - -static u64 access_64(struct ftrace_field *f, void *data) -{ - return *(int64_t *)(data + f->offset); -} - -static u64 access_string_local(struct ftrace_field *f, void *data) -{ - int offset; - - if (f->size == 2) - offset = *(int16_t *)(data + f->offset); - else - offset = *(int32_t *)(data + f->offset) & 0xFFFF; - - return (long)(data + offset); -} - -static u64 access_string(struct ftrace_field *f, void *data) -{ - return (long)(data + f->offset); -} - -static u64 access_other_local(struct ftrace_field *f, void *data) -{ - return access_string_local(f, data); -} - -static u64 access_other(struct ftrace_field *f, void *data) -{ - return (long)(data + f->offset); -} - -static void ftrace_field_access_init(struct ftrace_field *f) -{ - /* guess whether it is string array */ - if (!strncmp(f->type, "__data_loc", sizeof("__data_loc") - 1)) { - if (f->size != 2 && f->size != 4) { - /* kernel side may be changed, need fix here */ - f->op = access_error; - } else if (strstr(f->type, "char")) { - f->op = access_string_local; - } else { - f->op = access_other_local; - } - } else if (strchr(f->type, '[')) { - if (strstr(f->type, "char")) - f->op = access_string; - else - f->op = access_other; - } else { - switch (f->size) { - case 1: f->op = access_8; break; - case 2: f->op = access_16; break; - case 4: f->op = access_32; break; - case 8: f->op = access_64; break; - default: f->op = access_other; break; - } - } -} - static void show_basic_info(void) { fprintf(fp, "current tracer is %s ", current_tracer_name); @@ -1881,334 +1419,58 @@ static void ftrace_dump(int argc, char *argv[]) } } -static char show_event_buf[4096]; -static int show_event_pos; - -#define INVALID_ACCESS_FIELD 1 -static jmp_buf show_event_env; - -struct format_context { - struct ring_buffer_stream stream; - struct ftrace_event event; - int cpu; -}; - -static struct format_context format_context; - -/* !!!! @event_type and @field_name should be const for every call */ -#define access_field(event_type, data, field_name) -({ - static struct ftrace_field *__access_field##_field; - - if (__access_field##_field == NULL) { - __access_field##_field = find_event_field(event_type, - field_name); - } - - if (__access_field##_field == NULL) { - event_type->printer = event_default_print; - ring_buffer_stream_push_current_event(&format_cont ext.stream); - longjmp(show_event_env, INVALID_ACCESS_FIELD); - } - - __access_field##_field->op(__access_field##_field, data); -}) - -static int ftrace_event_get_id(void *data) -{ - return access_field(event_types[0], data, "common_type"); -} - -static int ftrace_event_get_pid(void *data) -{ - return access_field(event_types[0], data, "common_pid"); -} - -#define event_printf(fmt, args...) -do { - show_event_pos += snprintf(show_event_buf + show_event_pos, - sizeof(show_event_buf) - show_event_pos, - fmt, ##args); -} while (0) - - -static void event_field_print(struct ftrace_field *f, void *data) +static void ftrace_show(int argc, char *argv[]) { - u64 value = f->op(f, data); + char buf[4096]; + char tmp[] = "/tmp/crash.trace_dat.XXXXXX"; + char *trace_cmd = "trace-cmd", *env_trace_cmd = getenv("TRACE_CMD"); + int fd; + FILE *file; + size_t ret; - if (f->op == access_error) { - event_printf("<Error>"); - } else if (f->op == access_8) { - if (f->is_signed) - event_printf("%d", (int8_t)value); - else - event_printf("%u", (uint8_t)value); - } else if (f->op == access_16) { - if (f->is_signed) - event_printf("%d", (int16_t)value); - else - event_printf("%u", (uint16_t)value); - } else if (f->op == access_32) { - if (f->is_signed) - event_printf("%d", (int32_t)value); - else - event_printf("%u", (uint32_t)value); - } else if (f->op == access_64) { - if (f->is_signed) - event_printf("%lld", (long long)value); + /* check trace-cmd */ + if (env_trace_cmd) + trace_cmd = env_trace_cmd; + if (!(file = popen(trace_cmd, "r"))) + return; + ret = fread(buf, 1, sizeof(buf), file); + buf[4097] = 0; + if (!strstr(buf, "trace-cmd version")) { + if (env_trace_cmd) + fprintf(fp, "Invalid environment TRACE_CMD: %s ", + env_trace_cmd); else - event_printf("%llu", (unsigned long long)value); - } else if (f->op == access_string_local) { - int size = 0; + fprintf(fp, ""trace show" requires trace-cmd. " + "please set the environment TRACE_CMD " + "if you installed it a special path " + ); + return; + } - if (f->size == 4) - size = *(int32_t *)(data + f->offset) >> 16; + /* dump trace.dat to the temp file */ + mktemp(tmp); + fd = open(tmp, O_WRONLY | O_CREAT | O_TRUNC, 0644); + if (trace_cmd_data_output(fd) < 0) + goto out; - if (size) - event_printf("%.*s", size, (char *)(long)value); - else - event_printf("%s", (char *)(long)value); - } else if (f->op == access_string) { - event_printf("%.*s", f->size, (char *)(long)value); - } else if (f->op == access_other) { - /* TODO */ - } else if (f->op == access_other_local) { - /* TODO */ - } else { - /* TODO */ + /* splice the output of trace-cmd to user */ + snprintf(buf, sizeof(buf), "%s report %s", trace_cmd, tmp); + if (!(file = popen(buf, "r"))) + goto out; + for (;;) { + ret = fread(buf, 1, sizeof(buf), file); + if (ret == 0) + break; + fwrite(buf, 1, ret, fp); } + pclose(file); +out: + close(fd); + unlink(tmp); + return; } -static void get_comm_from_pid(int pid, char *comm) -{ - int li, hi; - struct task_context *tc; - - if (pid == 0) { - strcpy(comm, "<swapper>"); - return; - } - - tc = FIRST_CONTEXT(); - - li = 0; - hi = RUNNING_TASKS(); - while (li < hi) { - int mid = (li + hi) / 2; - - if (tc[mid].pid > pid) - hi = mid; - else if (tc[mid].pid < pid) - li = mid + 1; - else { - strcpy(comm, tc[mid].comm); - return; - } - } - - strcpy(comm, "<...>"); -} - -static void event_context_print(struct event_type *t, struct format_context *fc) -{ - u64 time = fc->event.ts / 1000; - ulong sec = time / 1000000; - ulong usec = time % 1000000; - int pid = ftrace_event_get_pid(fc->event.data); - char comm[20]; - - get_comm_from_pid(pid, comm); - event_printf("%16s-%-5d [%03d] %5lu.%06lu: ", - comm, pid, fc->cpu, sec, usec); -} - -static int gopt_context_info; -static int gopt_sym_offset; -static int gopt_sym_addr; - -static int gopt_graph_print_duration; -static int gopt_graph_print_overhead; -static int gopt_graph_print_abstime; -static int gopt_graph_print_cpu; -static int gopt_graph_print_proc; -static int gopt_graph_print_overrun; - -static void set_all_flags_default(void) -{ - gopt_context_info = 1; - gopt_sym_offset = 0; - gopt_sym_addr = 0; - - gopt_graph_print_duration = 1; - gopt_graph_print_overhead = 1; - gopt_graph_print_abstime = 0; - gopt_graph_print_cpu = 1; - gopt_graph_print_proc = 0; - gopt_graph_print_overrun = 0; -} - -static void set_clear_flag(const char *flag_name, int set) -{ - if (!strcmp(flag_name, "context_info")) - gopt_context_info = set; - else if (!strcmp(flag_name, "sym_offset")) - gopt_sym_offset = set; - else if (!strcmp(flag_name, "sym_addr")) - gopt_sym_addr = set; - else if (!strcmp(flag_name, "graph_print_duration")) - gopt_graph_print_duration = set; - else if (!strcmp(flag_name, "graph_print_overhead")) - gopt_graph_print_overhead = set; - else if (!strcmp(flag_name, "graph_print_abstime")) - gopt_graph_print_abstime = set; - else if (!strcmp(flag_name, "graph_print_cpu")) - gopt_graph_print_cpu = set; - else if (!strcmp(flag_name, "graph_print_proc")) - gopt_graph_print_proc = set; - else if (!strcmp(flag_name, "graph_print_overrun")) - gopt_graph_print_overrun = set; - /* invalid flage_name is omitted. */ -} - -static int tracer_no_event_context; - -static void ftrace_show_function_graph_init(void); -static void ftrace_show_function_init(void); -static void ftrace_show_trace_event_init(void); - -static int ftrace_show_init(void) -{ - /* ftrace_event_get_id(), ftrace_event_get_pid() should not failed. */ - if (find_event_field(event_types[0], "common_type") == NULL) - return -1; - - if (find_event_field(event_types[0], "common_pid") == NULL) - return -1; - - ftrace_show_function_init(); - ftrace_show_function_graph_init(); - ftrace_show_trace_event_init(); - - return 0; -} - -void show_event(struct format_context *fc) -{ - struct event_type *etype; - int id; - - id = ftrace_event_get_id(fc->event.data); - etype = find_event_type(id); - - if (etype == NULL) { - event_printf("<Unknown event type> "); - return; - } - - if (!tracer_no_event_context && gopt_context_info) - event_context_print(etype, fc); - if (!etype->plugin) - event_printf("%s: ", etype->name); - etype->printer(etype, fc); -} - -static int parse_cpulist(int *cpulist, const char *cpulist_str, int len) -{ - unsigned a, b; - const char *s = cpulist_str; - - memset(cpulist, 0, sizeof(int) * len); - - do { - if (!isdigit(*s)) - return -1; - b = a = strtoul(s, (char **)&s, 10); - if (*s == '-') { - s++; - if (!isdigit(*s)) - return -1; - b = strtoul(s, (char **)&s, 10); - } - if (!(a <= b)) - return -1; - if (b >= len) - return -1; - while (a <= b) { - cpulist[a] = 1; - a++; - } - if (*s == ',') - s++; - } while (*s != ' ' && *s != ' '); - - return 0; -} - -static void ftrace_show_function_graph_start(void); - -static void ftrace_show(int argc, char *argv[]) -{ - int c; - int *cpulist = NULL; - - set_all_flags_default(); - ftrace_show_function_graph_start(); - - while ((c = getopt(argc, argv, "f:c:")) != EOF) { - switch(c) - { - case 'f': - if (optarg[0] == 'n' && optarg[1] == 'o') - set_clear_flag(optarg + 2, 0); - else - set_clear_flag(optarg, 1); - break; - case 'c': - if (cpulist) - goto err_arg; - - cpulist = malloc(sizeof(int) * nr_cpu_ids); - if (cpulist == NULL) { - error(INFO, "malloc() fail "); - return; - } - - if (parse_cpulist(cpulist, optarg, nr_cpu_ids) < 0) - goto err_arg; - break; - default: - goto err_arg; - } - } - - if (argc - optind != 0) { -err_arg: - cmd_usage(pc->curcmd, SYNOPSIS); - free(cpulist); - return; - } - - ring_buffer_stream_init(&format_context.stream, cpulist); - - /* Ignore setjmp()'s return value, no special things to do. */ - setjmp(show_event_env); - - for (;;) { - show_event_pos = 0; - format_context.cpu = ring_buffer_stream_pop_event( - &format_context.stream, &format_context.event); - if (format_context.cpu < 0) - break; - - show_event(&format_context); - fprintf(fp, "%s", show_event_buf); - } - - ring_buffer_stream_destroy(&format_context.stream, cpulist); - free(cpulist); -} - -static void cmd_ftrace(void) +static void cmd_ftrace(void) { if (argcnt == 1) show_basic_info(); @@ -2216,729 +1478,12 @@ static void cmd_ftrace(void) ftrace_dump(argcnt - 1, args + 1); else if (!strcmp(args[1], "show")) ftrace_show(argcnt - 1, args + 1); + else if (!strcmp(args[1], "report")) + ftrace_show(argcnt - 1, args + 1); else cmd_usage(pc->curcmd, SYNOPSIS); } -static void event_default_print(struct event_type *t, struct format_context *fc) -{ - int i; - - /* Skip the common types */ - for (i = t->nfields - 6; i >= 0; i--) { - struct ftrace_field *f; - - f = &t->fields[i]; - event_printf("%s=", f->name); - event_field_print(f, fc->event.data); - if (i) - event_printf(", "); - } - - event_printf(" "); -} - -static void sym_print(ulong sym, int opt_offset) -{ - if (!sym) { - event_printf("0"); - } else { - ulong offset; - struct syment *se; - - se = value_search(sym, &offset); - if (se) { - event_printf("%s", se->name); - if (opt_offset) - event_printf("+%lu", offset); - } - } -} - -static void event_fn_print(struct event_type *t, struct format_context *fc) -{ - unsigned long ip = access_field(t, fc->event.data, "ip"); - unsigned long parent_ip = access_field(t, fc->event.data, "parent_ip"); - - sym_print(ip, gopt_sym_offset); - if (gopt_sym_addr) - event_printf("<%lx>", ip); - - event_printf(" <-"); - - sym_print(parent_ip, gopt_sym_offset); - if (gopt_sym_addr) - event_printf("<%lx>", parent_ip); - - event_printf(" "); -} - -static void ftrace_show_function_init(void) -{ - struct event_type *t = find_event_type_by_name("ftrace", "function"); - - if (t) - t->printer = event_fn_print; -} - -#if 0 -/* simple */ -static void event_fn_entry_print(struct event_type *t, struct format_context *fc) -{ - ulong func = access_field(t, fc->event.data, "graph_ent.func"); - int depth = access_field(t, fc->event.data, "graph_ent.depth"); - - event_printf("%*s", depth, " "); - sym_print(func, gopt_sym_offset); - if (gopt_sym_addr) - event_printf("<%lx>", func); - event_printf("() {"); -} - -static void event_fn_return_print(struct event_type *t, struct format_context *fc) -{ - ulong func = access_field(t, fc->event.data, "ret.func"); - u64 calltime = access_field(t, fc->event.data, "ret.calltime"); - u64 rettime = access_field(t, fc->event.data, "ret.rettime"); - int depth = access_field(t, fc->event.data, "ret.depth"); - - event_printf("%*s} %lluns", depth, " ", - (unsigned long long)(rettime - calltime)); -} - -static void ftrace_show_function_graph_init(void) -{ - struct event_type *t1 = find_event_type_by_name( - "ftrace", "funcgraph_entry"); - struct event_type *t2 = find_event_type_by_name( - "ftrace", "funcgraph_exit"); - - if (t1 == NULL || t2 == NULL) - return; - - t1->printer = event_fn_entry_print; - t2->printer = event_fn_return_print; -} -#endif - - -#define TRACE_GRAPH_PROCINFO_LENGTH 14 -#define TRACE_GRAPH_INDENT 2 - -static int max_bytes_for_cpu; -static int *cpus_prev_pid; - -static int function_graph_entry_id; -static int function_graph_return_id; -static struct event_type *function_graph_entry_type; -static struct event_type *function_graph_return_type; - -static void ftrace_show_function_graph_start(void) -{ - int i; - - if (cpus_prev_pid == NULL) - return; - - for (i = 0; i < nr_cpu_ids; i++) - cpus_prev_pid[i] = -1; -} - -static void fn_graph_proc_print(int pid) -{ - int pid_strlen, comm_strlen; - char pid_str[20]; - char comm[20] = "<...>"; - - pid_strlen = sprintf(pid_str, "%d", pid); - comm_strlen = TRACE_GRAPH_PROCINFO_LENGTH - 1 - pid_strlen; - - get_comm_from_pid(pid, comm); - event_printf("%*.*s-%s", comm_strlen, comm_strlen, comm, pid_str); -} - -/* If the pid changed since the last trace, output this event */ -static void fn_graph_proc_switch_print(int pid, int cpu) -{ - int prev_pid = cpus_prev_pid[cpu]; - - cpus_prev_pid[cpu] = pid; - if ((prev_pid == pid) || (prev_pid == -1)) - return; - -/* - * Context-switch trace line: - - ------------------------------------------ - | 1) migration/0--1 => sshd-1755 - ------------------------------------------ - - */ - - event_printf(" ------------------------------------------ "); - event_printf(" %*d) ", max_bytes_for_cpu, cpu); - fn_graph_proc_print(prev_pid); - event_printf(" => "); - fn_graph_proc_print(pid); - event_printf(" ------------------------------------------ "); -} - -/* Signal a overhead of time execution to the output */ -static void fn_graph_overhead_print(unsigned long long duration) -{ - const char *s = " "; - - /* If duration disappear, we don't need anything */ - if (!gopt_graph_print_duration) - return; - - /* duration == -1 is for non nested entry or return */ - if ((duration != -1) && gopt_graph_print_overhead) { - /* Duration exceeded 100 msecs */ - if (duration > 100000ULL) - s = "! "; - /* Duration exceeded 10 msecs */ - else if (duration > 10000ULL) - s = "+ "; - } - - event_printf(s); -} - -static void fn_graph_abstime_print(u64 ts) -{ - u64 time = ts / 1000; - unsigned long sec = time / 1000000; - unsigned long usec = time % 1000000; - - event_printf("%5lu.%06lu | ", sec, usec); -} - -static void fn_graph_irq_print(int type) -{ - /* TODO: implement it. */ -} - -static void fn_graph_duration_print(unsigned long long duration) -{ - /* log10(ULONG_MAX) + ' ' */ - char msecs_str[21]; - char nsecs_str[5]; - int len; - unsigned long nsecs_rem = duration % 1000; - - duration = duration / 1000; - len = sprintf(msecs_str, "%lu", (unsigned long) duration); - - /* Print msecs */ - event_printf("%s", msecs_str); - - /* Print nsecs (we don't want to exceed 7 numbers) */ - if (len < 7) { - snprintf(nsecs_str, 8 - len, "%03lu", nsecs_rem); - event_printf(".%s", nsecs_str); - - len += strlen(nsecs_str); - } - - if (len > 7) - len = 7; - - event_printf(" us %*s| ", 7 - len, ""); -} - -/* Case of a leaf function on its call entry */ -static void fn_graph_entry_leaf_print(void *entry_data, void *exit_data) -{ - struct event_type *t = function_graph_return_type; - - u64 calltime = access_field(t, exit_data, "ret.calltime"); - u64 rettime = access_field(t, exit_data, "ret.rettime"); - u64 duration = rettime - calltime; - int depth = access_field(t, exit_data, "ret.depth"); - ulong func = access_field(t, exit_data, "ret.func"); - - fn_graph_overhead_print(duration); - if (gopt_graph_print_duration) - fn_graph_duration_print(duration); - - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); - sym_print(func, 0); - event_printf("(); "); -} - -static void fn_graph_entry_nested_print(struct event_type *t, void *data) -{ - int depth = access_field(t, data, "graph_ent.depth"); - ulong func = access_field(t, data, "graph_ent.func"); - - fn_graph_overhead_print(-1); - - /* No time */ - if (gopt_graph_print_duration) - event_printf(" | "); - - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); - sym_print(func, 0); - event_printf("() { "); -} - -static void fn_graph_prologue_print(int cpu, u64 ts, int pid, int type) -{ - fn_graph_proc_switch_print(pid, cpu); - - if (type) - fn_graph_irq_print(type); - - if (gopt_graph_print_abstime) - fn_graph_abstime_print(ts); - - if (gopt_graph_print_cpu) - event_printf(" %*d) ", max_bytes_for_cpu, cpu); - - if (gopt_graph_print_proc) { - fn_graph_proc_print(pid); - event_printf(" | "); - } -} - -static void *get_return_for_leaf(struct event_type *t, - struct format_context *fc, void *curr_data) -{ - int cpu; - struct ftrace_event next; - ulong entry_func, exit_func; - - cpu = ring_buffer_stream_pop_event(&fc->stream, &next); - - if (cpu < 0) - goto not_leaf; - - if (ftrace_event_get_id(next.data) != function_graph_return_id) - goto not_leaf; - - if (ftrace_event_get_pid(curr_data) != ftrace_event_get_pid(next.data)) - goto not_leaf; - - entry_func = access_field(t, curr_data, "graph_ent.func"); - exit_func = access_field(function_graph_return_type, next.data, - "ret.func"); - - if (entry_func != exit_func) - goto not_leaf; - - return next.data; - -not_leaf: - ring_buffer_stream_push_current_event(&fc->stream); - return NULL; -} - -static -void event_fn_entry_print(struct event_type *t, struct format_context *fc) -{ - void *leaf_ret_data = NULL, *curr_data = fc->event.data, *data; - int pid = ftrace_event_get_pid(curr_data); - - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 1); - - data = alloca(fc->event.length); - if (data) { - memcpy(data, fc->event.data, fc->event.length); - curr_data = data; - leaf_ret_data = get_return_for_leaf(t, fc, curr_data); - } - - if (leaf_ret_data) - return fn_graph_entry_leaf_print(curr_data, leaf_ret_data); - else - return fn_graph_entry_nested_print(t, curr_data); -} - -static -void event_fn_return_print(struct event_type *t, struct format_context *fc) -{ - void *data = fc->event.data; - int pid = ftrace_event_get_pid(data); - - u64 calltime = access_field(t, data, "ret.calltime"); - u64 rettime = access_field(t, data, "ret.rettime"); - u64 duration = rettime - calltime; - int depth = access_field(t, data, "ret.depth"); - - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 0); - fn_graph_overhead_print(duration); - - if (gopt_graph_print_duration) - fn_graph_duration_print(duration); - - event_printf("%*s} ", depth * TRACE_GRAPH_INDENT, ""); - - if (gopt_graph_print_overrun) { - unsigned long overrun = access_field(t, data, "ret.overrun"); - event_printf(" (Overruns: %lu) ", overrun); - } - - fn_graph_irq_print(0); -} - -static void ftrace_show_function_graph_init(void) -{ - if (strcmp(current_tracer_name, "function_graph")) - return; - - function_graph_entry_type = find_event_type_by_name( - "ftrace", "funcgraph_entry"); - function_graph_return_type = find_event_type_by_name( - "ftrace", "funcgraph_exit"); - - if (!function_graph_entry_type || !function_graph_return_type) - return; - - /* - * Because of get_return_for_leaf(), the exception handling - * of access_field() is not work for function_graph. So we need - * to ensure access_field() will not failed for these fields. - * - * I know these will not failed. I just ensure it. - */ - - if (!find_event_field(function_graph_entry_type, "graph_ent.func")) - return; - - if (!find_event_field(function_graph_entry_type, "graph_ent.depth")) - return; - - if (!find_event_field(function_graph_return_type, "ret.func")) - return; - - if (!find_event_field(function_graph_return_type, "ret.calltime")) - return; - - if (!find_event_field(function_graph_return_type, "ret.rettime")) - return; - - if (!find_event_field(function_graph_return_type, "ret.overrun")) - return; - - if (!find_event_field(function_graph_return_type, "ret.depth")) - return; - - cpus_prev_pid = malloc(sizeof(int) * nr_cpu_ids); - if (!cpus_prev_pid) - return; - - max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1); - - function_graph_entry_id = function_graph_entry_type->id; - function_graph_return_id = function_graph_return_type->id; - - /* OK, set the printer for function_graph. */ - tracer_no_event_context = 1; - function_graph_entry_type->printer = event_fn_entry_print; - function_graph_return_type->printer = event_fn_return_print; -} - -static void event_sched_kthread_stop_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid")); -} - -static void event_sched_kthread_stop_ret_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("ret %d ", (int)access_field(t, fc->event.data, "ret")); -} - -static void event_sched_wait_task_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_wakeup_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] success=%d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio"), - (int)access_field(t, fc->event.data, "success")); -} - -static void event_sched_wakeup_new_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] success=%d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio"), - (int)access_field(t, fc->event.data, "success")); -} - -static void event_sched_switch_print(struct event_type *t, - struct format_context *fc) -{ - char *prev_comm = (char *)(long)access_field(t, fc->event.data, - "prev_comm"); - int prev_pid = access_field(t, fc->event.data, "prev_pid"); - int prev_prio = access_field(t, fc->event.data, "prev_prio"); - - int prev_state = access_field(t, fc->event.data, "prev_state"); - - char *next_comm = (char *)(long)access_field(t, fc->event.data, - "next_comm"); - int next_pid = access_field(t, fc->event.data, "next_pid"); - int next_prio = access_field(t, fc->event.data, "next_prio"); - - event_printf("task %s:%d [%d] (", prev_comm, prev_pid, prev_prio); - - if (prev_state == 0) { - event_printf("R"); - } else { - if (prev_state & 1) - event_printf("S"); - if (prev_state & 2) - event_printf("D"); - if (prev_state & 4) - event_printf("T"); - if (prev_state & 8) - event_printf("t"); - if (prev_state & 16) - event_printf("Z"); - if (prev_state & 32) - event_printf("X"); - if (prev_state & 64) - event_printf("x"); - if (prev_state & 128) - event_printf("W"); - } - - event_printf(") ==> %s:%d [%d] ", next_comm, next_pid, next_prio); -} - -static void event_sched_migrate_task_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] from: %d to: %d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio"), - (int)access_field(t, fc->event.data, "orig_cpu"), - (int)access_field(t, fc->event.data, "dest_cpu")); -} - -static void event_sched_process_free_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_process_exit_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_process_wait_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_process_fork_print(struct event_type *t, - struct format_context *fc) -{ - char *parent_comm = (char *)(long)access_field(t, fc->event.data, - "parent_comm"); - int parent_pid = access_field(t, fc->event.data, "parent_pid"); - - char *child_comm = (char *)(long)access_field(t, fc->event.data, - "child_comm"); - int child_pid = access_field(t, fc->event.data, "child_pid"); - - event_printf("parent %s:%d child %s:%d ", parent_comm, parent_pid, - child_comm, child_pid); -} - -static void event_sched_signal_send_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("sig: %d task %s:%d ", - (int)access_field(t, fc->event.data, "sig"), - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid")); -} - -static void event_kmalloc_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags")); -} - -static void event_kmem_cache_alloc_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags")); -} - -static void event_kmalloc_node_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx node=%d ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags"), - (int)access_field(t, fc->event.data, "node")); -} - -static void event_kmem_cache_alloc_node_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx node=%d ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags"), - (int)access_field(t, fc->event.data, "node")); -} - -static void event_kfree_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr")); -} - -static void event_kmem_cache_free_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr")); -} - -static void event_workqueue_insertion_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - ulong func = access_field(t, fc->event.data, "func"); - - event_printf("thread=%s:%d func=", thread_comm, thread_pid); - sym_print(func, 1); - event_printf(" "); -} - -static void event_workqueue_execution_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - ulong func = access_field(t, fc->event.data, "func"); - - event_printf("thread=%s:%d func=", thread_comm, thread_pid); - sym_print(func, 1); - event_printf(" "); -} - -static void event_workqueue_creation_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - int cpu = access_field(t, fc->event.data, "cpu"); - - event_printf("thread=%s:%d cpu=%d ", thread_comm, thread_pid, cpu); -} - -static void event_workqueue_destruction_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - - event_printf("thread=%s:%d ", thread_comm, thread_pid); -} - -static void ftrace_show_trace_event_init(void) -{ -#define init_trace_event(system, name) -do { - struct event_type *t = find_event_type_by_name(#system, #name); - if (t) - t->printer = event_ ## name ## _print; -} while (0) - - init_trace_event(sched, sched_kthread_stop); - init_trace_event(sched, sched_kthread_stop_ret); - init_trace_event(sched, sched_wait_task); - init_trace_event(sched, sched_wakeup); - init_trace_event(sched, sched_wakeup_new); - init_trace_event(sched, sched_switch); - init_trace_event(sched, sched_migrate_task); - init_trace_event(sched, sched_process_free); - init_trace_event(sched, sched_process_exit); - init_trace_event(sched, sched_process_wait); - init_trace_event(sched, sched_process_fork); - init_trace_event(sched, sched_signal_send); - - init_trace_event(kmem, kmalloc); - init_trace_event(kmem, kmem_cache_alloc); - init_trace_event(kmem, kmalloc_node); - init_trace_event(kmem, kmem_cache_alloc_node); - init_trace_event(kmem, kfree); - init_trace_event(kmem, kmem_cache_free); - - init_trace_event(workqueue, workqueue_insertion); - init_trace_event(workqueue, workqueue_execution); - init_trace_event(workqueue, workqueue_creation); - init_trace_event(workqueue, workqueue_destruction); -#undef init_trace_event -} - -static void ftrace_show_destroy(void) -{ - free(cpus_prev_pid); -} - static char *help_ftrace[] = { "trace", "show or dump the tracing info", @@ -2946,22 +1491,11 @@ static char *help_ftrace[] = { "trace", " shows the current tracer and other informations.", "", -"trace show [ -c <cpulist> ] [ -f [no]<flagename> ]", +"trace show", " shows all events with readability text(sorted by timestamp)", -" -c: only shows specified CPUs' events.", -" ex. trace show -c 1,2 - only shows cpu#1 and cpu#2 's events.", -" trace show -c 0,2-7 - only shows cpu#0, cpu#2...cpu#7's events.", -" -f: set or clear a flag", -" available flags default", -" context_info true", -" sym_offset false", -" sym_addr false", -" graph_print_duration true", -" graph_print_overhead true", -" graph_print_abstime false", -" graph_print_cpu true", -" graph_print_proc false", -" graph_print_overrun false", +"", +"trace report", +" the same as "trace show"", "", "trace dump [-sm] <dest-dir>", " dump ring_buffers to dest-dir. Then you can parse it", -- Crash-utility mailing list Crash-utility@redhat.com https://www.redhat.com/mailman/listinfo/crash-utility |
trace: Improve "trace show" command
----- Original Message -----
> The code were also applied to: > git://github.com/laijs/tracing-extension-module-for-crash.git > > Documents and man pages will/may be added in two weeks. > > Dave Anderson, could you add a "Requires" entry to its RPM.spec, > it requires trace-cmd RPM after this patch applied. Sorry, but no, I cannot do that. There are two versions of the trace.c extension module that I am aware of: (1) The extensions/trace.c file that is included as part of each upstream crash utility release. That version is the one that you updated in crash-5.1.2 to add support for kernel versions beyond 2.6.32. - Update of the "extensions/trace.c" extension module. Initially designed to support 2.6.32 (RHEL6), it has been updated to support kernels up to 2.6.38-rc1. (laijs@cn.fujitsu.com) (2) the trace.c file in the RHEL6 crash-trace-command-1.0-3.el6.src.rpm package. Now, with respect to (1), I can certainly update the version in the next crash-5.1.3 release. However, the patch does not apply to that version: # lsdiff trace-command.patch a/extensions/trace.c # patch -p1 < trace-command.patch patching file extensions/trace.c Hunk #5 FAILED at 631. Hunk #6 succeeded at 854 (offset 1 line). Hunk #8 succeeded at 1177 (offset 1 line). Hunk #10 succeeded at 1420 (offset 1 line). Hunk #12 FAILED at 1491. 2 out of 12 hunks FAILED -- saving rejects to file extensions/trace.c.rej # And with respect to (2), if you want to re-work the RHEL6 version, you will have to work with Red Hat's Fujitsu TAM (Technical Account Manager), open an Issue-Tracker and accompanying bugzilla, get it approved for a RHEL6 errata release, etc., -- in other words, go through the same channels that resulted in the package being proposed and accepted as a RHEL6 package. That procedure is completely beyond the scope of this mailing list. And FWIW, your patch does not apply to that version of trace.c either. If I install the RHEL6 crash-trace-command-1.0-3.el6.src.rpm package, (where there is no "extensions" directory) and try to apply the patch: # rpm -ivh crash-trace-command-1.0-3.el6.src.rpm # cd /rpmbuild/SPECS # rpmbuild -bp crash-trace-command.spec ... # cd ../BUILD/crash-trace-command-1.0 # patch -p2 < /tmp/trace-command.patch patching file trace.c Hunk #1 succeeded at 97 (offset 1 line). Hunk #2 succeeded at 433 (offset -54 lines). Hunk #3 succeeded at 450 (offset -54 lines). Hunk #4 succeeded at 566 (offset -37 lines). Hunk #5 FAILED at 631. Hunk #6 succeeded at 669 (offset -194 lines). Hunk #7 succeeded at 772 (offset -389 lines). Hunk #8 FAILED at 1186. Hunk #9 FAILED at 1338. Hunk #10 succeeded at 1395 (offset -460 lines). Hunk #11 succeeded at 1454 (offset -460 lines). Hunk #12 FAILED at 1927. 4 out of 12 hunks FAILED -- saving rejects to file trace.c.rej # So I don't even know what version of trace.c your patch applies to? In any case, if you would like to update the version of trace.c in the upcoming crash-5.1.3 release, please post a patch that applies cleanly. And if you (Fujitsu) would like to update the RHEL6 crash-trace-command package, please go through the proper channels. Thanks, Dave > Subject: [PATCH] trace: Improve "trace show" command > > Use trace-cmd to implement "trace show" command and remove > the related code. It is not a good idea to maintain another > set of code with the same functional. trace-cmd is better > and mature. > > How the new "trace show" works: > 1) build trace.dat from the core file and dump it to /tmp. > 2) exec "trace-cmd report" upon the trace.dat > 3) splice the output of trace-cmd to user and unlink the temp file. > > Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com> > --- > trace.c | 1566 > ++-------------------------------------------------------------- > 1 file changed, 50 insertions(+), 1516 deletions(-) > > diff --git a/extensions/trace.c b/extensions/trace.c > index 714765e..057459b 100755 > --- a/extensions/trace.c > +++ b/extensions/trace.c > @@ -96,8 +96,6 @@ static const char *current_tracer_name; > > static void ftrace_destroy_event_types(void); > static int ftrace_init_event_types(void); > -static int ftrace_show_init(void); > -static void ftrace_show_destroy(void); > > /* at = ((struct *)ptr)->member */ > #define read_value(at, ptr, struct, member) > @@ -489,13 +487,8 @@ static int ftrace_init(void) > if (ftrace_init_current_tracer() < 0) > goto out_2; > > - if (ftrace_show_init() < 0) > - goto out_3; > - > return 0; > > -out_3: > - free(current_tracer_name); > out_2: > ftrace_destroy_event_types(); > out_1: > @@ -511,7 +504,6 @@ out_0: > > static void ftrace_destroy(void) > { > - ftrace_show_destroy(); > free(current_tracer_name); > ftrace_destroy_event_types(); > > @@ -611,37 +603,21 @@ out_fail: > return -1; > } > > -typedef uint64_t u64; > -typedef int64_t s64; > -typedef uint32_t u32; > - > #define MAX_CACHE_ID 256 > > -struct ftrace_field; > -typedef u64 (*access_op)(struct ftrace_field *aop, void *data); > -static void ftrace_field_access_init(struct ftrace_field *f); > - > struct ftrace_field { > const char *name; > const char *type; > - access_op op; > int offset; > int size; > int is_signed; > }; > > -struct event_type; > -struct format_context; > -typedef void (*event_printer)(struct event_type *t, struct > format_context *fc); > - > - /* SIGH, we cann't get "print fmt" from core-file */ > - > struct event_type { > struct event_type *next; > const char *system; > const char *name; > int plugin; > - event_printer printer; > const char *print_fmt; > int id; > int nfields; > @@ -655,16 +631,6 @@ static int nr_event_types; > static struct ftrace_field *ftrace_common_fields; > static int ftrace_common_fields_count; > > -/* > - * TODO: implement event_generic_print_fmt_print() when the print fmt > - * in tracing/events/$SYSTEM/$TRACE/format becomes a will-defined > - * language. > - */ > -static void event_generic_print_fmt_print(struct event_type *t, > - struct format_context *fc); > -static void event_default_print(struct event_type *t, > - struct format_context *fc); > - > static int syscall_get_enter_fields(ulong call, ulong *fields) > { > static int inited; > @@ -887,7 +853,6 @@ static int ftrace_init_event_fields(ulong > fields_head, int *pnfields, > goto out_fail; > } > > - ftrace_field_access_init(&fields[nfields]); > nfields++; > > /* Advance to the next field */ > @@ -1186,7 +1151,6 @@ static int ftrace_init_event_types(void) > aevent_type->plugin = 1; > else > aevent_type->plugin = 0; > - aevent_type->printer = event_default_print; > > /* Add a event type */ > event_types[nr_event_types++] = aevent_type; > @@ -1212,57 +1176,6 @@ out_fail: > return -1; > } > > -static > -struct ftrace_field *find_event_field(struct event_type *t, const > char *name) > -{ > - int i; > - struct ftrace_field *f; > - > - for (i = 0; i < ftrace_common_fields_count; i++) { > - f = ftrace_common_fields + i; > - if (!strcmp(name, f->name)) > - return f; > - } > - > - for (i = 0; i < t->nfields; i++) { > - f = &t->fields[i]; > - if (!strcmp(name, f->name)) > - return f; > - } > - > - return NULL; > -} > - > -static struct event_type *find_event_type(int id) > -{ > - int i; > - > - if ((unsigned int)id < MAX_CACHE_ID) > - return event_type_cache[id]; > - > - for (i = 0; i < nr_event_types; i++) { > - if (event_types[i]->id == id) > - return event_types[i]; > - } > - > - return NULL; > -} > - > -static > -struct event_type *find_event_type_by_name(const char *system, const > char *name) > -{ > - int i; > - > - for (i = 0; i < nr_event_types; i++) { > - if (system && strcmp(system, event_types[i]->system)) > - continue; > - if (!strcmp(name, event_types[i]->name)) > - return event_types[i]; > - } > - > - return NULL; > -} > - > #define default_common_field_count 5 > > static int ftrace_dump_event_type(struct event_type *t, const char > *path) > @@ -1364,381 +1277,6 @@ static int ftrace_dump_event_types(const char > *events_path) > return 0; > } > > -struct ring_buffer_per_cpu_stream { > - struct ring_buffer_per_cpu *cpu_buffer; > - void *curr_page; > - int curr_page_indx; > - > - uint64_t ts; > - uint32_t *offset; > - uint32_t *commit; > -}; > - > -static > -int ring_buffer_per_cpu_stream_init(struct ring_buffer_per_cpu > *cpu_buffer, > - unsigned pages, struct ring_buffer_per_cpu_stream *s) > -{ > - s->cpu_buffer = cpu_buffer; > - s->curr_page = malloc(PAGESIZE()); > - if (s->curr_page == NULL) > - return -1; > - > - s->curr_page_indx = -1; > - return 0; > -} > - > -static > -void ring_buffer_per_cpu_stream_destroy(struct > ring_buffer_per_cpu_stream *s) > -{ > - free(s->curr_page); > -} > - > -struct ftrace_event { > - uint64_t ts; > - int length; > - void *data; > -}; > - > -struct event { > - u32 type_len:5, time_delta:27; > -}; > - > -#define RINGBUF_TYPE_PADDING 29 > -#define RINGBUF_TYPE_TIME_EXTEND 30 > -#define RINGBUF_TYPE_TIME_STAMP 31 > -#define RINGBUF_TYPE_DATA 0 ... 28 > - > -#define sizeof_local_t (sizeof(ulong)) > -#define PAGE_HEADER_LEN (8 + sizeof_local_t) > - > -static > -int ring_buffer_per_cpu_stream_get_page(struct > ring_buffer_per_cpu_stream *s) > -{ > - ulong raw_page; > - > - read_value(raw_page, s->cpu_buffer->linear_pages[s->curr_page_indx], > - buffer_page, page); > - > - if (!readmem(raw_page, KVADDR, s->curr_page, PAGESIZE(), > - "get page context", RETURN_ON_ERROR)) > - return -1; > - > - s->ts = *(u64 *)s->curr_page; > - s->offset = s->curr_page + PAGE_HEADER_LEN; > - s->commit = s->offset + *(ulong *)(s->curr_page + 8) / 4; > - > - return 0; > - > -out_fail: > - return -1; > -} > - > -static > -int ring_buffer_per_cpu_stream_pop_event(struct > ring_buffer_per_cpu_stream *s, > - struct ftrace_event *res) > -{ > - struct event *event; > - > - res->data = NULL; > - > - if (s->curr_page_indx >= s->cpu_buffer->nr_linear_pages) > - return -1; > - > -again: > - if ((s->curr_page_indx == -1) || (s->offset >= s->commit)) { > - s->curr_page_indx++; > - > - if (s->curr_page_indx == s->cpu_buffer->nr_linear_pages) > - return -1; > - > - if (ring_buffer_per_cpu_stream_get_page(s) < 0) { > - s->curr_page_indx = s->cpu_buffer->nr_linear_pages; > - return -1; > - } > - > - if (s->offset >= s->commit) > - goto again; > - } > - > - event = (void *)s->offset; > - > - switch (event->type_len) { > - case RINGBUF_TYPE_PADDING: > - if (event->time_delta) > - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); > - else > - s->offset = s->commit; > - goto again; > - > - case RINGBUF_TYPE_TIME_EXTEND: > - s->ts +=event->time_delta; > - s->ts += ((u64)*(s->offset + 1)) << 27; > - s->offset += 2; > - goto again; > - > - case RINGBUF_TYPE_TIME_STAMP: > - /* FIXME: not implemented */ > - s->offset += 4; > - goto again; > - > - case RINGBUF_TYPE_DATA: > - if (!event->type_len) { > - res->data = s->offset + 2; > - res->length = *(s->offset + 1) - 4; > - > - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); > - } else { > - res->data = s->offset + 1; > - res->length = event->type_len * 4; > - > - s->offset += 1 + event->type_len; > - } > - > - if (s->offset > s->commit) { > - fprintf(fp, "corrupt "); > - res->data = NULL; > - goto again; > - } > - > - s->ts += event->time_delta; > - res->ts = s->ts; > - > - return 0; > - > - default:; > - } > - > - return -1; > -} > - > -struct ring_buffer_stream { > - struct ring_buffer_per_cpu_stream *ss; > - struct ftrace_event *es; > - u64 ts; > - int popped_cpu; > - int pushed; > -}; > - > -static void __rbs_destroy(struct ring_buffer_stream *s, int *cpulist, > int nr) > -{ > - int cpu; > - > - for (cpu = 0; cpu < nr; cpu++) { > - if (!s->ss[cpu].cpu_buffer) > - continue; > - > - ring_buffer_per_cpu_stream_destroy(s->ss + cpu); > - } > - > - free(s->ss); > - free(s->es); > -} > - > -static > -int ring_buffer_stream_init(struct ring_buffer_stream *s, int > *cpulist) > -{ > - int cpu; > - > - s->ss = malloc(sizeof(*s->ss) * nr_cpu_ids); > - if (s->ss == NULL) > - return -1; > - > - s->es = malloc(sizeof(*s->es) * nr_cpu_ids); > - if (s->es == NULL) { > - free(s->ss); > - return -1; > - } > - > - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { > - s->ss[cpu].cpu_buffer = NULL; > - s->es[cpu].data = NULL; > - > - if (!global_buffers[cpu].kaddr) > - continue; > - > - if (cpulist && !cpulist[cpu]) > - continue; > - > - if (ring_buffer_per_cpu_stream_init(global_buffers + cpu, > - global_pages, s->ss + cpu) < 0) { > - __rbs_destroy(s, cpulist, cpu); > - return -1; > - } > - } > - > - s->ts = 0; > - s->popped_cpu = nr_cpu_ids; > - s->pushed = 0; > - > - return 0; > -} > - > -static > -void ring_buffer_stream_destroy(struct ring_buffer_stream *s, int > *cpulist) > -{ > - __rbs_destroy(s, cpulist, nr_cpu_ids); > -} > - > -/* make current event be returned again at next pop */ > -static void ring_buffer_stream_push_current_event(struct > ring_buffer_stream *s) > -{ > - if ((s->popped_cpu < 0) || (s->popped_cpu == nr_cpu_ids)) > - return; > - > - s->pushed = 1; > -} > - > -/* return the cpu# of this event */ > -static int ring_buffer_stream_pop_event(struct ring_buffer_stream *s, > - struct ftrace_event *res) > -{ > - int cpu, min_cpu = -1; > - u64 ts, min_ts; > - > - res->data = NULL; > - > - if (s->popped_cpu < 0) > - return -1; > - > - if (s->popped_cpu == nr_cpu_ids) { > - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { > - if (!s->ss[cpu].cpu_buffer) > - continue; > - > - ring_buffer_per_cpu_stream_pop_event(s->ss + cpu, > - s->es + cpu); > - > - if (s->es[cpu].data == NULL) > - continue; > - > - /* > - * We do not have start point of time, > - * determine the min_ts with heuristic way. > - */ > - ts = s->es[cpu].ts; > - if (min_cpu < 0 || (s64)(ts - min_ts) < 0) { > - min_ts = ts; > - min_cpu = cpu; > - } > - } > - > - s->pushed = 0; > - goto done; > - } > - > - if (s->pushed) { > - s->pushed = 0; > - *res = s->es[s->popped_cpu]; > - return s->popped_cpu; > - } > - > - ring_buffer_per_cpu_stream_pop_event(&s->ss[s->popped_cpu], > - &s->es[s->popped_cpu]); > - > - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { > - if (s->es[cpu].data == NULL) > - continue; > - > - /* we have start point of time(s->ts) */ > - ts = s->es[cpu].ts - s->ts; > - if (min_cpu < 0 || ts < min_ts) { > - min_ts = ts; > - min_cpu = cpu; > - } > - } > - > -done: > - s->popped_cpu = min_cpu; > - > - if (min_cpu < 0) > - return -1; > - > - s->ts = s->es[min_cpu].ts; > - *res = s->es[min_cpu]; > - > - return min_cpu; > -} > - > -static u64 access_error(struct ftrace_field *f, void *data) > -{ > - return 0; > -} > - > -static u64 access_8(struct ftrace_field *f, void *data) > -{ > - return *(int8_t *)(data + f->offset); > -} > - > -static u64 access_16(struct ftrace_field *f, void *data) > -{ > - return *(int16_t *)(data + f->offset); > -} > - > -static u64 access_32(struct ftrace_field *f, void *data) > -{ > - return *(int32_t *)(data + f->offset); > -} > - > -static u64 access_64(struct ftrace_field *f, void *data) > -{ > - return *(int64_t *)(data + f->offset); > -} > - > -static u64 access_string_local(struct ftrace_field *f, void *data) > -{ > - int offset; > - > - if (f->size == 2) > - offset = *(int16_t *)(data + f->offset); > - else > - offset = *(int32_t *)(data + f->offset) & 0xFFFF; > - > - return (long)(data + offset); > -} > - > -static u64 access_string(struct ftrace_field *f, void *data) > -{ > - return (long)(data + f->offset); > -} > - > -static u64 access_other_local(struct ftrace_field *f, void *data) > -{ > - return access_string_local(f, data); > -} > - > -static u64 access_other(struct ftrace_field *f, void *data) > -{ > - return (long)(data + f->offset); > -} > - > -static void ftrace_field_access_init(struct ftrace_field *f) > -{ > - /* guess whether it is string array */ > - if (!strncmp(f->type, "__data_loc", sizeof("__data_loc") - 1)) { > - if (f->size != 2 && f->size != 4) { > - /* kernel side may be changed, need fix here */ > - f->op = access_error; > - } else if (strstr(f->type, "char")) { > - f->op = access_string_local; > - } else { > - f->op = access_other_local; > - } > - } else if (strchr(f->type, '[')) { > - if (strstr(f->type, "char")) > - f->op = access_string; > - else > - f->op = access_other; > - } else { > - switch (f->size) { > - case 1: f->op = access_8; break; > - case 2: f->op = access_16; break; > - case 4: f->op = access_32; break; > - case 8: f->op = access_64; break; > - default: f->op = access_other; break; > - } > - } > -} > - > static void show_basic_info(void) > { > fprintf(fp, "current tracer is %s ", current_tracer_name); > @@ -1881,334 +1419,58 @@ static void ftrace_dump(int argc, char > *argv[]) > } > } > > -static char show_event_buf[4096]; > -static int show_event_pos; > - > -#define INVALID_ACCESS_FIELD 1 > -static jmp_buf show_event_env; > - > -struct format_context { > - struct ring_buffer_stream stream; > - struct ftrace_event event; > - int cpu; > -}; > - > -static struct format_context format_context; > - > -/* !!!! @event_type and @field_name should be const for every call */ > -#define access_field(event_type, data, field_name) > -({ > - static struct ftrace_field *__access_field##_field; > - > - if (__access_field##_field == NULL) { > - __access_field##_field = find_event_field(event_type, > - field_name); > - } > - > - if (__access_field##_field == NULL) { > - event_type->printer = event_default_print; > - ring_buffer_stream_push_current_event(&format_cont ext.stream); > - longjmp(show_event_env, INVALID_ACCESS_FIELD); > - } > - > - __access_field##_field->op(__access_field##_field, data); > -}) > - > -static int ftrace_event_get_id(void *data) > -{ > - return access_field(event_types[0], data, "common_type"); > -} > - > -static int ftrace_event_get_pid(void *data) > -{ > - return access_field(event_types[0], data, "common_pid"); > -} > - > -#define event_printf(fmt, args...) > -do { > - show_event_pos += snprintf(show_event_buf + show_event_pos, > - sizeof(show_event_buf) - show_event_pos, > - fmt, ##args); > -} while (0) > - > - > -static void event_field_print(struct ftrace_field *f, void *data) > +static void ftrace_show(int argc, char *argv[]) > { > - u64 value = f->op(f, data); > + char buf[4096]; > + char tmp[] = "/tmp/crash.trace_dat.XXXXXX"; > + char *trace_cmd = "trace-cmd", *env_trace_cmd = getenv("TRACE_CMD"); > + int fd; > + FILE *file; > + size_t ret; > > - if (f->op == access_error) { > - event_printf("<Error>"); > - } else if (f->op == access_8) { > - if (f->is_signed) > - event_printf("%d", (int8_t)value); > - else > - event_printf("%u", (uint8_t)value); > - } else if (f->op == access_16) { > - if (f->is_signed) > - event_printf("%d", (int16_t)value); > - else > - event_printf("%u", (uint16_t)value); > - } else if (f->op == access_32) { > - if (f->is_signed) > - event_printf("%d", (int32_t)value); > - else > - event_printf("%u", (uint32_t)value); > - } else if (f->op == access_64) { > - if (f->is_signed) > - event_printf("%lld", (long long)value); > + /* check trace-cmd */ > + if (env_trace_cmd) > + trace_cmd = env_trace_cmd; > + if (!(file = popen(trace_cmd, "r"))) > + return; > + ret = fread(buf, 1, sizeof(buf), file); > + buf[4097] = 0; > + if (!strstr(buf, "trace-cmd version")) { > + if (env_trace_cmd) > + fprintf(fp, "Invalid environment TRACE_CMD: %s ", > + env_trace_cmd); > else > - event_printf("%llu", (unsigned long long)value); > - } else if (f->op == access_string_local) { > - int size = 0; > + fprintf(fp, ""trace show" requires trace-cmd. " > + "please set the environment TRACE_CMD " > + "if you installed it a special path " > + ); > + return; > + } > > - if (f->size == 4) > - size = *(int32_t *)(data + f->offset) >> 16; > + /* dump trace.dat to the temp file */ > + mktemp(tmp); > + fd = open(tmp, O_WRONLY | O_CREAT | O_TRUNC, 0644); > + if (trace_cmd_data_output(fd) < 0) > + goto out; > > - if (size) > - event_printf("%.*s", size, (char *)(long)value); > - else > - event_printf("%s", (char *)(long)value); > - } else if (f->op == access_string) { > - event_printf("%.*s", f->size, (char *)(long)value); > - } else if (f->op == access_other) { > - /* TODO */ > - } else if (f->op == access_other_local) { > - /* TODO */ > - } else { > - /* TODO */ > + /* splice the output of trace-cmd to user */ > + snprintf(buf, sizeof(buf), "%s report %s", trace_cmd, tmp); > + if (!(file = popen(buf, "r"))) > + goto out; > + for (;;) { > + ret = fread(buf, 1, sizeof(buf), file); > + if (ret == 0) > + break; > + fwrite(buf, 1, ret, fp); > } > + pclose(file); > +out: > + close(fd); > + unlink(tmp); > + return; > } > > -static void get_comm_from_pid(int pid, char *comm) > -{ > - int li, hi; > - struct task_context *tc; > - > - if (pid == 0) { > - strcpy(comm, "<swapper>"); > - return; > - } > - > - tc = FIRST_CONTEXT(); > - > - li = 0; > - hi = RUNNING_TASKS(); > - while (li < hi) { > - int mid = (li + hi) / 2; > - > - if (tc[mid].pid > pid) > - hi = mid; > - else if (tc[mid].pid < pid) > - li = mid + 1; > - else { > - strcpy(comm, tc[mid].comm); > - return; > - } > - } > - > - strcpy(comm, "<...>"); > -} > - > -static void event_context_print(struct event_type *t, struct > format_context *fc) > -{ > - u64 time = fc->event.ts / 1000; > - ulong sec = time / 1000000; > - ulong usec = time % 1000000; > - int pid = ftrace_event_get_pid(fc->event.data); > - char comm[20]; > - > - get_comm_from_pid(pid, comm); > - event_printf("%16s-%-5d [%03d] %5lu.%06lu: ", > - comm, pid, fc->cpu, sec, usec); > -} > - > -static int gopt_context_info; > -static int gopt_sym_offset; > -static int gopt_sym_addr; > - > -static int gopt_graph_print_duration; > -static int gopt_graph_print_overhead; > -static int gopt_graph_print_abstime; > -static int gopt_graph_print_cpu; > -static int gopt_graph_print_proc; > -static int gopt_graph_print_overrun; > - > -static void set_all_flags_default(void) > -{ > - gopt_context_info = 1; > - gopt_sym_offset = 0; > - gopt_sym_addr = 0; > - > - gopt_graph_print_duration = 1; > - gopt_graph_print_overhead = 1; > - gopt_graph_print_abstime = 0; > - gopt_graph_print_cpu = 1; > - gopt_graph_print_proc = 0; > - gopt_graph_print_overrun = 0; > -} > - > -static void set_clear_flag(const char *flag_name, int set) > -{ > - if (!strcmp(flag_name, "context_info")) > - gopt_context_info = set; > - else if (!strcmp(flag_name, "sym_offset")) > - gopt_sym_offset = set; > - else if (!strcmp(flag_name, "sym_addr")) > - gopt_sym_addr = set; > - else if (!strcmp(flag_name, "graph_print_duration")) > - gopt_graph_print_duration = set; > - else if (!strcmp(flag_name, "graph_print_overhead")) > - gopt_graph_print_overhead = set; > - else if (!strcmp(flag_name, "graph_print_abstime")) > - gopt_graph_print_abstime = set; > - else if (!strcmp(flag_name, "graph_print_cpu")) > - gopt_graph_print_cpu = set; > - else if (!strcmp(flag_name, "graph_print_proc")) > - gopt_graph_print_proc = set; > - else if (!strcmp(flag_name, "graph_print_overrun")) > - gopt_graph_print_overrun = set; > - /* invalid flage_name is omitted. */ > -} > - > -static int tracer_no_event_context; > - > -static void ftrace_show_function_graph_init(void); > -static void ftrace_show_function_init(void); > -static void ftrace_show_trace_event_init(void); > - > -static int ftrace_show_init(void) > -{ > - /* ftrace_event_get_id(), ftrace_event_get_pid() should not failed. > */ > - if (find_event_field(event_types[0], "common_type") == NULL) > - return -1; > - > - if (find_event_field(event_types[0], "common_pid") == NULL) > - return -1; > - > - ftrace_show_function_init(); > - ftrace_show_function_graph_init(); > - ftrace_show_trace_event_init(); > - > - return 0; > -} > - > -void show_event(struct format_context *fc) > -{ > - struct event_type *etype; > - int id; > - > - id = ftrace_event_get_id(fc->event.data); > - etype = find_event_type(id); > - > - if (etype == NULL) { > - event_printf("<Unknown event type> "); > - return; > - } > - > - if (!tracer_no_event_context && gopt_context_info) > - event_context_print(etype, fc); > - if (!etype->plugin) > - event_printf("%s: ", etype->name); > - etype->printer(etype, fc); > -} > - > -static int parse_cpulist(int *cpulist, const char *cpulist_str, int > len) > -{ > - unsigned a, b; > - const char *s = cpulist_str; > - > - memset(cpulist, 0, sizeof(int) * len); > - > - do { > - if (!isdigit(*s)) > - return -1; > - b = a = strtoul(s, (char **)&s, 10); > - if (*s == '-') { > - s++; > - if (!isdigit(*s)) > - return -1; > - b = strtoul(s, (char **)&s, 10); > - } > - if (!(a <= b)) > - return -1; > - if (b >= len) > - return -1; > - while (a <= b) { > - cpulist[a] = 1; > - a++; > - } > - if (*s == ',') > - s++; > - } while (*s != ' ' && *s != ' '); > - > - return 0; > -} > - > -static void ftrace_show_function_graph_start(void); > - > -static void ftrace_show(int argc, char *argv[]) > -{ > - int c; > - int *cpulist = NULL; > - > - set_all_flags_default(); > - ftrace_show_function_graph_start(); > - > - while ((c = getopt(argc, argv, "f:c:")) != EOF) { > - switch(c) > - { > - case 'f': > - if (optarg[0] == 'n' && optarg[1] == 'o') > - set_clear_flag(optarg + 2, 0); > - else > - set_clear_flag(optarg, 1); > - break; > - case 'c': > - if (cpulist) > - goto err_arg; > - > - cpulist = malloc(sizeof(int) * nr_cpu_ids); > - if (cpulist == NULL) { > - error(INFO, "malloc() fail "); > - return; > - } > - > - if (parse_cpulist(cpulist, optarg, nr_cpu_ids) < 0) > - goto err_arg; > - break; > - default: > - goto err_arg; > - } > - } > - > - if (argc - optind != 0) { > -err_arg: > - cmd_usage(pc->curcmd, SYNOPSIS); > - free(cpulist); > - return; > - } > - > - ring_buffer_stream_init(&format_context.stream, cpulist); > - > - /* Ignore setjmp()'s return value, no special things to do. */ > - setjmp(show_event_env); > - > - for (;;) { > - show_event_pos = 0; > - format_context.cpu = ring_buffer_stream_pop_event( > - &format_context.stream, &format_context.event); > - if (format_context.cpu < 0) > - break; > - > - show_event(&format_context); > - fprintf(fp, "%s", show_event_buf); > - } > - > - ring_buffer_stream_destroy(&format_context.stream, cpulist); > - free(cpulist); > -} > - > -static void cmd_ftrace(void) > +static void cmd_ftrace(void) > { > if (argcnt == 1) > show_basic_info(); > @@ -2216,729 +1478,12 @@ static void cmd_ftrace(void) > ftrace_dump(argcnt - 1, args + 1); > else if (!strcmp(args[1], "show")) > ftrace_show(argcnt - 1, args + 1); > + else if (!strcmp(args[1], "report")) > + ftrace_show(argcnt - 1, args + 1); > else > cmd_usage(pc->curcmd, SYNOPSIS); > } > > -static void event_default_print(struct event_type *t, struct > format_context *fc) > -{ > - int i; > - > - /* Skip the common types */ > - for (i = t->nfields - 6; i >= 0; i--) { > - struct ftrace_field *f; > - > - f = &t->fields[i]; > - event_printf("%s=", f->name); > - event_field_print(f, fc->event.data); > - if (i) > - event_printf(", "); > - } > - > - event_printf(" "); > -} > - > -static void sym_print(ulong sym, int opt_offset) > -{ > - if (!sym) { > - event_printf("0"); > - } else { > - ulong offset; > - struct syment *se; > - > - se = value_search(sym, &offset); > - if (se) { > - event_printf("%s", se->name); > - if (opt_offset) > - event_printf("+%lu", offset); > - } > - } > -} > - > -static void event_fn_print(struct event_type *t, struct > format_context *fc) > -{ > - unsigned long ip = access_field(t, fc->event.data, "ip"); > - unsigned long parent_ip = access_field(t, fc->event.data, > "parent_ip"); > - > - sym_print(ip, gopt_sym_offset); > - if (gopt_sym_addr) > - event_printf("<%lx>", ip); > - > - event_printf(" <-"); > - > - sym_print(parent_ip, gopt_sym_offset); > - if (gopt_sym_addr) > - event_printf("<%lx>", parent_ip); > - > - event_printf(" "); > -} > - > -static void ftrace_show_function_init(void) > -{ > - struct event_type *t = find_event_type_by_name("ftrace", > "function"); > - > - if (t) > - t->printer = event_fn_print; > -} > - > -#if 0 > -/* simple */ > -static void event_fn_entry_print(struct event_type *t, struct > format_context *fc) > -{ > - ulong func = access_field(t, fc->event.data, "graph_ent.func"); > - int depth = access_field(t, fc->event.data, "graph_ent.depth"); > - > - event_printf("%*s", depth, " "); > - sym_print(func, gopt_sym_offset); > - if (gopt_sym_addr) > - event_printf("<%lx>", func); > - event_printf("() {"); > -} > - > -static void event_fn_return_print(struct event_type *t, struct > format_context *fc) > -{ > - ulong func = access_field(t, fc->event.data, "ret.func"); > - u64 calltime = access_field(t, fc->event.data, "ret.calltime"); > - u64 rettime = access_field(t, fc->event.data, "ret.rettime"); > - int depth = access_field(t, fc->event.data, "ret.depth"); > - > - event_printf("%*s} %lluns", depth, " ", > - (unsigned long long)(rettime - calltime)); > -} > - > -static void ftrace_show_function_graph_init(void) > -{ > - struct event_type *t1 = find_event_type_by_name( > - "ftrace", "funcgraph_entry"); > - struct event_type *t2 = find_event_type_by_name( > - "ftrace", "funcgraph_exit"); > - > - if (t1 == NULL || t2 == NULL) > - return; > - > - t1->printer = event_fn_entry_print; > - t2->printer = event_fn_return_print; > -} > -#endif > - > - > -#define TRACE_GRAPH_PROCINFO_LENGTH 14 > -#define TRACE_GRAPH_INDENT 2 > - > -static int max_bytes_for_cpu; > -static int *cpus_prev_pid; > - > -static int function_graph_entry_id; > -static int function_graph_return_id; > -static struct event_type *function_graph_entry_type; > -static struct event_type *function_graph_return_type; > - > -static void ftrace_show_function_graph_start(void) > -{ > - int i; > - > - if (cpus_prev_pid == NULL) > - return; > - > - for (i = 0; i < nr_cpu_ids; i++) > - cpus_prev_pid[i] = -1; > -} > - > -static void fn_graph_proc_print(int pid) > -{ > - int pid_strlen, comm_strlen; > - char pid_str[20]; > - char comm[20] = "<...>"; > - > - pid_strlen = sprintf(pid_str, "%d", pid); > - comm_strlen = TRACE_GRAPH_PROCINFO_LENGTH - 1 - pid_strlen; > - > - get_comm_from_pid(pid, comm); > - event_printf("%*.*s-%s", comm_strlen, comm_strlen, comm, pid_str); > -} > - > -/* If the pid changed since the last trace, output this event */ > -static void fn_graph_proc_switch_print(int pid, int cpu) > -{ > - int prev_pid = cpus_prev_pid[cpu]; > - > - cpus_prev_pid[cpu] = pid; > - if ((prev_pid == pid) || (prev_pid == -1)) > - return; > - > -/* > - * Context-switch trace line: > - > - ------------------------------------------ > - | 1) migration/0--1 => sshd-1755 > - ------------------------------------------ > - > - */ > - > - event_printf(" ------------------------------------------ "); > - event_printf(" %*d) ", max_bytes_for_cpu, cpu); > - fn_graph_proc_print(prev_pid); > - event_printf(" => "); > - fn_graph_proc_print(pid); > - event_printf(" ------------------------------------------ "); > -} > - > -/* Signal a overhead of time execution to the output */ > -static void fn_graph_overhead_print(unsigned long long duration) > -{ > - const char *s = " "; > - > - /* If duration disappear, we don't need anything */ > - if (!gopt_graph_print_duration) > - return; > - > - /* duration == -1 is for non nested entry or return */ > - if ((duration != -1) && gopt_graph_print_overhead) { > - /* Duration exceeded 100 msecs */ > - if (duration > 100000ULL) > - s = "! "; > - /* Duration exceeded 10 msecs */ > - else if (duration > 10000ULL) > - s = "+ "; > - } > - > - event_printf(s); > -} > - > -static void fn_graph_abstime_print(u64 ts) > -{ > - u64 time = ts / 1000; > - unsigned long sec = time / 1000000; > - unsigned long usec = time % 1000000; > - > - event_printf("%5lu.%06lu | ", sec, usec); > -} > - > -static void fn_graph_irq_print(int type) > -{ > - /* TODO: implement it. */ > -} > - > -static void fn_graph_duration_print(unsigned long long duration) > -{ > - /* log10(ULONG_MAX) + ' ' */ > - char msecs_str[21]; > - char nsecs_str[5]; > - int len; > - unsigned long nsecs_rem = duration % 1000; > - > - duration = duration / 1000; > - len = sprintf(msecs_str, "%lu", (unsigned long) duration); > - > - /* Print msecs */ > - event_printf("%s", msecs_str); > - > - /* Print nsecs (we don't want to exceed 7 numbers) */ > - if (len < 7) { > - snprintf(nsecs_str, 8 - len, "%03lu", nsecs_rem); > - event_printf(".%s", nsecs_str); > - > - len += strlen(nsecs_str); > - } > - > - if (len > 7) > - len = 7; > - > - event_printf(" us %*s| ", 7 - len, ""); > -} > - > -/* Case of a leaf function on its call entry */ > -static void fn_graph_entry_leaf_print(void *entry_data, void > *exit_data) > -{ > - struct event_type *t = function_graph_return_type; > - > - u64 calltime = access_field(t, exit_data, "ret.calltime"); > - u64 rettime = access_field(t, exit_data, "ret.rettime"); > - u64 duration = rettime - calltime; > - int depth = access_field(t, exit_data, "ret.depth"); > - ulong func = access_field(t, exit_data, "ret.func"); > - > - fn_graph_overhead_print(duration); > - if (gopt_graph_print_duration) > - fn_graph_duration_print(duration); > - > - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); > - sym_print(func, 0); > - event_printf("(); "); > -} > - > -static void fn_graph_entry_nested_print(struct event_type *t, void > *data) > -{ > - int depth = access_field(t, data, "graph_ent.depth"); > - ulong func = access_field(t, data, "graph_ent.func"); > - > - fn_graph_overhead_print(-1); > - > - /* No time */ > - if (gopt_graph_print_duration) > - event_printf(" | "); > - > - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); > - sym_print(func, 0); > - event_printf("() { "); > -} > - > -static void fn_graph_prologue_print(int cpu, u64 ts, int pid, int > type) > -{ > - fn_graph_proc_switch_print(pid, cpu); > - > - if (type) > - fn_graph_irq_print(type); > - > - if (gopt_graph_print_abstime) > - fn_graph_abstime_print(ts); > - > - if (gopt_graph_print_cpu) > - event_printf(" %*d) ", max_bytes_for_cpu, cpu); > - > - if (gopt_graph_print_proc) { > - fn_graph_proc_print(pid); > - event_printf(" | "); > - } > -} > - > -static void *get_return_for_leaf(struct event_type *t, > - struct format_context *fc, void *curr_data) > -{ > - int cpu; > - struct ftrace_event next; > - ulong entry_func, exit_func; > - > - cpu = ring_buffer_stream_pop_event(&fc->stream, &next); > - > - if (cpu < 0) > - goto not_leaf; > - > - if (ftrace_event_get_id(next.data) != function_graph_return_id) > - goto not_leaf; > - > - if (ftrace_event_get_pid(curr_data) != > ftrace_event_get_pid(next.data)) > - goto not_leaf; > - > - entry_func = access_field(t, curr_data, "graph_ent.func"); > - exit_func = access_field(function_graph_return_type, next.data, > - "ret.func"); > - > - if (entry_func != exit_func) > - goto not_leaf; > - > - return next.data; > - > -not_leaf: > - ring_buffer_stream_push_current_event(&fc->stream); > - return NULL; > -} > - > -static > -void event_fn_entry_print(struct event_type *t, struct format_context > *fc) > -{ > - void *leaf_ret_data = NULL, *curr_data = fc->event.data, *data; > - int pid = ftrace_event_get_pid(curr_data); > - > - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 1); > - > - data = alloca(fc->event.length); > - if (data) { > - memcpy(data, fc->event.data, fc->event.length); > - curr_data = data; > - leaf_ret_data = get_return_for_leaf(t, fc, curr_data); > - } > - > - if (leaf_ret_data) > - return fn_graph_entry_leaf_print(curr_data, leaf_ret_data); > - else > - return fn_graph_entry_nested_print(t, curr_data); > -} > - > -static > -void event_fn_return_print(struct event_type *t, struct > format_context *fc) > -{ > - void *data = fc->event.data; > - int pid = ftrace_event_get_pid(data); > - > - u64 calltime = access_field(t, data, "ret.calltime"); > - u64 rettime = access_field(t, data, "ret.rettime"); > - u64 duration = rettime - calltime; > - int depth = access_field(t, data, "ret.depth"); > - > - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 0); > - fn_graph_overhead_print(duration); > - > - if (gopt_graph_print_duration) > - fn_graph_duration_print(duration); > - > - event_printf("%*s} ", depth * TRACE_GRAPH_INDENT, ""); > - > - if (gopt_graph_print_overrun) { > - unsigned long overrun = access_field(t, data, "ret.overrun"); > - event_printf(" (Overruns: %lu) ", overrun); > - } > - > - fn_graph_irq_print(0); > -} > - > -static void ftrace_show_function_graph_init(void) > -{ > - if (strcmp(current_tracer_name, "function_graph")) > - return; > - > - function_graph_entry_type = find_event_type_by_name( > - "ftrace", "funcgraph_entry"); > - function_graph_return_type = find_event_type_by_name( > - "ftrace", "funcgraph_exit"); > - > - if (!function_graph_entry_type || !function_graph_return_type) > - return; > - > - /* > - * Because of get_return_for_leaf(), the exception handling > - * of access_field() is not work for function_graph. So we need > - * to ensure access_field() will not failed for these fields. > - * > - * I know these will not failed. I just ensure it. > - */ > - > - if (!find_event_field(function_graph_entry_type, "graph_ent.func")) > - return; > - > - if (!find_event_field(function_graph_entry_type, "graph_ent.depth")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.func")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.calltime")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.rettime")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.overrun")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.depth")) > - return; > - > - cpus_prev_pid = malloc(sizeof(int) * nr_cpu_ids); > - if (!cpus_prev_pid) > - return; > - > - max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1); > - > - function_graph_entry_id = function_graph_entry_type->id; > - function_graph_return_id = function_graph_return_type->id; > - > - /* OK, set the printer for function_graph. */ > - tracer_no_event_context = 1; > - function_graph_entry_type->printer = event_fn_entry_print; > - function_graph_return_type->printer = event_fn_return_print; > -} > - > -static void event_sched_kthread_stop_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid")); > -} > - > -static void event_sched_kthread_stop_ret_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("ret %d ", (int)access_field(t, fc->event.data, > "ret")); > -} > - > -static void event_sched_wait_task_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_wakeup_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] success=%d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio"), > - (int)access_field(t, fc->event.data, "success")); > -} > - > -static void event_sched_wakeup_new_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] success=%d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio"), > - (int)access_field(t, fc->event.data, "success")); > -} > - > -static void event_sched_switch_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *prev_comm = (char *)(long)access_field(t, fc->event.data, > - "prev_comm"); > - int prev_pid = access_field(t, fc->event.data, "prev_pid"); > - int prev_prio = access_field(t, fc->event.data, "prev_prio"); > - > - int prev_state = access_field(t, fc->event.data, "prev_state"); > - > - char *next_comm = (char *)(long)access_field(t, fc->event.data, > - "next_comm"); > - int next_pid = access_field(t, fc->event.data, "next_pid"); > - int next_prio = access_field(t, fc->event.data, "next_prio"); > - > - event_printf("task %s:%d [%d] (", prev_comm, prev_pid, prev_prio); > - > - if (prev_state == 0) { > - event_printf("R"); > - } else { > - if (prev_state & 1) > - event_printf("S"); > - if (prev_state & 2) > - event_printf("D"); > - if (prev_state & 4) > - event_printf("T"); > - if (prev_state & 8) > - event_printf("t"); > - if (prev_state & 16) > - event_printf("Z"); > - if (prev_state & 32) > - event_printf("X"); > - if (prev_state & 64) > - event_printf("x"); > - if (prev_state & 128) > - event_printf("W"); > - } > - > - event_printf(") ==> %s:%d [%d] ", next_comm, next_pid, next_prio); > -} > - > -static void event_sched_migrate_task_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] from: %d to: %d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio"), > - (int)access_field(t, fc->event.data, "orig_cpu"), > - (int)access_field(t, fc->event.data, "dest_cpu")); > -} > - > -static void event_sched_process_free_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_process_exit_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_process_wait_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_process_fork_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *parent_comm = (char *)(long)access_field(t, fc->event.data, > - "parent_comm"); > - int parent_pid = access_field(t, fc->event.data, "parent_pid"); > - > - char *child_comm = (char *)(long)access_field(t, fc->event.data, > - "child_comm"); > - int child_pid = access_field(t, fc->event.data, "child_pid"); > - > - event_printf("parent %s:%d child %s:%d ", parent_comm, parent_pid, > - child_comm, child_pid); > -} > - > -static void event_sched_signal_send_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("sig: %d task %s:%d ", > - (int)access_field(t, fc->event.data, "sig"), > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid")); > -} > - > -static void event_kmalloc_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags")); > -} > - > -static void event_kmem_cache_alloc_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags")); > -} > - > -static void event_kmalloc_node_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx node=%d ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags"), > - (int)access_field(t, fc->event.data, "node")); > -} > - > -static void event_kmem_cache_alloc_node_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx node=%d ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags"), > - (int)access_field(t, fc->event.data, "node")); > -} > - > -static void event_kfree_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr")); > -} > - > -static void event_kmem_cache_free_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr")); > -} > - > -static void event_workqueue_insertion_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - ulong func = access_field(t, fc->event.data, "func"); > - > - event_printf("thread=%s:%d func=", thread_comm, thread_pid); > - sym_print(func, 1); > - event_printf(" "); > -} > - > -static void event_workqueue_execution_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - ulong func = access_field(t, fc->event.data, "func"); > - > - event_printf("thread=%s:%d func=", thread_comm, thread_pid); > - sym_print(func, 1); > - event_printf(" "); > -} > - > -static void event_workqueue_creation_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - int cpu = access_field(t, fc->event.data, "cpu"); > - > - event_printf("thread=%s:%d cpu=%d ", thread_comm, thread_pid, cpu); > -} > - > -static void event_workqueue_destruction_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - > - event_printf("thread=%s:%d ", thread_comm, thread_pid); > -} > - > -static void ftrace_show_trace_event_init(void) > -{ > -#define init_trace_event(system, name) > -do { > - struct event_type *t = find_event_type_by_name(#system, #name); > - if (t) > - t->printer = event_ ## name ## _print; > -} while (0) > - > - init_trace_event(sched, sched_kthread_stop); > - init_trace_event(sched, sched_kthread_stop_ret); > - init_trace_event(sched, sched_wait_task); > - init_trace_event(sched, sched_wakeup); > - init_trace_event(sched, sched_wakeup_new); > - init_trace_event(sched, sched_switch); > - init_trace_event(sched, sched_migrate_task); > - init_trace_event(sched, sched_process_free); > - init_trace_event(sched, sched_process_exit); > - init_trace_event(sched, sched_process_wait); > - init_trace_event(sched, sched_process_fork); > - init_trace_event(sched, sched_signal_send); > - > - init_trace_event(kmem, kmalloc); > - init_trace_event(kmem, kmem_cache_alloc); > - init_trace_event(kmem, kmalloc_node); > - init_trace_event(kmem, kmem_cache_alloc_node); > - init_trace_event(kmem, kfree); > - init_trace_event(kmem, kmem_cache_free); > - > - init_trace_event(workqueue, workqueue_insertion); > - init_trace_event(workqueue, workqueue_execution); > - init_trace_event(workqueue, workqueue_creation); > - init_trace_event(workqueue, workqueue_destruction); > -#undef init_trace_event > -} > - > -static void ftrace_show_destroy(void) > -{ > - free(cpus_prev_pid); > -} > - > static char *help_ftrace[] = { > "trace", > "show or dump the tracing info", > @@ -2946,22 +1491,11 @@ static char *help_ftrace[] = { > "trace", > " shows the current tracer and other informations.", > "", > -"trace show [ -c <cpulist> ] [ -f [no]<flagename> ]", > +"trace show", > " shows all events with readability text(sorted by timestamp)", > -" -c: only shows specified CPUs' events.", > -" ex. trace show -c 1,2 - only shows cpu#1 and cpu#2 's events.", > -" trace show -c 0,2-7 - only shows cpu#0, cpu#2...cpu#7's events.", > -" -f: set or clear a flag", > -" available flags default", > -" context_info true", > -" sym_offset false", > -" sym_addr false", > -" graph_print_duration true", > -" graph_print_overhead true", > -" graph_print_abstime false", > -" graph_print_cpu true", > -" graph_print_proc false", > -" graph_print_overrun false", > +"", > +"trace report", > +" the same as "trace show"", > "", > "trace dump [-sm] <dest-dir>", > " dump ring_buffers to dest-dir. Then you can parse it", -- Crash-utility mailing list Crash-utility@redhat.com https://www.redhat.com/mailman/listinfo/crash-utility |
trace: Improve "trace show" command
On 03/03/2011 11:25 PM, Dave Anderson wrote:
> > > ----- Original Message ----- >> The code were also applied to: >> git://github.com/laijs/tracing-extension-module-for-crash.git >> >> Documents and man pages will/may be added in two weeks. >> >> Dave Anderson, could you add a "Requires" entry to its RPM.spec, >> it requires trace-cmd RPM after this patch applied. Sorry, please omit this requirement of mine. > > Sorry, but no, I cannot do that. > > There are two versions of the trace.c extension module that > I am aware of: > > (1) The extensions/trace.c file that is included as part of > each upstream crash utility release. That version is the > one that you updated in crash-5.1.2 to add support for > kernel versions beyond 2.6.32. > > - Update of the "extensions/trace.c" extension module. Initially > designed to support 2.6.32 (RHEL6), it has been updated to support > kernels up to 2.6.38-rc1. > (laijs@cn.fujitsu.com) > This patch is for upstream crash utility release, but I just coded it based my git tree, I forgot to check the different between crash-5.1.3 in which you have beautified the trace.c a little with several lines. The following is the updated patch. Subject: [PATCH] trace: Improve "trace show" command Use trace-cmd to implement "trace show" command and remove the related code. It is not a good idea to maintain another set of code with the same functional. trace-cmd is better and mature. How the new "trace show" works: 1) build trace.dat from the core file and dump it to /tmp. 2) exec "trace-cmd report" upon the trace.dat 3) splice the output of trace-cmd to user and unlink the temp file. Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com> --- trace.c | 1565 ++-------------------------------------------------------------- 1 file changed, 49 insertions(+), 1516 deletions(-) diff --git b/extensions/trace.c a/extensions/trace.c index 1cfc50f..057459b 100755 --- b/extensions/trace.c +++ a/extensions/trace.c @@ -96,8 +96,6 @@ static const char *current_tracer_name; static void ftrace_destroy_event_types(void); static int ftrace_init_event_types(void); -static int ftrace_show_init(void); -static void ftrace_show_destroy(void); /* at = ((struct *)ptr)->member */ #define read_value(at, ptr, struct, member) @@ -489,13 +487,8 @@ static int ftrace_init(void) if (ftrace_init_current_tracer() < 0) goto out_2; - if (ftrace_show_init() < 0) - goto out_3; - return 0; -out_3: - free(current_tracer_name); out_2: ftrace_destroy_event_types(); out_1: @@ -511,7 +504,6 @@ out_0: static void ftrace_destroy(void) { - ftrace_show_destroy(); free(current_tracer_name); ftrace_destroy_event_types(); @@ -611,37 +603,21 @@ out_fail: return -1; } -typedef uint64_t u64; -typedef int64_t s64; -typedef uint32_t u32; - #define MAX_CACHE_ID 256 -struct ftrace_field; -typedef u64 (*access_op)(struct ftrace_field *aop, void *data); -static void ftrace_field_access_init(struct ftrace_field *f); - struct ftrace_field { const char *name; const char *type; - access_op op; int offset; int size; int is_signed; }; -struct event_type; -struct format_context; -typedef void (*event_printer)(struct event_type *t, struct format_context *fc); - - /* SIGH, we cann't get "print fmt" from core-file */ - struct event_type { struct event_type *next; const char *system; const char *name; int plugin; - event_printer printer; const char *print_fmt; int id; int nfields; @@ -655,17 +631,6 @@ static int nr_event_types; static struct ftrace_field *ftrace_common_fields; static int ftrace_common_fields_count; -/* - * TODO: implement event_generic_print_fmt_print() when the print fmt - * in tracing/events/$SYSTEM/$TRACE/format becomes a will-defined - * language. - * - * static void event_generic_print_fmt_print(struct event_type *t, - * struct format_context *fc); - */ -static void event_default_print(struct event_type *t, - struct format_context *fc); - static int syscall_get_enter_fields(ulong call, ulong *fields) { static int inited; @@ -888,7 +853,6 @@ static int ftrace_init_event_fields(ulong fields_head, int *pnfields, goto out_fail; } - ftrace_field_access_init(&fields[nfields]); nfields++; /* Advance to the next field */ @@ -1187,7 +1151,6 @@ static int ftrace_init_event_types(void) aevent_type->plugin = 1; else aevent_type->plugin = 0; - aevent_type->printer = event_default_print; /* Add a event type */ event_types[nr_event_types++] = aevent_type; @@ -1213,57 +1176,6 @@ out_fail: return -1; } -static -struct ftrace_field *find_event_field(struct event_type *t, const char *name) -{ - int i; - struct ftrace_field *f; - - for (i = 0; i < ftrace_common_fields_count; i++) { - f = ftrace_common_fields + i; - if (!strcmp(name, f->name)) - return f; - } - - for (i = 0; i < t->nfields; i++) { - f = &t->fields[i]; - if (!strcmp(name, f->name)) - return f; - } - - return NULL; -} - -static struct event_type *find_event_type(int id) -{ - int i; - - if ((unsigned int)id < MAX_CACHE_ID) - return event_type_cache[id]; - - for (i = 0; i < nr_event_types; i++) { - if (event_types[i]->id == id) - return event_types[i]; - } - - return NULL; -} - -static -struct event_type *find_event_type_by_name(const char *system, const char *name) -{ - int i; - - for (i = 0; i < nr_event_types; i++) { - if (system && strcmp(system, event_types[i]->system)) - continue; - if (!strcmp(name, event_types[i]->name)) - return event_types[i]; - } - - return NULL; -} - #define default_common_field_count 5 static int ftrace_dump_event_type(struct event_type *t, const char *path) @@ -1365,381 +1277,6 @@ static int ftrace_dump_event_types(const char *events_path) return 0; } -struct ring_buffer_per_cpu_stream { - struct ring_buffer_per_cpu *cpu_buffer; - void *curr_page; - int curr_page_indx; - - uint64_t ts; - uint32_t *offset; - uint32_t *commit; -}; - -static -int ring_buffer_per_cpu_stream_init(struct ring_buffer_per_cpu *cpu_buffer, - unsigned pages, struct ring_buffer_per_cpu_stream *s) -{ - s->cpu_buffer = cpu_buffer; - s->curr_page = malloc(PAGESIZE()); - if (s->curr_page == NULL) - return -1; - - s->curr_page_indx = -1; - return 0; -} - -static -void ring_buffer_per_cpu_stream_destroy(struct ring_buffer_per_cpu_stream *s) -{ - free(s->curr_page); -} - -struct ftrace_event { - uint64_t ts; - int length; - void *data; -}; - -struct event { - u32 type_len:5, time_delta:27; -}; - -#define RINGBUF_TYPE_PADDING 29 -#define RINGBUF_TYPE_TIME_EXTEND 30 -#define RINGBUF_TYPE_TIME_STAMP 31 -#define RINGBUF_TYPE_DATA 0 ... 28 - -#define sizeof_local_t (sizeof(ulong)) -#define PAGE_HEADER_LEN (8 + sizeof_local_t) - -static -int ring_buffer_per_cpu_stream_get_page(struct ring_buffer_per_cpu_stream *s) -{ - ulong raw_page; - - read_value(raw_page, s->cpu_buffer->linear_pages[s->curr_page_indx], - buffer_page, page); - - if (!readmem(raw_page, KVADDR, s->curr_page, PAGESIZE(), - "get page context", RETURN_ON_ERROR)) - return -1; - - s->ts = *(u64 *)s->curr_page; - s->offset = s->curr_page + PAGE_HEADER_LEN; - s->commit = s->offset + *(ulong *)(s->curr_page + 8) / 4; - - return 0; - -out_fail: - return -1; -} - -static -int ring_buffer_per_cpu_stream_pop_event(struct ring_buffer_per_cpu_stream *s, - struct ftrace_event *res) -{ - struct event *event; - - res->data = NULL; - - if (s->curr_page_indx >= s->cpu_buffer->nr_linear_pages) - return -1; - -again: - if ((s->curr_page_indx == -1) || (s->offset >= s->commit)) { - s->curr_page_indx++; - - if (s->curr_page_indx == s->cpu_buffer->nr_linear_pages) - return -1; - - if (ring_buffer_per_cpu_stream_get_page(s) < 0) { - s->curr_page_indx = s->cpu_buffer->nr_linear_pages; - return -1; - } - - if (s->offset >= s->commit) - goto again; - } - - event = (void *)s->offset; - - switch (event->type_len) { - case RINGBUF_TYPE_PADDING: - if (event->time_delta) - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); - else - s->offset = s->commit; - goto again; - - case RINGBUF_TYPE_TIME_EXTEND: - s->ts +=event->time_delta; - s->ts += ((u64)*(s->offset + 1)) << 27; - s->offset += 2; - goto again; - - case RINGBUF_TYPE_TIME_STAMP: - /* FIXME: not implemented */ - s->offset += 4; - goto again; - - case RINGBUF_TYPE_DATA: - if (!event->type_len) { - res->data = s->offset + 2; - res->length = *(s->offset + 1) - 4; - - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); - } else { - res->data = s->offset + 1; - res->length = event->type_len * 4; - - s->offset += 1 + event->type_len; - } - - if (s->offset > s->commit) { - fprintf(fp, "corrupt "); - res->data = NULL; - goto again; - } - - s->ts += event->time_delta; - res->ts = s->ts; - - return 0; - - default:; - } - - return -1; -} - -struct ring_buffer_stream { - struct ring_buffer_per_cpu_stream *ss; - struct ftrace_event *es; - u64 ts; - int popped_cpu; - int pushed; -}; - -static void __rbs_destroy(struct ring_buffer_stream *s, int *cpulist, int nr) -{ - int cpu; - - for (cpu = 0; cpu < nr; cpu++) { - if (!s->ss[cpu].cpu_buffer) - continue; - - ring_buffer_per_cpu_stream_destroy(s->ss + cpu); - } - - free(s->ss); - free(s->es); -} - -static -int ring_buffer_stream_init(struct ring_buffer_stream *s, int *cpulist) -{ - int cpu; - - s->ss = malloc(sizeof(*s->ss) * nr_cpu_ids); - if (s->ss == NULL) - return -1; - - s->es = malloc(sizeof(*s->es) * nr_cpu_ids); - if (s->es == NULL) { - free(s->ss); - return -1; - } - - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { - s->ss[cpu].cpu_buffer = NULL; - s->es[cpu].data = NULL; - - if (!global_buffers[cpu].kaddr) - continue; - - if (cpulist && !cpulist[cpu]) - continue; - - if (ring_buffer_per_cpu_stream_init(global_buffers + cpu, - global_pages, s->ss + cpu) < 0) { - __rbs_destroy(s, cpulist, cpu); - return -1; - } - } - - s->ts = 0; - s->popped_cpu = nr_cpu_ids; - s->pushed = 0; - - return 0; -} - -static -void ring_buffer_stream_destroy(struct ring_buffer_stream *s, int *cpulist) -{ - __rbs_destroy(s, cpulist, nr_cpu_ids); -} - -/* make current event be returned again at next pop */ -static void ring_buffer_stream_push_current_event(struct ring_buffer_stream *s) -{ - if ((s->popped_cpu < 0) || (s->popped_cpu == nr_cpu_ids)) - return; - - s->pushed = 1; -} - -/* return the cpu# of this event */ -static int ring_buffer_stream_pop_event(struct ring_buffer_stream *s, - struct ftrace_event *res) -{ - int cpu, min_cpu = -1; - u64 ts, min_ts; - - res->data = NULL; - - if (s->popped_cpu < 0) - return -1; - - if (s->popped_cpu == nr_cpu_ids) { - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { - if (!s->ss[cpu].cpu_buffer) - continue; - - ring_buffer_per_cpu_stream_pop_event(s->ss + cpu, - s->es + cpu); - - if (s->es[cpu].data == NULL) - continue; - - /* - * We do not have start point of time, - * determine the min_ts with heuristic way. - */ - ts = s->es[cpu].ts; - if (min_cpu < 0 || (s64)(ts - min_ts) < 0) { - min_ts = ts; - min_cpu = cpu; - } - } - - s->pushed = 0; - goto done; - } - - if (s->pushed) { - s->pushed = 0; - *res = s->es[s->popped_cpu]; - return s->popped_cpu; - } - - ring_buffer_per_cpu_stream_pop_event(&s->ss[s->popped_cpu], - &s->es[s->popped_cpu]); - - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { - if (s->es[cpu].data == NULL) - continue; - - /* we have start point of time(s->ts) */ - ts = s->es[cpu].ts - s->ts; - if (min_cpu < 0 || ts < min_ts) { - min_ts = ts; - min_cpu = cpu; - } - } - -done: - s->popped_cpu = min_cpu; - - if (min_cpu < 0) - return -1; - - s->ts = s->es[min_cpu].ts; - *res = s->es[min_cpu]; - - return min_cpu; -} - -static u64 access_error(struct ftrace_field *f, void *data) -{ - return 0; -} - -static u64 access_8(struct ftrace_field *f, void *data) -{ - return *(int8_t *)(data + f->offset); -} - -static u64 access_16(struct ftrace_field *f, void *data) -{ - return *(int16_t *)(data + f->offset); -} - -static u64 access_32(struct ftrace_field *f, void *data) -{ - return *(int32_t *)(data + f->offset); -} - -static u64 access_64(struct ftrace_field *f, void *data) -{ - return *(int64_t *)(data + f->offset); -} - -static u64 access_string_local(struct ftrace_field *f, void *data) -{ - int offset; - - if (f->size == 2) - offset = *(int16_t *)(data + f->offset); - else - offset = *(int32_t *)(data + f->offset) & 0xFFFF; - - return (long)(data + offset); -} - -static u64 access_string(struct ftrace_field *f, void *data) -{ - return (long)(data + f->offset); -} - -static u64 access_other_local(struct ftrace_field *f, void *data) -{ - return access_string_local(f, data); -} - -static u64 access_other(struct ftrace_field *f, void *data) -{ - return (long)(data + f->offset); -} - -static void ftrace_field_access_init(struct ftrace_field *f) -{ - /* guess whether it is string array */ - if (!strncmp(f->type, "__data_loc", sizeof("__data_loc") - 1)) { - if (f->size != 2 && f->size != 4) { - /* kernel side may be changed, need fix here */ - f->op = access_error; - } else if (strstr(f->type, "char")) { - f->op = access_string_local; - } else { - f->op = access_other_local; - } - } else if (strchr(f->type, '[')) { - if (strstr(f->type, "char")) - f->op = access_string; - else - f->op = access_other; - } else { - switch (f->size) { - case 1: f->op = access_8; break; - case 2: f->op = access_16; break; - case 4: f->op = access_32; break; - case 8: f->op = access_64; break; - default: f->op = access_other; break; - } - } -} - static void show_basic_info(void) { fprintf(fp, "current tracer is %s ", current_tracer_name); @@ -1882,331 +1419,55 @@ static void ftrace_dump(int argc, char *argv[]) } } -static char show_event_buf[4096]; -static int show_event_pos; - -#define INVALID_ACCESS_FIELD 1 -static jmp_buf show_event_env; - -struct format_context { - struct ring_buffer_stream stream; - struct ftrace_event event; - int cpu; -}; - -static struct format_context format_context; - -/* !!!! @event_type and @field_name should be const for every call */ -#define access_field(event_type, data, field_name) -({ - static struct ftrace_field *__access_field##_field; - - if (__access_field##_field == NULL) { - __access_field##_field = find_event_field(event_type, - field_name); - } - - if (__access_field##_field == NULL) { - event_type->printer = event_default_print; - ring_buffer_stream_push_current_event(&format_cont ext.stream); - longjmp(show_event_env, INVALID_ACCESS_FIELD); - } - - __access_field##_field->op(__access_field##_field, data); -}) - -static int ftrace_event_get_id(void *data) -{ - return access_field(event_types[0], data, "common_type"); -} - -static int ftrace_event_get_pid(void *data) -{ - return access_field(event_types[0], data, "common_pid"); -} - -#define event_printf(fmt, args...) -do { - show_event_pos += snprintf(show_event_buf + show_event_pos, - sizeof(show_event_buf) - show_event_pos, - fmt, ##args); -} while (0) - - -static void event_field_print(struct ftrace_field *f, void *data) +static void ftrace_show(int argc, char *argv[]) { - u64 value = f->op(f, data); + char buf[4096]; + char tmp[] = "/tmp/crash.trace_dat.XXXXXX"; + char *trace_cmd = "trace-cmd", *env_trace_cmd = getenv("TRACE_CMD"); + int fd; + FILE *file; + size_t ret; - if (f->op == access_error) { - event_printf("<Error>"); - } else if (f->op == access_8) { - if (f->is_signed) - event_printf("%d", (int8_t)value); - else - event_printf("%u", (uint8_t)value); - } else if (f->op == access_16) { - if (f->is_signed) - event_printf("%d", (int16_t)value); - else - event_printf("%u", (uint16_t)value); - } else if (f->op == access_32) { - if (f->is_signed) - event_printf("%d", (int32_t)value); - else - event_printf("%u", (uint32_t)value); - } else if (f->op == access_64) { - if (f->is_signed) - event_printf("%lld", (long long)value); + /* check trace-cmd */ + if (env_trace_cmd) + trace_cmd = env_trace_cmd; + if (!(file = popen(trace_cmd, "r"))) + return; + ret = fread(buf, 1, sizeof(buf), file); + buf[4097] = 0; + if (!strstr(buf, "trace-cmd version")) { + if (env_trace_cmd) + fprintf(fp, "Invalid environment TRACE_CMD: %s ", + env_trace_cmd); else - event_printf("%llu", (unsigned long long)value); - } else if (f->op == access_string_local) { - int size = 0; + fprintf(fp, ""trace show" requires trace-cmd. " + "please set the environment TRACE_CMD " + "if you installed it a special path " + ); + return; + } - if (f->size == 4) - size = *(int32_t *)(data + f->offset) >> 16; + /* dump trace.dat to the temp file */ + mktemp(tmp); + fd = open(tmp, O_WRONLY | O_CREAT | O_TRUNC, 0644); + if (trace_cmd_data_output(fd) < 0) + goto out; - if (size) - event_printf("%.*s", size, (char *)(long)value); - else - event_printf("%s", (char *)(long)value); - } else if (f->op == access_string) { - event_printf("%.*s", f->size, (char *)(long)value); - } else if (f->op == access_other) { - /* TODO */ - } else if (f->op == access_other_local) { - /* TODO */ - } else { - /* TODO */ + /* splice the output of trace-cmd to user */ + snprintf(buf, sizeof(buf), "%s report %s", trace_cmd, tmp); + if (!(file = popen(buf, "r"))) + goto out; + for (;;) { + ret = fread(buf, 1, sizeof(buf), file); + if (ret == 0) + break; + fwrite(buf, 1, ret, fp); } -} - -static void get_comm_from_pid(int pid, char *comm) -{ - int li, hi; - struct task_context *tc; - - if (pid == 0) { - strcpy(comm, "<swapper>"); - return; - } - - tc = FIRST_CONTEXT(); - - li = 0; - hi = RUNNING_TASKS(); - while (li < hi) { - int mid = (li + hi) / 2; - - if (tc[mid].pid > pid) - hi = mid; - else if (tc[mid].pid < pid) - li = mid + 1; - else { - strcpy(comm, tc[mid].comm); - return; - } - } - - strcpy(comm, "<...>"); -} - -static void event_context_print(struct event_type *t, struct format_context *fc) -{ - u64 time = fc->event.ts / 1000; - ulong sec = time / 1000000; - ulong usec = time % 1000000; - int pid = ftrace_event_get_pid(fc->event.data); - char comm[20]; - - get_comm_from_pid(pid, comm); - event_printf("%16s-%-5d [%03d] %5lu.%06lu: ", - comm, pid, fc->cpu, sec, usec); -} - -static int gopt_context_info; -static int gopt_sym_offset; -static int gopt_sym_addr; - -static int gopt_graph_print_duration; -static int gopt_graph_print_overhead; -static int gopt_graph_print_abstime; -static int gopt_graph_print_cpu; -static int gopt_graph_print_proc; -static int gopt_graph_print_overrun; - -static void set_all_flags_default(void) -{ - gopt_context_info = 1; - gopt_sym_offset = 0; - gopt_sym_addr = 0; - - gopt_graph_print_duration = 1; - gopt_graph_print_overhead = 1; - gopt_graph_print_abstime = 0; - gopt_graph_print_cpu = 1; - gopt_graph_print_proc = 0; - gopt_graph_print_overrun = 0; -} - -static void set_clear_flag(const char *flag_name, int set) -{ - if (!strcmp(flag_name, "context_info")) - gopt_context_info = set; - else if (!strcmp(flag_name, "sym_offset")) - gopt_sym_offset = set; - else if (!strcmp(flag_name, "sym_addr")) - gopt_sym_addr = set; - else if (!strcmp(flag_name, "graph_print_duration")) - gopt_graph_print_duration = set; - else if (!strcmp(flag_name, "graph_print_overhead")) - gopt_graph_print_overhead = set; - else if (!strcmp(flag_name, "graph_print_abstime")) - gopt_graph_print_abstime = set; - else if (!strcmp(flag_name, "graph_print_cpu")) - gopt_graph_print_cpu = set; - else if (!strcmp(flag_name, "graph_print_proc")) - gopt_graph_print_proc = set; - else if (!strcmp(flag_name, "graph_print_overrun")) - gopt_graph_print_overrun = set; - /* invalid flage_name is omitted. */ -} - -static int tracer_no_event_context; - -static void ftrace_show_function_graph_init(void); -static void ftrace_show_function_init(void); -static void ftrace_show_trace_event_init(void); - -static int ftrace_show_init(void) -{ - /* ftrace_event_get_id(), ftrace_event_get_pid() should not failed. */ - if (find_event_field(event_types[0], "common_type") == NULL) - return -1; - - if (find_event_field(event_types[0], "common_pid") == NULL) - return -1; - - ftrace_show_function_init(); - ftrace_show_function_graph_init(); - ftrace_show_trace_event_init(); - - return 0; -} - -void show_event(struct format_context *fc) -{ - struct event_type *etype; - int id; - - id = ftrace_event_get_id(fc->event.data); - etype = find_event_type(id); - - if (etype == NULL) { - event_printf("<Unknown event type> "); - return; - } - - if (!tracer_no_event_context && gopt_context_info) - event_context_print(etype, fc); - if (!etype->plugin) - event_printf("%s: ", etype->name); - etype->printer(etype, fc); -} - -static int parse_cpulist(int *cpulist, const char *cpulist_str, int len) -{ - unsigned a, b; - const char *s = cpulist_str; - - memset(cpulist, 0, sizeof(int) * len); - - do { - if (!isdigit(*s)) - return -1; - b = a = strtoul(s, (char **)&s, 10); - if (*s == '-') { - s++; - if (!isdigit(*s)) - return -1; - b = strtoul(s, (char **)&s, 10); - } - if (!(a <= b)) - return -1; - if (b >= len) - return -1; - while (a <= b) { - cpulist[a] = 1; - a++; - } - if (*s == ',') - s++; - } while (*s != ' ' && *s != ' '); - - return 0; -} - -static void ftrace_show_function_graph_start(void); - -static void ftrace_show(int argc, char *argv[]) -{ - int c; - int *cpulist = NULL; - - set_all_flags_default(); - ftrace_show_function_graph_start(); - - while ((c = getopt(argc, argv, "f:c:")) != EOF) { - switch(c) - { - case 'f': - if (optarg[0] == 'n' && optarg[1] == 'o') - set_clear_flag(optarg + 2, 0); - else - set_clear_flag(optarg, 1); - break; - case 'c': - if (cpulist) - goto err_arg; - - cpulist = malloc(sizeof(int) * nr_cpu_ids); - if (cpulist == NULL) { - error(INFO, "malloc() fail "); - return; - } - - if (parse_cpulist(cpulist, optarg, nr_cpu_ids) < 0) - goto err_arg; - break; - default: - goto err_arg; - } - } - - if (argc - optind != 0) { -err_arg: - cmd_usage(pc->curcmd, SYNOPSIS); - free(cpulist); - return; - } - - ring_buffer_stream_init(&format_context.stream, cpulist); - - /* Ignore setjmp()'s return value, no special things to do. */ - setjmp(show_event_env); - - for (;;) { - show_event_pos = 0; - format_context.cpu = ring_buffer_stream_pop_event( - &format_context.stream, &format_context.event); - if (format_context.cpu < 0) - break; - - show_event(&format_context); - fprintf(fp, "%s", show_event_buf); - } - - ring_buffer_stream_destroy(&format_context.stream, cpulist); - free(cpulist); + pclose(file); +out: + close(fd); + unlink(tmp); + return; } static void cmd_ftrace(void) @@ -2217,729 +1478,12 @@ static void cmd_ftrace(void) ftrace_dump(argcnt - 1, args + 1); else if (!strcmp(args[1], "show")) ftrace_show(argcnt - 1, args + 1); + else if (!strcmp(args[1], "report")) + ftrace_show(argcnt - 1, args + 1); else cmd_usage(pc->curcmd, SYNOPSIS); } -static void event_default_print(struct event_type *t, struct format_context *fc) -{ - int i; - - /* Skip the common types */ - for (i = t->nfields - 6; i >= 0; i--) { - struct ftrace_field *f; - - f = &t->fields[i]; - event_printf("%s=", f->name); - event_field_print(f, fc->event.data); - if (i) - event_printf(", "); - } - - event_printf(" "); -} - -static void sym_print(ulong sym, int opt_offset) -{ - if (!sym) { - event_printf("0"); - } else { - ulong offset; - struct syment *se; - - se = value_search(sym, &offset); - if (se) { - event_printf("%s", se->name); - if (opt_offset) - event_printf("+%lu", offset); - } - } -} - -static void event_fn_print(struct event_type *t, struct format_context *fc) -{ - unsigned long ip = access_field(t, fc->event.data, "ip"); - unsigned long parent_ip = access_field(t, fc->event.data, "parent_ip"); - - sym_print(ip, gopt_sym_offset); - if (gopt_sym_addr) - event_printf("<%lx>", ip); - - event_printf(" <-"); - - sym_print(parent_ip, gopt_sym_offset); - if (gopt_sym_addr) - event_printf("<%lx>", parent_ip); - - event_printf(" "); -} - -static void ftrace_show_function_init(void) -{ - struct event_type *t = find_event_type_by_name("ftrace", "function"); - - if (t) - t->printer = event_fn_print; -} - -#if 0 -/* simple */ -static void event_fn_entry_print(struct event_type *t, struct format_context *fc) -{ - ulong func = access_field(t, fc->event.data, "graph_ent.func"); - int depth = access_field(t, fc->event.data, "graph_ent.depth"); - - event_printf("%*s", depth, " "); - sym_print(func, gopt_sym_offset); - if (gopt_sym_addr) - event_printf("<%lx>", func); - event_printf("() {"); -} - -static void event_fn_return_print(struct event_type *t, struct format_context *fc) -{ - ulong func = access_field(t, fc->event.data, "ret.func"); - u64 calltime = access_field(t, fc->event.data, "ret.calltime"); - u64 rettime = access_field(t, fc->event.data, "ret.rettime"); - int depth = access_field(t, fc->event.data, "ret.depth"); - - event_printf("%*s} %lluns", depth, " ", - (unsigned long long)(rettime - calltime)); -} - -static void ftrace_show_function_graph_init(void) -{ - struct event_type *t1 = find_event_type_by_name( - "ftrace", "funcgraph_entry"); - struct event_type *t2 = find_event_type_by_name( - "ftrace", "funcgraph_exit"); - - if (t1 == NULL || t2 == NULL) - return; - - t1->printer = event_fn_entry_print; - t2->printer = event_fn_return_print; -} -#endif - - -#define TRACE_GRAPH_PROCINFO_LENGTH 14 -#define TRACE_GRAPH_INDENT 2 - -static int max_bytes_for_cpu; -static int *cpus_prev_pid; - -static int function_graph_entry_id; -static int function_graph_return_id; -static struct event_type *function_graph_entry_type; -static struct event_type *function_graph_return_type; - -static void ftrace_show_function_graph_start(void) -{ - int i; - - if (cpus_prev_pid == NULL) - return; - - for (i = 0; i < nr_cpu_ids; i++) - cpus_prev_pid[i] = -1; -} - -static void fn_graph_proc_print(int pid) -{ - int pid_strlen, comm_strlen; - char pid_str[20]; - char comm[20] = "<...>"; - - pid_strlen = sprintf(pid_str, "%d", pid); - comm_strlen = TRACE_GRAPH_PROCINFO_LENGTH - 1 - pid_strlen; - - get_comm_from_pid(pid, comm); - event_printf("%*.*s-%s", comm_strlen, comm_strlen, comm, pid_str); -} - -/* If the pid changed since the last trace, output this event */ -static void fn_graph_proc_switch_print(int pid, int cpu) -{ - int prev_pid = cpus_prev_pid[cpu]; - - cpus_prev_pid[cpu] = pid; - if ((prev_pid == pid) || (prev_pid == -1)) - return; - -/* - * Context-switch trace line: - - ------------------------------------------ - | 1) migration/0--1 => sshd-1755 - ------------------------------------------ - - */ - - event_printf(" ------------------------------------------ "); - event_printf(" %*d) ", max_bytes_for_cpu, cpu); - fn_graph_proc_print(prev_pid); - event_printf(" => "); - fn_graph_proc_print(pid); - event_printf(" ------------------------------------------ "); -} - -/* Signal a overhead of time execution to the output */ -static void fn_graph_overhead_print(unsigned long long duration) -{ - const char *s = " "; - - /* If duration disappear, we don't need anything */ - if (!gopt_graph_print_duration) - return; - - /* duration == -1 is for non nested entry or return */ - if ((duration != -1) && gopt_graph_print_overhead) { - /* Duration exceeded 100 msecs */ - if (duration > 100000ULL) - s = "! "; - /* Duration exceeded 10 msecs */ - else if (duration > 10000ULL) - s = "+ "; - } - - event_printf(s); -} - -static void fn_graph_abstime_print(u64 ts) -{ - u64 time = ts / 1000; - unsigned long sec = time / 1000000; - unsigned long usec = time % 1000000; - - event_printf("%5lu.%06lu | ", sec, usec); -} - -static void fn_graph_irq_print(int type) -{ - /* TODO: implement it. */ -} - -static void fn_graph_duration_print(unsigned long long duration) -{ - /* log10(ULONG_MAX) + ' ' */ - char msecs_str[21]; - char nsecs_str[5]; - int len; - unsigned long nsecs_rem = duration % 1000; - - duration = duration / 1000; - len = sprintf(msecs_str, "%lu", (unsigned long) duration); - - /* Print msecs */ - event_printf("%s", msecs_str); - - /* Print nsecs (we don't want to exceed 7 numbers) */ - if (len < 7) { - snprintf(nsecs_str, 8 - len, "%03lu", nsecs_rem); - event_printf(".%s", nsecs_str); - - len += strlen(nsecs_str); - } - - if (len > 7) - len = 7; - - event_printf(" us %*s| ", 7 - len, ""); -} - -/* Case of a leaf function on its call entry */ -static void fn_graph_entry_leaf_print(void *entry_data, void *exit_data) -{ - struct event_type *t = function_graph_return_type; - - u64 calltime = access_field(t, exit_data, "ret.calltime"); - u64 rettime = access_field(t, exit_data, "ret.rettime"); - u64 duration = rettime - calltime; - int depth = access_field(t, exit_data, "ret.depth"); - ulong func = access_field(t, exit_data, "ret.func"); - - fn_graph_overhead_print(duration); - if (gopt_graph_print_duration) - fn_graph_duration_print(duration); - - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); - sym_print(func, 0); - event_printf("(); "); -} - -static void fn_graph_entry_nested_print(struct event_type *t, void *data) -{ - int depth = access_field(t, data, "graph_ent.depth"); - ulong func = access_field(t, data, "graph_ent.func"); - - fn_graph_overhead_print(-1); - - /* No time */ - if (gopt_graph_print_duration) - event_printf(" | "); - - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); - sym_print(func, 0); - event_printf("() { "); -} - -static void fn_graph_prologue_print(int cpu, u64 ts, int pid, int type) -{ - fn_graph_proc_switch_print(pid, cpu); - - if (type) - fn_graph_irq_print(type); - - if (gopt_graph_print_abstime) - fn_graph_abstime_print(ts); - - if (gopt_graph_print_cpu) - event_printf(" %*d) ", max_bytes_for_cpu, cpu); - - if (gopt_graph_print_proc) { - fn_graph_proc_print(pid); - event_printf(" | "); - } -} - -static void *get_return_for_leaf(struct event_type *t, - struct format_context *fc, void *curr_data) -{ - int cpu; - struct ftrace_event next; - ulong entry_func, exit_func; - - cpu = ring_buffer_stream_pop_event(&fc->stream, &next); - - if (cpu < 0) - goto not_leaf; - - if (ftrace_event_get_id(next.data) != function_graph_return_id) - goto not_leaf; - - if (ftrace_event_get_pid(curr_data) != ftrace_event_get_pid(next.data)) - goto not_leaf; - - entry_func = access_field(t, curr_data, "graph_ent.func"); - exit_func = access_field(function_graph_return_type, next.data, - "ret.func"); - - if (entry_func != exit_func) - goto not_leaf; - - return next.data; - -not_leaf: - ring_buffer_stream_push_current_event(&fc->stream); - return NULL; -} - -static -void event_fn_entry_print(struct event_type *t, struct format_context *fc) -{ - void *leaf_ret_data = NULL, *curr_data = fc->event.data, *data; - int pid = ftrace_event_get_pid(curr_data); - - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 1); - - data = alloca(fc->event.length); - if (data) { - memcpy(data, fc->event.data, fc->event.length); - curr_data = data; - leaf_ret_data = get_return_for_leaf(t, fc, curr_data); - } - - if (leaf_ret_data) - return fn_graph_entry_leaf_print(curr_data, leaf_ret_data); - else - return fn_graph_entry_nested_print(t, curr_data); -} - -static -void event_fn_return_print(struct event_type *t, struct format_context *fc) -{ - void *data = fc->event.data; - int pid = ftrace_event_get_pid(data); - - u64 calltime = access_field(t, data, "ret.calltime"); - u64 rettime = access_field(t, data, "ret.rettime"); - u64 duration = rettime - calltime; - int depth = access_field(t, data, "ret.depth"); - - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 0); - fn_graph_overhead_print(duration); - - if (gopt_graph_print_duration) - fn_graph_duration_print(duration); - - event_printf("%*s} ", depth * TRACE_GRAPH_INDENT, ""); - - if (gopt_graph_print_overrun) { - unsigned long overrun = access_field(t, data, "ret.overrun"); - event_printf(" (Overruns: %lu) ", overrun); - } - - fn_graph_irq_print(0); -} - -static void ftrace_show_function_graph_init(void) -{ - if (strcmp(current_tracer_name, "function_graph")) - return; - - function_graph_entry_type = find_event_type_by_name( - "ftrace", "funcgraph_entry"); - function_graph_return_type = find_event_type_by_name( - "ftrace", "funcgraph_exit"); - - if (!function_graph_entry_type || !function_graph_return_type) - return; - - /* - * Because of get_return_for_leaf(), the exception handling - * of access_field() is not work for function_graph. So we need - * to ensure access_field() will not failed for these fields. - * - * I know these will not failed. I just ensure it. - */ - - if (!find_event_field(function_graph_entry_type, "graph_ent.func")) - return; - - if (!find_event_field(function_graph_entry_type, "graph_ent.depth")) - return; - - if (!find_event_field(function_graph_return_type, "ret.func")) - return; - - if (!find_event_field(function_graph_return_type, "ret.calltime")) - return; - - if (!find_event_field(function_graph_return_type, "ret.rettime")) - return; - - if (!find_event_field(function_graph_return_type, "ret.overrun")) - return; - - if (!find_event_field(function_graph_return_type, "ret.depth")) - return; - - cpus_prev_pid = malloc(sizeof(int) * nr_cpu_ids); - if (!cpus_prev_pid) - return; - - max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1); - - function_graph_entry_id = function_graph_entry_type->id; - function_graph_return_id = function_graph_return_type->id; - - /* OK, set the printer for function_graph. */ - tracer_no_event_context = 1; - function_graph_entry_type->printer = event_fn_entry_print; - function_graph_return_type->printer = event_fn_return_print; -} - -static void event_sched_kthread_stop_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid")); -} - -static void event_sched_kthread_stop_ret_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("ret %d ", (int)access_field(t, fc->event.data, "ret")); -} - -static void event_sched_wait_task_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_wakeup_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] success=%d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio"), - (int)access_field(t, fc->event.data, "success")); -} - -static void event_sched_wakeup_new_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] success=%d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio"), - (int)access_field(t, fc->event.data, "success")); -} - -static void event_sched_switch_print(struct event_type *t, - struct format_context *fc) -{ - char *prev_comm = (char *)(long)access_field(t, fc->event.data, - "prev_comm"); - int prev_pid = access_field(t, fc->event.data, "prev_pid"); - int prev_prio = access_field(t, fc->event.data, "prev_prio"); - - int prev_state = access_field(t, fc->event.data, "prev_state"); - - char *next_comm = (char *)(long)access_field(t, fc->event.data, - "next_comm"); - int next_pid = access_field(t, fc->event.data, "next_pid"); - int next_prio = access_field(t, fc->event.data, "next_prio"); - - event_printf("task %s:%d [%d] (", prev_comm, prev_pid, prev_prio); - - if (prev_state == 0) { - event_printf("R"); - } else { - if (prev_state & 1) - event_printf("S"); - if (prev_state & 2) - event_printf("D"); - if (prev_state & 4) - event_printf("T"); - if (prev_state & 8) - event_printf("t"); - if (prev_state & 16) - event_printf("Z"); - if (prev_state & 32) - event_printf("X"); - if (prev_state & 64) - event_printf("x"); - if (prev_state & 128) - event_printf("W"); - } - - event_printf(") ==> %s:%d [%d] ", next_comm, next_pid, next_prio); -} - -static void event_sched_migrate_task_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] from: %d to: %d ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio"), - (int)access_field(t, fc->event.data, "orig_cpu"), - (int)access_field(t, fc->event.data, "dest_cpu")); -} - -static void event_sched_process_free_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_process_exit_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_process_wait_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("task %s:%d [%d] ", - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid"), - (int)access_field(t, fc->event.data, "prio")); -} - -static void event_sched_process_fork_print(struct event_type *t, - struct format_context *fc) -{ - char *parent_comm = (char *)(long)access_field(t, fc->event.data, - "parent_comm"); - int parent_pid = access_field(t, fc->event.data, "parent_pid"); - - char *child_comm = (char *)(long)access_field(t, fc->event.data, - "child_comm"); - int child_pid = access_field(t, fc->event.data, "child_pid"); - - event_printf("parent %s:%d child %s:%d ", parent_comm, parent_pid, - child_comm, child_pid); -} - -static void event_sched_signal_send_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("sig: %d task %s:%d ", - (int)access_field(t, fc->event.data, "sig"), - (char *)(long)access_field(t, fc->event.data, "comm"), - (int)access_field(t, fc->event.data, "pid")); -} - -static void event_kmalloc_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags")); -} - -static void event_kmem_cache_alloc_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags")); -} - -static void event_kmalloc_node_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx node=%d ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags"), - (int)access_field(t, fc->event.data, "node")); -} - -static void event_kmem_cache_alloc_node_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " - "gfp_flags=%lx node=%d ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr"), - (size_t)access_field(t, fc->event.data, "bytes_req"), - (size_t)access_field(t, fc->event.data, "bytes_alloc"), - (long)access_field(t, fc->event.data, "gfp_flags"), - (int)access_field(t, fc->event.data, "node")); -} - -static void event_kfree_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr")); -} - -static void event_kmem_cache_free_print(struct event_type *t, - struct format_context *fc) -{ - event_printf("call_site=%lx ptr=%p ", - (long)access_field(t, fc->event.data, "call_site"), - (void *)(long)access_field(t, fc->event.data, "ptr")); -} - -static void event_workqueue_insertion_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - ulong func = access_field(t, fc->event.data, "func"); - - event_printf("thread=%s:%d func=", thread_comm, thread_pid); - sym_print(func, 1); - event_printf(" "); -} - -static void event_workqueue_execution_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - ulong func = access_field(t, fc->event.data, "func"); - - event_printf("thread=%s:%d func=", thread_comm, thread_pid); - sym_print(func, 1); - event_printf(" "); -} - -static void event_workqueue_creation_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - int cpu = access_field(t, fc->event.data, "cpu"); - - event_printf("thread=%s:%d cpu=%d ", thread_comm, thread_pid, cpu); -} - -static void event_workqueue_destruction_print(struct event_type *t, - struct format_context *fc) -{ - char *thread_comm = (char *)(long)access_field(t, fc->event.data, - "thread_comm"); - int thread_pid = access_field(t, fc->event.data, "thread_pid"); - - event_printf("thread=%s:%d ", thread_comm, thread_pid); -} - -static void ftrace_show_trace_event_init(void) -{ -#define init_trace_event(system, name) -do { - struct event_type *t = find_event_type_by_name(#system, #name); - if (t) - t->printer = event_ ## name ## _print; -} while (0) - - init_trace_event(sched, sched_kthread_stop); - init_trace_event(sched, sched_kthread_stop_ret); - init_trace_event(sched, sched_wait_task); - init_trace_event(sched, sched_wakeup); - init_trace_event(sched, sched_wakeup_new); - init_trace_event(sched, sched_switch); - init_trace_event(sched, sched_migrate_task); - init_trace_event(sched, sched_process_free); - init_trace_event(sched, sched_process_exit); - init_trace_event(sched, sched_process_wait); - init_trace_event(sched, sched_process_fork); - init_trace_event(sched, sched_signal_send); - - init_trace_event(kmem, kmalloc); - init_trace_event(kmem, kmem_cache_alloc); - init_trace_event(kmem, kmalloc_node); - init_trace_event(kmem, kmem_cache_alloc_node); - init_trace_event(kmem, kfree); - init_trace_event(kmem, kmem_cache_free); - - init_trace_event(workqueue, workqueue_insertion); - init_trace_event(workqueue, workqueue_execution); - init_trace_event(workqueue, workqueue_creation); - init_trace_event(workqueue, workqueue_destruction); -#undef init_trace_event -} - -static void ftrace_show_destroy(void) -{ - free(cpus_prev_pid); -} - static char *help_ftrace[] = { "trace", "show or dump the tracing info", @@ -2947,22 +1491,11 @@ static char *help_ftrace[] = { "trace", " shows the current tracer and other informations.", "", -"trace show [ -c <cpulist> ] [ -f [no]<flagname> ]", +"trace show", " shows all events with readability text(sorted by timestamp)", -" -c: only shows specified CPUs' events.", -" ex. trace show -c 1,2 - only shows cpu#1 and cpu#2 's events.", -" trace show -c 0,2-7 - only shows cpu#0, cpu#2...cpu#7's events.", -" -f: set or clear a flag", -" available flags default", -" context_info true", -" sym_offset false", -" sym_addr false", -" graph_print_duration true", -" graph_print_overhead true", -" graph_print_abstime false", -" graph_print_cpu true", -" graph_print_proc false", -" graph_print_overrun false", +"", +"trace report", +" the same as "trace show"", "", "trace dump [-sm] <dest-dir>", " dump ring_buffers to dest-dir. Then you can parse it", -- Crash-utility mailing list Crash-utility@redhat.com https://www.redhat.com/mailman/listinfo/crash-utility |
trace: Improve "trace show" command
----- Original Message -----
> On 03/03/2011 11:25 PM, Dave Anderson wrote: > > > > > > ----- Original Message ----- > >> The code were also applied to: > >> git://github.com/laijs/tracing-extension-module-for-crash.git > >> > >> Documents and man pages will/may be added in two weeks. > >> > >> Dave Anderson, could you add a "Requires" entry to its RPM.spec, > >> it requires trace-cmd RPM after this patch applied. > > Sorry, please omit this requirement of mine. That actually would be a legitimate request for the RHEL6 crash-trace-command package, but I'd prefer not to add a Requires entry for the upstream src.rpm. But I note in your new patch, that ftrace_show() is a void function, and if the popen("trace.cmd") fails, it just returns quietly. I would think that there should be an explanatory error message in that case? Also, there's a buffer overflow error assignment to buf[4097]: static void ftrace_show(int argc, char *argv[]) { char buf[4096]; char tmp[] = "/tmp/crash.trace_dat.XXXXXX"; char *trace_cmd = "trace-cmd", *env_trace_cmd = getenv("TRACE_CMD"); int fd; FILE *file; size_t ret; /* check trace-cmd */ if (env_trace_cmd) trace_cmd = env_trace_cmd; if (!(file = popen(trace_cmd, "r"))) return; ret = fread(buf, 1, sizeof(buf), file); buf[4097] = 0; if (!strstr(buf, "trace-cmd version")) { if (env_trace_cmd) fprintf(fp, "Invalid environment TRACE_CMD: %s ", env_trace_cmd); else fprintf(fp, ""trace show" requires trace-cmd. " "please set the environment TRACE_CMD " "if you installed it a special path " ); return; } So if you don't mind, I'll fix it like this: buf[0] = 0; if ((file = popen(trace_cmd, "r"))) { ret = fread(buf, 1, sizeof(buf), file); buf[4095] = 0; } if (!strstr(buf, "trace-cmd version")) { if (env_trace_cmd) fprintf(fp, "Invalid environment TRACE_CMD: %s ", env_trace_cmd); else fprintf(fp, ""trace show" requires trace-cmd. " "please set the environment TRACE_CMD " "if you installed it in a special path " ); return; } If that's OK with you, the patch is queued for crash 5.1.4. Thanks, Dave > > > > > Sorry, but no, I cannot do that. > > > > There are two versions of the trace.c extension module that > > I am aware of: > > > > (1) The extensions/trace.c file that is included as part of > > each upstream crash utility release. That version is the > > one that you updated in crash-5.1.2 to add support for > > kernel versions beyond 2.6.32. > > > > - Update of the "extensions/trace.c" extension module. > > Initially > > designed to support 2.6.32 (RHEL6), it has been updated to > > support > > kernels up to 2.6.38-rc1. > > (laijs@cn.fujitsu.com) > > > > This patch is for upstream crash utility release, but I just coded it > based my git tree, I forgot to check the different between crash-5.1.3 > in which you have beautified the trace.c a little with several lines. > > The following is the updated patch. > > Subject: [PATCH] trace: Improve "trace show" command > > Use trace-cmd to implement "trace show" command and remove > the related code. It is not a good idea to maintain another > set of code with the same functional. trace-cmd is better > and mature. > > How the new "trace show" works: > 1) build trace.dat from the core file and dump it to /tmp. > 2) exec "trace-cmd report" upon the trace.dat > 3) splice the output of trace-cmd to user and unlink the temp file. > > Signed-off-by: Lai Jiangshan <laijs@cn.fujitsu.com> > --- > trace.c | 1565 > ++-------------------------------------------------------------- > 1 file changed, 49 insertions(+), 1516 deletions(-) > diff --git b/extensions/trace.c a/extensions/trace.c > index 1cfc50f..057459b 100755 > --- b/extensions/trace.c > +++ a/extensions/trace.c > @@ -96,8 +96,6 @@ static const char *current_tracer_name; > > static void ftrace_destroy_event_types(void); > static int ftrace_init_event_types(void); > -static int ftrace_show_init(void); > -static void ftrace_show_destroy(void); > > /* at = ((struct *)ptr)->member */ > #define read_value(at, ptr, struct, member) > @@ -489,13 +487,8 @@ static int ftrace_init(void) > if (ftrace_init_current_tracer() < 0) > goto out_2; > > - if (ftrace_show_init() < 0) > - goto out_3; > - > return 0; > > -out_3: > - free(current_tracer_name); > out_2: > ftrace_destroy_event_types(); > out_1: > @@ -511,7 +504,6 @@ out_0: > > static void ftrace_destroy(void) > { > - ftrace_show_destroy(); > free(current_tracer_name); > ftrace_destroy_event_types(); > > @@ -611,37 +603,21 @@ out_fail: > return -1; > } > > -typedef uint64_t u64; > -typedef int64_t s64; > -typedef uint32_t u32; > - > #define MAX_CACHE_ID 256 > > -struct ftrace_field; > -typedef u64 (*access_op)(struct ftrace_field *aop, void *data); > -static void ftrace_field_access_init(struct ftrace_field *f); > - > struct ftrace_field { > const char *name; > const char *type; > - access_op op; > int offset; > int size; > int is_signed; > }; > > -struct event_type; > -struct format_context; > -typedef void (*event_printer)(struct event_type *t, struct > format_context *fc); > - > - /* SIGH, we cann't get "print fmt" from core-file */ > - > struct event_type { > struct event_type *next; > const char *system; > const char *name; > int plugin; > - event_printer printer; > const char *print_fmt; > int id; > int nfields; > @@ -655,17 +631,6 @@ static int nr_event_types; > static struct ftrace_field *ftrace_common_fields; > static int ftrace_common_fields_count; > > -/* > - * TODO: implement event_generic_print_fmt_print() when the print fmt > - * in tracing/events/$SYSTEM/$TRACE/format becomes a will-defined > - * language. > - * > - * static void event_generic_print_fmt_print(struct event_type *t, > - * struct format_context *fc); > - */ > -static void event_default_print(struct event_type *t, > - struct format_context *fc); > - > static int syscall_get_enter_fields(ulong call, ulong *fields) > { > static int inited; > @@ -888,7 +853,6 @@ static int ftrace_init_event_fields(ulong > fields_head, int *pnfields, > goto out_fail; > } > > - ftrace_field_access_init(&fields[nfields]); > nfields++; > > /* Advance to the next field */ > @@ -1187,7 +1151,6 @@ static int ftrace_init_event_types(void) > aevent_type->plugin = 1; > else > aevent_type->plugin = 0; > - aevent_type->printer = event_default_print; > > /* Add a event type */ > event_types[nr_event_types++] = aevent_type; > @@ -1213,57 +1176,6 @@ out_fail: > return -1; > } > > -static > -struct ftrace_field *find_event_field(struct event_type *t, const > char *name) > -{ > - int i; > - struct ftrace_field *f; > - > - for (i = 0; i < ftrace_common_fields_count; i++) { > - f = ftrace_common_fields + i; > - if (!strcmp(name, f->name)) > - return f; > - } > - > - for (i = 0; i < t->nfields; i++) { > - f = &t->fields[i]; > - if (!strcmp(name, f->name)) > - return f; > - } > - > - return NULL; > -} > - > -static struct event_type *find_event_type(int id) > -{ > - int i; > - > - if ((unsigned int)id < MAX_CACHE_ID) > - return event_type_cache[id]; > - > - for (i = 0; i < nr_event_types; i++) { > - if (event_types[i]->id == id) > - return event_types[i]; > - } > - > - return NULL; > -} > - > -static > -struct event_type *find_event_type_by_name(const char *system, const > char *name) > -{ > - int i; > - > - for (i = 0; i < nr_event_types; i++) { > - if (system && strcmp(system, event_types[i]->system)) > - continue; > - if (!strcmp(name, event_types[i]->name)) > - return event_types[i]; > - } > - > - return NULL; > -} > - > #define default_common_field_count 5 > > static int ftrace_dump_event_type(struct event_type *t, const char > *path) > @@ -1365,381 +1277,6 @@ static int ftrace_dump_event_types(const char > *events_path) > return 0; > } > > -struct ring_buffer_per_cpu_stream { > - struct ring_buffer_per_cpu *cpu_buffer; > - void *curr_page; > - int curr_page_indx; > - > - uint64_t ts; > - uint32_t *offset; > - uint32_t *commit; > -}; > - > -static > -int ring_buffer_per_cpu_stream_init(struct ring_buffer_per_cpu > *cpu_buffer, > - unsigned pages, struct ring_buffer_per_cpu_stream *s) > -{ > - s->cpu_buffer = cpu_buffer; > - s->curr_page = malloc(PAGESIZE()); > - if (s->curr_page == NULL) > - return -1; > - > - s->curr_page_indx = -1; > - return 0; > -} > - > -static > -void ring_buffer_per_cpu_stream_destroy(struct > ring_buffer_per_cpu_stream *s) > -{ > - free(s->curr_page); > -} > - > -struct ftrace_event { > - uint64_t ts; > - int length; > - void *data; > -}; > - > -struct event { > - u32 type_len:5, time_delta:27; > -}; > - > -#define RINGBUF_TYPE_PADDING 29 > -#define RINGBUF_TYPE_TIME_EXTEND 30 > -#define RINGBUF_TYPE_TIME_STAMP 31 > -#define RINGBUF_TYPE_DATA 0 ... 28 > - > -#define sizeof_local_t (sizeof(ulong)) > -#define PAGE_HEADER_LEN (8 + sizeof_local_t) > - > -static > -int ring_buffer_per_cpu_stream_get_page(struct > ring_buffer_per_cpu_stream *s) > -{ > - ulong raw_page; > - > - read_value(raw_page, s->cpu_buffer->linear_pages[s->curr_page_indx], > - buffer_page, page); > - > - if (!readmem(raw_page, KVADDR, s->curr_page, PAGESIZE(), > - "get page context", RETURN_ON_ERROR)) > - return -1; > - > - s->ts = *(u64 *)s->curr_page; > - s->offset = s->curr_page + PAGE_HEADER_LEN; > - s->commit = s->offset + *(ulong *)(s->curr_page + 8) / 4; > - > - return 0; > - > -out_fail: > - return -1; > -} > - > -static > -int ring_buffer_per_cpu_stream_pop_event(struct > ring_buffer_per_cpu_stream *s, > - struct ftrace_event *res) > -{ > - struct event *event; > - > - res->data = NULL; > - > - if (s->curr_page_indx >= s->cpu_buffer->nr_linear_pages) > - return -1; > - > -again: > - if ((s->curr_page_indx == -1) || (s->offset >= s->commit)) { > - s->curr_page_indx++; > - > - if (s->curr_page_indx == s->cpu_buffer->nr_linear_pages) > - return -1; > - > - if (ring_buffer_per_cpu_stream_get_page(s) < 0) { > - s->curr_page_indx = s->cpu_buffer->nr_linear_pages; > - return -1; > - } > - > - if (s->offset >= s->commit) > - goto again; > - } > - > - event = (void *)s->offset; > - > - switch (event->type_len) { > - case RINGBUF_TYPE_PADDING: > - if (event->time_delta) > - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); > - else > - s->offset = s->commit; > - goto again; > - > - case RINGBUF_TYPE_TIME_EXTEND: > - s->ts +=event->time_delta; > - s->ts += ((u64)*(s->offset + 1)) << 27; > - s->offset += 2; > - goto again; > - > - case RINGBUF_TYPE_TIME_STAMP: > - /* FIXME: not implemented */ > - s->offset += 4; > - goto again; > - > - case RINGBUF_TYPE_DATA: > - if (!event->type_len) { > - res->data = s->offset + 2; > - res->length = *(s->offset + 1) - 4; > - > - s->offset += 1 + ((*(s->offset + 1) + 3) / 4); > - } else { > - res->data = s->offset + 1; > - res->length = event->type_len * 4; > - > - s->offset += 1 + event->type_len; > - } > - > - if (s->offset > s->commit) { > - fprintf(fp, "corrupt "); > - res->data = NULL; > - goto again; > - } > - > - s->ts += event->time_delta; > - res->ts = s->ts; > - > - return 0; > - > - default:; > - } > - > - return -1; > -} > - > -struct ring_buffer_stream { > - struct ring_buffer_per_cpu_stream *ss; > - struct ftrace_event *es; > - u64 ts; > - int popped_cpu; > - int pushed; > -}; > - > -static void __rbs_destroy(struct ring_buffer_stream *s, int *cpulist, > int nr) > -{ > - int cpu; > - > - for (cpu = 0; cpu < nr; cpu++) { > - if (!s->ss[cpu].cpu_buffer) > - continue; > - > - ring_buffer_per_cpu_stream_destroy(s->ss + cpu); > - } > - > - free(s->ss); > - free(s->es); > -} > - > -static > -int ring_buffer_stream_init(struct ring_buffer_stream *s, int > *cpulist) > -{ > - int cpu; > - > - s->ss = malloc(sizeof(*s->ss) * nr_cpu_ids); > - if (s->ss == NULL) > - return -1; > - > - s->es = malloc(sizeof(*s->es) * nr_cpu_ids); > - if (s->es == NULL) { > - free(s->ss); > - return -1; > - } > - > - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { > - s->ss[cpu].cpu_buffer = NULL; > - s->es[cpu].data = NULL; > - > - if (!global_buffers[cpu].kaddr) > - continue; > - > - if (cpulist && !cpulist[cpu]) > - continue; > - > - if (ring_buffer_per_cpu_stream_init(global_buffers + cpu, > - global_pages, s->ss + cpu) < 0) { > - __rbs_destroy(s, cpulist, cpu); > - return -1; > - } > - } > - > - s->ts = 0; > - s->popped_cpu = nr_cpu_ids; > - s->pushed = 0; > - > - return 0; > -} > - > -static > -void ring_buffer_stream_destroy(struct ring_buffer_stream *s, int > *cpulist) > -{ > - __rbs_destroy(s, cpulist, nr_cpu_ids); > -} > - > -/* make current event be returned again at next pop */ > -static void ring_buffer_stream_push_current_event(struct > ring_buffer_stream *s) > -{ > - if ((s->popped_cpu < 0) || (s->popped_cpu == nr_cpu_ids)) > - return; > - > - s->pushed = 1; > -} > - > -/* return the cpu# of this event */ > -static int ring_buffer_stream_pop_event(struct ring_buffer_stream *s, > - struct ftrace_event *res) > -{ > - int cpu, min_cpu = -1; > - u64 ts, min_ts; > - > - res->data = NULL; > - > - if (s->popped_cpu < 0) > - return -1; > - > - if (s->popped_cpu == nr_cpu_ids) { > - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { > - if (!s->ss[cpu].cpu_buffer) > - continue; > - > - ring_buffer_per_cpu_stream_pop_event(s->ss + cpu, > - s->es + cpu); > - > - if (s->es[cpu].data == NULL) > - continue; > - > - /* > - * We do not have start point of time, > - * determine the min_ts with heuristic way. > - */ > - ts = s->es[cpu].ts; > - if (min_cpu < 0 || (s64)(ts - min_ts) < 0) { > - min_ts = ts; > - min_cpu = cpu; > - } > - } > - > - s->pushed = 0; > - goto done; > - } > - > - if (s->pushed) { > - s->pushed = 0; > - *res = s->es[s->popped_cpu]; > - return s->popped_cpu; > - } > - > - ring_buffer_per_cpu_stream_pop_event(&s->ss[s->popped_cpu], > - &s->es[s->popped_cpu]); > - > - for (cpu = 0; cpu < nr_cpu_ids; cpu++) { > - if (s->es[cpu].data == NULL) > - continue; > - > - /* we have start point of time(s->ts) */ > - ts = s->es[cpu].ts - s->ts; > - if (min_cpu < 0 || ts < min_ts) { > - min_ts = ts; > - min_cpu = cpu; > - } > - } > - > -done: > - s->popped_cpu = min_cpu; > - > - if (min_cpu < 0) > - return -1; > - > - s->ts = s->es[min_cpu].ts; > - *res = s->es[min_cpu]; > - > - return min_cpu; > -} > - > -static u64 access_error(struct ftrace_field *f, void *data) > -{ > - return 0; > -} > - > -static u64 access_8(struct ftrace_field *f, void *data) > -{ > - return *(int8_t *)(data + f->offset); > -} > - > -static u64 access_16(struct ftrace_field *f, void *data) > -{ > - return *(int16_t *)(data + f->offset); > -} > - > -static u64 access_32(struct ftrace_field *f, void *data) > -{ > - return *(int32_t *)(data + f->offset); > -} > - > -static u64 access_64(struct ftrace_field *f, void *data) > -{ > - return *(int64_t *)(data + f->offset); > -} > - > -static u64 access_string_local(struct ftrace_field *f, void *data) > -{ > - int offset; > - > - if (f->size == 2) > - offset = *(int16_t *)(data + f->offset); > - else > - offset = *(int32_t *)(data + f->offset) & 0xFFFF; > - > - return (long)(data + offset); > -} > - > -static u64 access_string(struct ftrace_field *f, void *data) > -{ > - return (long)(data + f->offset); > -} > - > -static u64 access_other_local(struct ftrace_field *f, void *data) > -{ > - return access_string_local(f, data); > -} > - > -static u64 access_other(struct ftrace_field *f, void *data) > -{ > - return (long)(data + f->offset); > -} > - > -static void ftrace_field_access_init(struct ftrace_field *f) > -{ > - /* guess whether it is string array */ > - if (!strncmp(f->type, "__data_loc", sizeof("__data_loc") - 1)) { > - if (f->size != 2 && f->size != 4) { > - /* kernel side may be changed, need fix here */ > - f->op = access_error; > - } else if (strstr(f->type, "char")) { > - f->op = access_string_local; > - } else { > - f->op = access_other_local; > - } > - } else if (strchr(f->type, '[')) { > - if (strstr(f->type, "char")) > - f->op = access_string; > - else > - f->op = access_other; > - } else { > - switch (f->size) { > - case 1: f->op = access_8; break; > - case 2: f->op = access_16; break; > - case 4: f->op = access_32; break; > - case 8: f->op = access_64; break; > - default: f->op = access_other; break; > - } > - } > -} > - > static void show_basic_info(void) > { > fprintf(fp, "current tracer is %s ", current_tracer_name); > @@ -1882,331 +1419,55 @@ static void ftrace_dump(int argc, char > *argv[]) > } > } > > -static char show_event_buf[4096]; > -static int show_event_pos; > - > -#define INVALID_ACCESS_FIELD 1 > -static jmp_buf show_event_env; > - > -struct format_context { > - struct ring_buffer_stream stream; > - struct ftrace_event event; > - int cpu; > -}; > - > -static struct format_context format_context; > - > -/* !!!! @event_type and @field_name should be const for every call */ > -#define access_field(event_type, data, field_name) > -({ > - static struct ftrace_field *__access_field##_field; > - > - if (__access_field##_field == NULL) { > - __access_field##_field = find_event_field(event_type, > - field_name); > - } > - > - if (__access_field##_field == NULL) { > - event_type->printer = event_default_print; > - ring_buffer_stream_push_current_event(&format_cont ext.stream); > - longjmp(show_event_env, INVALID_ACCESS_FIELD); > - } > - > - __access_field##_field->op(__access_field##_field, data); > -}) > - > -static int ftrace_event_get_id(void *data) > -{ > - return access_field(event_types[0], data, "common_type"); > -} > - > -static int ftrace_event_get_pid(void *data) > -{ > - return access_field(event_types[0], data, "common_pid"); > -} > - > -#define event_printf(fmt, args...) > -do { > - show_event_pos += snprintf(show_event_buf + show_event_pos, > - sizeof(show_event_buf) - show_event_pos, > - fmt, ##args); > -} while (0) > - > - > -static void event_field_print(struct ftrace_field *f, void *data) > +static void ftrace_show(int argc, char *argv[]) > { > - u64 value = f->op(f, data); > + char buf[4096]; > + char tmp[] = "/tmp/crash.trace_dat.XXXXXX"; > + char *trace_cmd = "trace-cmd", *env_trace_cmd = getenv("TRACE_CMD"); > + int fd; > + FILE *file; > + size_t ret; > > - if (f->op == access_error) { > - event_printf("<Error>"); > - } else if (f->op == access_8) { > - if (f->is_signed) > - event_printf("%d", (int8_t)value); > - else > - event_printf("%u", (uint8_t)value); > - } else if (f->op == access_16) { > - if (f->is_signed) > - event_printf("%d", (int16_t)value); > - else > - event_printf("%u", (uint16_t)value); > - } else if (f->op == access_32) { > - if (f->is_signed) > - event_printf("%d", (int32_t)value); > - else > - event_printf("%u", (uint32_t)value); > - } else if (f->op == access_64) { > - if (f->is_signed) > - event_printf("%lld", (long long)value); > + /* check trace-cmd */ > + if (env_trace_cmd) > + trace_cmd = env_trace_cmd; > + if (!(file = popen(trace_cmd, "r"))) > + return; > + ret = fread(buf, 1, sizeof(buf), file); > + buf[4097] = 0; > + if (!strstr(buf, "trace-cmd version")) { > + if (env_trace_cmd) > + fprintf(fp, "Invalid environment TRACE_CMD: %s ", > + env_trace_cmd); > else > - event_printf("%llu", (unsigned long long)value); > - } else if (f->op == access_string_local) { > - int size = 0; > + fprintf(fp, ""trace show" requires trace-cmd. " > + "please set the environment TRACE_CMD " > + "if you installed it a special path " > + ); > + return; > + } > > - if (f->size == 4) > - size = *(int32_t *)(data + f->offset) >> 16; > + /* dump trace.dat to the temp file */ > + mktemp(tmp); > + fd = open(tmp, O_WRONLY | O_CREAT | O_TRUNC, 0644); > + if (trace_cmd_data_output(fd) < 0) > + goto out; > > - if (size) > - event_printf("%.*s", size, (char *)(long)value); > - else > - event_printf("%s", (char *)(long)value); > - } else if (f->op == access_string) { > - event_printf("%.*s", f->size, (char *)(long)value); > - } else if (f->op == access_other) { > - /* TODO */ > - } else if (f->op == access_other_local) { > - /* TODO */ > - } else { > - /* TODO */ > + /* splice the output of trace-cmd to user */ > + snprintf(buf, sizeof(buf), "%s report %s", trace_cmd, tmp); > + if (!(file = popen(buf, "r"))) > + goto out; > + for (;;) { > + ret = fread(buf, 1, sizeof(buf), file); > + if (ret == 0) > + break; > + fwrite(buf, 1, ret, fp); > } > -} > - > -static void get_comm_from_pid(int pid, char *comm) > -{ > - int li, hi; > - struct task_context *tc; > - > - if (pid == 0) { > - strcpy(comm, "<swapper>"); > - return; > - } > - > - tc = FIRST_CONTEXT(); > - > - li = 0; > - hi = RUNNING_TASKS(); > - while (li < hi) { > - int mid = (li + hi) / 2; > - > - if (tc[mid].pid > pid) > - hi = mid; > - else if (tc[mid].pid < pid) > - li = mid + 1; > - else { > - strcpy(comm, tc[mid].comm); > - return; > - } > - } > - > - strcpy(comm, "<...>"); > -} > - > -static void event_context_print(struct event_type *t, struct > format_context *fc) > -{ > - u64 time = fc->event.ts / 1000; > - ulong sec = time / 1000000; > - ulong usec = time % 1000000; > - int pid = ftrace_event_get_pid(fc->event.data); > - char comm[20]; > - > - get_comm_from_pid(pid, comm); > - event_printf("%16s-%-5d [%03d] %5lu.%06lu: ", > - comm, pid, fc->cpu, sec, usec); > -} > - > -static int gopt_context_info; > -static int gopt_sym_offset; > -static int gopt_sym_addr; > - > -static int gopt_graph_print_duration; > -static int gopt_graph_print_overhead; > -static int gopt_graph_print_abstime; > -static int gopt_graph_print_cpu; > -static int gopt_graph_print_proc; > -static int gopt_graph_print_overrun; > - > -static void set_all_flags_default(void) > -{ > - gopt_context_info = 1; > - gopt_sym_offset = 0; > - gopt_sym_addr = 0; > - > - gopt_graph_print_duration = 1; > - gopt_graph_print_overhead = 1; > - gopt_graph_print_abstime = 0; > - gopt_graph_print_cpu = 1; > - gopt_graph_print_proc = 0; > - gopt_graph_print_overrun = 0; > -} > - > -static void set_clear_flag(const char *flag_name, int set) > -{ > - if (!strcmp(flag_name, "context_info")) > - gopt_context_info = set; > - else if (!strcmp(flag_name, "sym_offset")) > - gopt_sym_offset = set; > - else if (!strcmp(flag_name, "sym_addr")) > - gopt_sym_addr = set; > - else if (!strcmp(flag_name, "graph_print_duration")) > - gopt_graph_print_duration = set; > - else if (!strcmp(flag_name, "graph_print_overhead")) > - gopt_graph_print_overhead = set; > - else if (!strcmp(flag_name, "graph_print_abstime")) > - gopt_graph_print_abstime = set; > - else if (!strcmp(flag_name, "graph_print_cpu")) > - gopt_graph_print_cpu = set; > - else if (!strcmp(flag_name, "graph_print_proc")) > - gopt_graph_print_proc = set; > - else if (!strcmp(flag_name, "graph_print_overrun")) > - gopt_graph_print_overrun = set; > - /* invalid flage_name is omitted. */ > -} > - > -static int tracer_no_event_context; > - > -static void ftrace_show_function_graph_init(void); > -static void ftrace_show_function_init(void); > -static void ftrace_show_trace_event_init(void); > - > -static int ftrace_show_init(void) > -{ > - /* ftrace_event_get_id(), ftrace_event_get_pid() should not failed. > */ > - if (find_event_field(event_types[0], "common_type") == NULL) > - return -1; > - > - if (find_event_field(event_types[0], "common_pid") == NULL) > - return -1; > - > - ftrace_show_function_init(); > - ftrace_show_function_graph_init(); > - ftrace_show_trace_event_init(); > - > - return 0; > -} > - > -void show_event(struct format_context *fc) > -{ > - struct event_type *etype; > - int id; > - > - id = ftrace_event_get_id(fc->event.data); > - etype = find_event_type(id); > - > - if (etype == NULL) { > - event_printf("<Unknown event type> "); > - return; > - } > - > - if (!tracer_no_event_context && gopt_context_info) > - event_context_print(etype, fc); > - if (!etype->plugin) > - event_printf("%s: ", etype->name); > - etype->printer(etype, fc); > -} > - > -static int parse_cpulist(int *cpulist, const char *cpulist_str, int > len) > -{ > - unsigned a, b; > - const char *s = cpulist_str; > - > - memset(cpulist, 0, sizeof(int) * len); > - > - do { > - if (!isdigit(*s)) > - return -1; > - b = a = strtoul(s, (char **)&s, 10); > - if (*s == '-') { > - s++; > - if (!isdigit(*s)) > - return -1; > - b = strtoul(s, (char **)&s, 10); > - } > - if (!(a <= b)) > - return -1; > - if (b >= len) > - return -1; > - while (a <= b) { > - cpulist[a] = 1; > - a++; > - } > - if (*s == ',') > - s++; > - } while (*s != ' ' && *s != ' '); > - > - return 0; > -} > - > -static void ftrace_show_function_graph_start(void); > - > -static void ftrace_show(int argc, char *argv[]) > -{ > - int c; > - int *cpulist = NULL; > - > - set_all_flags_default(); > - ftrace_show_function_graph_start(); > - > - while ((c = getopt(argc, argv, "f:c:")) != EOF) { > - switch(c) > - { > - case 'f': > - if (optarg[0] == 'n' && optarg[1] == 'o') > - set_clear_flag(optarg + 2, 0); > - else > - set_clear_flag(optarg, 1); > - break; > - case 'c': > - if (cpulist) > - goto err_arg; > - > - cpulist = malloc(sizeof(int) * nr_cpu_ids); > - if (cpulist == NULL) { > - error(INFO, "malloc() fail "); > - return; > - } > - > - if (parse_cpulist(cpulist, optarg, nr_cpu_ids) < 0) > - goto err_arg; > - break; > - default: > - goto err_arg; > - } > - } > - > - if (argc - optind != 0) { > -err_arg: > - cmd_usage(pc->curcmd, SYNOPSIS); > - free(cpulist); > - return; > - } > - > - ring_buffer_stream_init(&format_context.stream, cpulist); > - > - /* Ignore setjmp()'s return value, no special things to do. */ > - setjmp(show_event_env); > - > - for (;;) { > - show_event_pos = 0; > - format_context.cpu = ring_buffer_stream_pop_event( > - &format_context.stream, &format_context.event); > - if (format_context.cpu < 0) > - break; > - > - show_event(&format_context); > - fprintf(fp, "%s", show_event_buf); > - } > - > - ring_buffer_stream_destroy(&format_context.stream, cpulist); > - free(cpulist); > + pclose(file); > +out: > + close(fd); > + unlink(tmp); > + return; > } > > static void cmd_ftrace(void) > @@ -2217,729 +1478,12 @@ static void cmd_ftrace(void) > ftrace_dump(argcnt - 1, args + 1); > else if (!strcmp(args[1], "show")) > ftrace_show(argcnt - 1, args + 1); > + else if (!strcmp(args[1], "report")) > + ftrace_show(argcnt - 1, args + 1); > else > cmd_usage(pc->curcmd, SYNOPSIS); > } > > -static void event_default_print(struct event_type *t, struct > format_context *fc) > -{ > - int i; > - > - /* Skip the common types */ > - for (i = t->nfields - 6; i >= 0; i--) { > - struct ftrace_field *f; > - > - f = &t->fields[i]; > - event_printf("%s=", f->name); > - event_field_print(f, fc->event.data); > - if (i) > - event_printf(", "); > - } > - > - event_printf(" "); > -} > - > -static void sym_print(ulong sym, int opt_offset) > -{ > - if (!sym) { > - event_printf("0"); > - } else { > - ulong offset; > - struct syment *se; > - > - se = value_search(sym, &offset); > - if (se) { > - event_printf("%s", se->name); > - if (opt_offset) > - event_printf("+%lu", offset); > - } > - } > -} > - > -static void event_fn_print(struct event_type *t, struct > format_context *fc) > -{ > - unsigned long ip = access_field(t, fc->event.data, "ip"); > - unsigned long parent_ip = access_field(t, fc->event.data, > "parent_ip"); > - > - sym_print(ip, gopt_sym_offset); > - if (gopt_sym_addr) > - event_printf("<%lx>", ip); > - > - event_printf(" <-"); > - > - sym_print(parent_ip, gopt_sym_offset); > - if (gopt_sym_addr) > - event_printf("<%lx>", parent_ip); > - > - event_printf(" "); > -} > - > -static void ftrace_show_function_init(void) > -{ > - struct event_type *t = find_event_type_by_name("ftrace", > "function"); > - > - if (t) > - t->printer = event_fn_print; > -} > - > -#if 0 > -/* simple */ > -static void event_fn_entry_print(struct event_type *t, struct > format_context *fc) > -{ > - ulong func = access_field(t, fc->event.data, "graph_ent.func"); > - int depth = access_field(t, fc->event.data, "graph_ent.depth"); > - > - event_printf("%*s", depth, " "); > - sym_print(func, gopt_sym_offset); > - if (gopt_sym_addr) > - event_printf("<%lx>", func); > - event_printf("() {"); > -} > - > -static void event_fn_return_print(struct event_type *t, struct > format_context *fc) > -{ > - ulong func = access_field(t, fc->event.data, "ret.func"); > - u64 calltime = access_field(t, fc->event.data, "ret.calltime"); > - u64 rettime = access_field(t, fc->event.data, "ret.rettime"); > - int depth = access_field(t, fc->event.data, "ret.depth"); > - > - event_printf("%*s} %lluns", depth, " ", > - (unsigned long long)(rettime - calltime)); > -} > - > -static void ftrace_show_function_graph_init(void) > -{ > - struct event_type *t1 = find_event_type_by_name( > - "ftrace", "funcgraph_entry"); > - struct event_type *t2 = find_event_type_by_name( > - "ftrace", "funcgraph_exit"); > - > - if (t1 == NULL || t2 == NULL) > - return; > - > - t1->printer = event_fn_entry_print; > - t2->printer = event_fn_return_print; > -} > -#endif > - > - > -#define TRACE_GRAPH_PROCINFO_LENGTH 14 > -#define TRACE_GRAPH_INDENT 2 > - > -static int max_bytes_for_cpu; > -static int *cpus_prev_pid; > - > -static int function_graph_entry_id; > -static int function_graph_return_id; > -static struct event_type *function_graph_entry_type; > -static struct event_type *function_graph_return_type; > - > -static void ftrace_show_function_graph_start(void) > -{ > - int i; > - > - if (cpus_prev_pid == NULL) > - return; > - > - for (i = 0; i < nr_cpu_ids; i++) > - cpus_prev_pid[i] = -1; > -} > - > -static void fn_graph_proc_print(int pid) > -{ > - int pid_strlen, comm_strlen; > - char pid_str[20]; > - char comm[20] = "<...>"; > - > - pid_strlen = sprintf(pid_str, "%d", pid); > - comm_strlen = TRACE_GRAPH_PROCINFO_LENGTH - 1 - pid_strlen; > - > - get_comm_from_pid(pid, comm); > - event_printf("%*.*s-%s", comm_strlen, comm_strlen, comm, pid_str); > -} > - > -/* If the pid changed since the last trace, output this event */ > -static void fn_graph_proc_switch_print(int pid, int cpu) > -{ > - int prev_pid = cpus_prev_pid[cpu]; > - > - cpus_prev_pid[cpu] = pid; > - if ((prev_pid == pid) || (prev_pid == -1)) > - return; > - > -/* > - * Context-switch trace line: > - > - ------------------------------------------ > - | 1) migration/0--1 => sshd-1755 > - ------------------------------------------ > - > - */ > - > - event_printf(" ------------------------------------------ "); > - event_printf(" %*d) ", max_bytes_for_cpu, cpu); > - fn_graph_proc_print(prev_pid); > - event_printf(" => "); > - fn_graph_proc_print(pid); > - event_printf(" ------------------------------------------ "); > -} > - > -/* Signal a overhead of time execution to the output */ > -static void fn_graph_overhead_print(unsigned long long duration) > -{ > - const char *s = " "; > - > - /* If duration disappear, we don't need anything */ > - if (!gopt_graph_print_duration) > - return; > - > - /* duration == -1 is for non nested entry or return */ > - if ((duration != -1) && gopt_graph_print_overhead) { > - /* Duration exceeded 100 msecs */ > - if (duration > 100000ULL) > - s = "! "; > - /* Duration exceeded 10 msecs */ > - else if (duration > 10000ULL) > - s = "+ "; > - } > - > - event_printf(s); > -} > - > -static void fn_graph_abstime_print(u64 ts) > -{ > - u64 time = ts / 1000; > - unsigned long sec = time / 1000000; > - unsigned long usec = time % 1000000; > - > - event_printf("%5lu.%06lu | ", sec, usec); > -} > - > -static void fn_graph_irq_print(int type) > -{ > - /* TODO: implement it. */ > -} > - > -static void fn_graph_duration_print(unsigned long long duration) > -{ > - /* log10(ULONG_MAX) + ' ' */ > - char msecs_str[21]; > - char nsecs_str[5]; > - int len; > - unsigned long nsecs_rem = duration % 1000; > - > - duration = duration / 1000; > - len = sprintf(msecs_str, "%lu", (unsigned long) duration); > - > - /* Print msecs */ > - event_printf("%s", msecs_str); > - > - /* Print nsecs (we don't want to exceed 7 numbers) */ > - if (len < 7) { > - snprintf(nsecs_str, 8 - len, "%03lu", nsecs_rem); > - event_printf(".%s", nsecs_str); > - > - len += strlen(nsecs_str); > - } > - > - if (len > 7) > - len = 7; > - > - event_printf(" us %*s| ", 7 - len, ""); > -} > - > -/* Case of a leaf function on its call entry */ > -static void fn_graph_entry_leaf_print(void *entry_data, void > *exit_data) > -{ > - struct event_type *t = function_graph_return_type; > - > - u64 calltime = access_field(t, exit_data, "ret.calltime"); > - u64 rettime = access_field(t, exit_data, "ret.rettime"); > - u64 duration = rettime - calltime; > - int depth = access_field(t, exit_data, "ret.depth"); > - ulong func = access_field(t, exit_data, "ret.func"); > - > - fn_graph_overhead_print(duration); > - if (gopt_graph_print_duration) > - fn_graph_duration_print(duration); > - > - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); > - sym_print(func, 0); > - event_printf("(); "); > -} > - > -static void fn_graph_entry_nested_print(struct event_type *t, void > *data) > -{ > - int depth = access_field(t, data, "graph_ent.depth"); > - ulong func = access_field(t, data, "graph_ent.func"); > - > - fn_graph_overhead_print(-1); > - > - /* No time */ > - if (gopt_graph_print_duration) > - event_printf(" | "); > - > - event_printf("%*s", depth * TRACE_GRAPH_INDENT, ""); > - sym_print(func, 0); > - event_printf("() { "); > -} > - > -static void fn_graph_prologue_print(int cpu, u64 ts, int pid, int > type) > -{ > - fn_graph_proc_switch_print(pid, cpu); > - > - if (type) > - fn_graph_irq_print(type); > - > - if (gopt_graph_print_abstime) > - fn_graph_abstime_print(ts); > - > - if (gopt_graph_print_cpu) > - event_printf(" %*d) ", max_bytes_for_cpu, cpu); > - > - if (gopt_graph_print_proc) { > - fn_graph_proc_print(pid); > - event_printf(" | "); > - } > -} > - > -static void *get_return_for_leaf(struct event_type *t, > - struct format_context *fc, void *curr_data) > -{ > - int cpu; > - struct ftrace_event next; > - ulong entry_func, exit_func; > - > - cpu = ring_buffer_stream_pop_event(&fc->stream, &next); > - > - if (cpu < 0) > - goto not_leaf; > - > - if (ftrace_event_get_id(next.data) != function_graph_return_id) > - goto not_leaf; > - > - if (ftrace_event_get_pid(curr_data) != > ftrace_event_get_pid(next.data)) > - goto not_leaf; > - > - entry_func = access_field(t, curr_data, "graph_ent.func"); > - exit_func = access_field(function_graph_return_type, next.data, > - "ret.func"); > - > - if (entry_func != exit_func) > - goto not_leaf; > - > - return next.data; > - > -not_leaf: > - ring_buffer_stream_push_current_event(&fc->stream); > - return NULL; > -} > - > -static > -void event_fn_entry_print(struct event_type *t, struct format_context > *fc) > -{ > - void *leaf_ret_data = NULL, *curr_data = fc->event.data, *data; > - int pid = ftrace_event_get_pid(curr_data); > - > - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 1); > - > - data = alloca(fc->event.length); > - if (data) { > - memcpy(data, fc->event.data, fc->event.length); > - curr_data = data; > - leaf_ret_data = get_return_for_leaf(t, fc, curr_data); > - } > - > - if (leaf_ret_data) > - return fn_graph_entry_leaf_print(curr_data, leaf_ret_data); > - else > - return fn_graph_entry_nested_print(t, curr_data); > -} > - > -static > -void event_fn_return_print(struct event_type *t, struct > format_context *fc) > -{ > - void *data = fc->event.data; > - int pid = ftrace_event_get_pid(data); > - > - u64 calltime = access_field(t, data, "ret.calltime"); > - u64 rettime = access_field(t, data, "ret.rettime"); > - u64 duration = rettime - calltime; > - int depth = access_field(t, data, "ret.depth"); > - > - fn_graph_prologue_print(fc->cpu, fc->event.ts, pid, 0); > - fn_graph_overhead_print(duration); > - > - if (gopt_graph_print_duration) > - fn_graph_duration_print(duration); > - > - event_printf("%*s} ", depth * TRACE_GRAPH_INDENT, ""); > - > - if (gopt_graph_print_overrun) { > - unsigned long overrun = access_field(t, data, "ret.overrun"); > - event_printf(" (Overruns: %lu) ", overrun); > - } > - > - fn_graph_irq_print(0); > -} > - > -static void ftrace_show_function_graph_init(void) > -{ > - if (strcmp(current_tracer_name, "function_graph")) > - return; > - > - function_graph_entry_type = find_event_type_by_name( > - "ftrace", "funcgraph_entry"); > - function_graph_return_type = find_event_type_by_name( > - "ftrace", "funcgraph_exit"); > - > - if (!function_graph_entry_type || !function_graph_return_type) > - return; > - > - /* > - * Because of get_return_for_leaf(), the exception handling > - * of access_field() is not work for function_graph. So we need > - * to ensure access_field() will not failed for these fields. > - * > - * I know these will not failed. I just ensure it. > - */ > - > - if (!find_event_field(function_graph_entry_type, "graph_ent.func")) > - return; > - > - if (!find_event_field(function_graph_entry_type, "graph_ent.depth")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.func")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.calltime")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.rettime")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.overrun")) > - return; > - > - if (!find_event_field(function_graph_return_type, "ret.depth")) > - return; > - > - cpus_prev_pid = malloc(sizeof(int) * nr_cpu_ids); > - if (!cpus_prev_pid) > - return; > - > - max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1); > - > - function_graph_entry_id = function_graph_entry_type->id; > - function_graph_return_id = function_graph_return_type->id; > - > - /* OK, set the printer for function_graph. */ > - tracer_no_event_context = 1; > - function_graph_entry_type->printer = event_fn_entry_print; > - function_graph_return_type->printer = event_fn_return_print; > -} > - > -static void event_sched_kthread_stop_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid")); > -} > - > -static void event_sched_kthread_stop_ret_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("ret %d ", (int)access_field(t, fc->event.data, > "ret")); > -} > - > -static void event_sched_wait_task_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_wakeup_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] success=%d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio"), > - (int)access_field(t, fc->event.data, "success")); > -} > - > -static void event_sched_wakeup_new_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] success=%d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio"), > - (int)access_field(t, fc->event.data, "success")); > -} > - > -static void event_sched_switch_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *prev_comm = (char *)(long)access_field(t, fc->event.data, > - "prev_comm"); > - int prev_pid = access_field(t, fc->event.data, "prev_pid"); > - int prev_prio = access_field(t, fc->event.data, "prev_prio"); > - > - int prev_state = access_field(t, fc->event.data, "prev_state"); > - > - char *next_comm = (char *)(long)access_field(t, fc->event.data, > - "next_comm"); > - int next_pid = access_field(t, fc->event.data, "next_pid"); > - int next_prio = access_field(t, fc->event.data, "next_prio"); > - > - event_printf("task %s:%d [%d] (", prev_comm, prev_pid, prev_prio); > - > - if (prev_state == 0) { > - event_printf("R"); > - } else { > - if (prev_state & 1) > - event_printf("S"); > - if (prev_state & 2) > - event_printf("D"); > - if (prev_state & 4) > - event_printf("T"); > - if (prev_state & 8) > - event_printf("t"); > - if (prev_state & 16) > - event_printf("Z"); > - if (prev_state & 32) > - event_printf("X"); > - if (prev_state & 64) > - event_printf("x"); > - if (prev_state & 128) > - event_printf("W"); > - } > - > - event_printf(") ==> %s:%d [%d] ", next_comm, next_pid, next_prio); > -} > - > -static void event_sched_migrate_task_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] from: %d to: %d ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio"), > - (int)access_field(t, fc->event.data, "orig_cpu"), > - (int)access_field(t, fc->event.data, "dest_cpu")); > -} > - > -static void event_sched_process_free_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_process_exit_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_process_wait_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("task %s:%d [%d] ", > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid"), > - (int)access_field(t, fc->event.data, "prio")); > -} > - > -static void event_sched_process_fork_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *parent_comm = (char *)(long)access_field(t, fc->event.data, > - "parent_comm"); > - int parent_pid = access_field(t, fc->event.data, "parent_pid"); > - > - char *child_comm = (char *)(long)access_field(t, fc->event.data, > - "child_comm"); > - int child_pid = access_field(t, fc->event.data, "child_pid"); > - > - event_printf("parent %s:%d child %s:%d ", parent_comm, parent_pid, > - child_comm, child_pid); > -} > - > -static void event_sched_signal_send_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("sig: %d task %s:%d ", > - (int)access_field(t, fc->event.data, "sig"), > - (char *)(long)access_field(t, fc->event.data, "comm"), > - (int)access_field(t, fc->event.data, "pid")); > -} > - > -static void event_kmalloc_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags")); > -} > - > -static void event_kmem_cache_alloc_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags")); > -} > - > -static void event_kmalloc_node_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx node=%d ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags"), > - (int)access_field(t, fc->event.data, "node")); > -} > - > -static void event_kmem_cache_alloc_node_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p bytes_req=%zu bytes_alloc=%zu " > - "gfp_flags=%lx node=%d ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr"), > - (size_t)access_field(t, fc->event.data, "bytes_req"), > - (size_t)access_field(t, fc->event.data, "bytes_alloc"), > - (long)access_field(t, fc->event.data, "gfp_flags"), > - (int)access_field(t, fc->event.data, "node")); > -} > - > -static void event_kfree_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr")); > -} > - > -static void event_kmem_cache_free_print(struct event_type *t, > - struct format_context *fc) > -{ > - event_printf("call_site=%lx ptr=%p ", > - (long)access_field(t, fc->event.data, "call_site"), > - (void *)(long)access_field(t, fc->event.data, "ptr")); > -} > - > -static void event_workqueue_insertion_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - ulong func = access_field(t, fc->event.data, "func"); > - > - event_printf("thread=%s:%d func=", thread_comm, thread_pid); > - sym_print(func, 1); > - event_printf(" "); > -} > - > -static void event_workqueue_execution_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - ulong func = access_field(t, fc->event.data, "func"); > - > - event_printf("thread=%s:%d func=", thread_comm, thread_pid); > - sym_print(func, 1); > - event_printf(" "); > -} > - > -static void event_workqueue_creation_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - int cpu = access_field(t, fc->event.data, "cpu"); > - > - event_printf("thread=%s:%d cpu=%d ", thread_comm, thread_pid, cpu); > -} > - > -static void event_workqueue_destruction_print(struct event_type *t, > - struct format_context *fc) > -{ > - char *thread_comm = (char *)(long)access_field(t, fc->event.data, > - "thread_comm"); > - int thread_pid = access_field(t, fc->event.data, "thread_pid"); > - > - event_printf("thread=%s:%d ", thread_comm, thread_pid); > -} > - > -static void ftrace_show_trace_event_init(void) > -{ > -#define init_trace_event(system, name) > -do { > - struct event_type *t = find_event_type_by_name(#system, #name); > - if (t) > - t->printer = event_ ## name ## _print; > -} while (0) > - > - init_trace_event(sched, sched_kthread_stop); > - init_trace_event(sched, sched_kthread_stop_ret); > - init_trace_event(sched, sched_wait_task); > - init_trace_event(sched, sched_wakeup); > - init_trace_event(sched, sched_wakeup_new); > - init_trace_event(sched, sched_switch); > - init_trace_event(sched, sched_migrate_task); > - init_trace_event(sched, sched_process_free); > - init_trace_event(sched, sched_process_exit); > - init_trace_event(sched, sched_process_wait); > - init_trace_event(sched, sched_process_fork); > - init_trace_event(sched, sched_signal_send); > - > - init_trace_event(kmem, kmalloc); > - init_trace_event(kmem, kmem_cache_alloc); > - init_trace_event(kmem, kmalloc_node); > - init_trace_event(kmem, kmem_cache_alloc_node); > - init_trace_event(kmem, kfree); > - init_trace_event(kmem, kmem_cache_free); > - > - init_trace_event(workqueue, workqueue_insertion); > - init_trace_event(workqueue, workqueue_execution); > - init_trace_event(workqueue, workqueue_creation); > - init_trace_event(workqueue, workqueue_destruction); > -#undef init_trace_event > -} > - > -static void ftrace_show_destroy(void) > -{ > - free(cpus_prev_pid); > -} > - > static char *help_ftrace[] = { > "trace", > "show or dump the tracing info", > @@ -2947,22 +1491,11 @@ static char *help_ftrace[] = { > "trace", > " shows the current tracer and other informations.", > "", > -"trace show [ -c <cpulist> ] [ -f [no]<flagname> ]", > +"trace show", > " shows all events with readability text(sorted by timestamp)", > -" -c: only shows specified CPUs' events.", > -" ex. trace show -c 1,2 - only shows cpu#1 and cpu#2 's events.", > -" trace show -c 0,2-7 - only shows cpu#0, cpu#2...cpu#7's events.", > -" -f: set or clear a flag", > -" available flags default", > -" context_info true", > -" sym_offset false", > -" sym_addr false", > -" graph_print_duration true", > -" graph_print_overhead true", > -" graph_print_abstime false", > -" graph_print_cpu true", > -" graph_print_proc false", > -" graph_print_overrun false", > +"", > +"trace report", > +" the same as "trace show"", > "", > "trace dump [-sm] <dest-dir>", > " dump ring_buffers to dest-dir. Then you can parse it", -- Crash-utility mailing list Crash-utility@redhat.com https://www.redhat.com/mailman/listinfo/crash-utility |
trace: Improve "trace show" command
On 03/23/2011 10:37 PM, Dave Anderson wrote:
> > > ----- Original Message ----- >> On 03/03/2011 11:25 PM, Dave Anderson wrote: >>> >>> >>> ----- Original Message ----- >>>> The code were also applied to: >>>> git://github.com/laijs/tracing-extension-module-for-crash.git >>>> >>>> Documents and man pages will/may be added in two weeks. >>>> >>>> Dave Anderson, could you add a "Requires" entry to its RPM.spec, >>>> it requires trace-cmd RPM after this patch applied. >> >> Sorry, please omit this requirement of mine. > > That actually would be a legitimate request for the RHEL6 crash-trace-command > package, but I'd prefer not to add a Requires entry for the upstream src.rpm. > > But I note in your new patch, that ftrace_show() is a void function, and > if the popen("trace.cmd") fails, it just returns quietly. I would think > that there should be an explanatory error message in that case? Also, > there's a buffer overflow error assignment to buf[4097]: > > static void ftrace_show(int argc, char *argv[]) > { > char buf[4096]; > char tmp[] = "/tmp/crash.trace_dat.XXXXXX"; > char *trace_cmd = "trace-cmd", *env_trace_cmd = getenv("TRACE_CMD"); > int fd; > FILE *file; > size_t ret; > > /* check trace-cmd */ > if (env_trace_cmd) > trace_cmd = env_trace_cmd; > if (!(file = popen(trace_cmd, "r"))) > return; > ret = fread(buf, 1, sizeof(buf), file); > buf[4097] = 0; > if (!strstr(buf, "trace-cmd version")) { > if (env_trace_cmd) > fprintf(fp, "Invalid environment TRACE_CMD: %s ", > env_trace_cmd); > else > fprintf(fp, ""trace show" requires trace-cmd. " > "please set the environment TRACE_CMD " > "if you installed it a special path " > ); > return; > } > > So if you don't mind, I'll fix it like this: > > buf[0] = 0; > if ((file = popen(trace_cmd, "r"))) { > ret = fread(buf, 1, sizeof(buf), file); > buf[4095] = 0; > } It seems better: if (...) { ret = fread(buf, 1, sizeof(buf) - 1, file); buf[ret] = 0; } > if (!strstr(buf, "trace-cmd version")) { > if (env_trace_cmd) > fprintf(fp, "Invalid environment TRACE_CMD: %s ", > env_trace_cmd); > else > fprintf(fp, ""trace show" requires trace-cmd. " > "please set the environment TRACE_CMD " > "if you installed it in a special path " > ); > return; > } > > If that's OK with you, the patch is queued for crash 5.1.4. > OK with me, thanks, Lai. -- Crash-utility mailing list Crash-utility@redhat.com https://www.redhat.com/mailman/listinfo/crash-utility |
trace: Improve "trace show" command
----- Original Message -----
> On 03/23/2011 10:37 PM, Dave Anderson wrote: > > So if you don't mind, I'll fix it like this: > > > > buf[0] = 0; > > if ((file = popen(trace_cmd, "r"))) { > > ret = fread(buf, 1, sizeof(buf), file); > > buf[4095] = 0; > > } > > It seems better: > if (...) { > ret = fread(buf, 1, sizeof(buf) - 1, file); > buf[ret] = 0; > } Even better -- applied as above, and queued for crash-5.1.4. Thanks Lai and Steve, Dave -- Crash-utility mailing list Crash-utility@redhat.com https://www.redhat.com/mailman/listinfo/crash-utility |
| All times are GMT. The time now is 09:53 AM. |
VBulletin, Copyright ©2000 - 2013, Jelsoft Enterprises Ltd.
Content Relevant URLs by vBSEO ©2007, Crawlability, Inc.