[ANNOUNCE][RFC][PATCH] Crash-utility, tracing: enable crash to analyze tracing from core-file (make tracing can act as a flight recorder)
by Lai Jiangshan
We use tracing subsystem very well when kernel is alive.
But we also want to get help from tracing when kernel is core-dump.
This patch is for this purpose. It makes tracing can act as a
flight recorder, we can find what have happen from the events.
This patch is applied for crash-4.0-8.8.
It was tested for linux version 2.6.31-rc5-tip-00972-gd84b9d2 on i386.
The codes is not mature, comments are welcome.
And any request is welcome, it will be added to my plan.
Lai.
crash> help trace
NAME
trace - show or dump the tracing info
SYNOPSIS
trace [ <show [-c <cpulist>] [-f [no]<flagname>]> | <dump [-sm] <dest-dir>> ]
DESCRIPTION
trace
shows the current tracer and other informations.
trace show [ -c <cpulist> ] [ -f [no]<flagename> ]
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 dump [-sm] <dest-dir>
dump ring_buffers to dest-dir. Then you can parse it
by other tracing tools. The dirs and files are generated
the same as debugfs/tracing.
-m: also dump metadata of ftrace.
-s: also dump symbols of the kernel <not implemented>.
EXAMPLE, dump ring_buffer:
crash > trace dump -m dumped_tracing
(quit crash)
# ls -R dumped_tracing
dumped_tracing:
events per_cpu saved_cmdlines
dumped_tracing/events:
block ftrace irq kmem sched skb workqueue
dumped_tracing/events/block:
block_bio_backmerge block_bio_frontmerge block_plug block_rq_complete block_rq_requeue block_unplug_io
block_bio_bounce block_bio_queue block_remap block_rq_insert block_sleeprq block_unplug_timer
block_bio_complete block_getrq block_rq_abort block_rq_issue block_split
dumped_tracing/events/block/block_bio_backmerge:
format
dumped_tracing/events/block/block_bio_bounce:
format
....
dumped_tracing/per_cpu:
cpu0 cpu1
dumped_tracing/per_cpu/cpu0:
trace_pipe_raw
dumped_tracing/per_cpu/cpu1:
trace_pipe_raw
EXAMPLE, shows function tracer
crash > trace show
<...>-3677 [001] 6094.628402: pick_next_task_fair <-schedule
<...>-3677 [001] 6094.628403: pick_next_task_rt <-schedule
<...>-3677 [001] 6094.628404: pick_next_task_fair <-schedule
<...>-3677 [001] 6094.628405: pick_next_task_idle <-schedule
<...>-3677 [001] 6094.628406: calc_load_account_active <-pick_next_task_idle
<...>-3677 [001] 6094.628407: perf_counter_task_sched_out <-schedule
<swapper>-0 [001] 6094.628437: finish_task_switch <-schedule
<swapper>-0 [001] 6094.628438: perf_counter_task_sched_in <-finish_task_switch
<swapper>-0 [001] 6094.628439: _spin_unlock_irq <-finish_task_switch
<swapper>-0 [001] 6094.628440: kretprobe_table_lock_ptr <-kretprobe_table_lock
<swapper>-0 [001] 6094.628442: _spin_lock_irqsave <-kretprobe_table_lock
....
bash-3580 [000] 6119.756585: native_apic_mem_read <-default_get_apic_id
bash-3580 [000] 6119.756616: crash_save_cpu <-native_machine_crash_shutdown
bash-3580 [000] 6119.756687: append_elf_note <-crash_save_cpu
bash-3580 [000] 6119.756688: strlen <-append_elf_note
bash-3580 [000] 6119.756712: final_note <-crash_save_cpu
bash-3580 [000] 6119.756776: machine_kexec <-crash_kexec
bash-3580 [000] 6119.756824: page_address <-machine_kexec
EXAMPLE, shows function_graph tracer
crash > trace show
1) 1.187 us | }
1) | hrtimer_forward() {
1) 1.018 us | ktime_add_safe();
1) 0.953 us | ktime_add_safe();
1) 5.419 us | }
1) + 87.322 us | }
1) 1.028 us | _spin_lock();
1) 1.779 us | enqueue_hrtimer();
1) ! 100.743 us | }
1) 1.043 us | _spin_unlock();
1) | tick_program_event() {
1) | tick_dev_program_event() {
1) 1.148 us | ktime_get();
EXAMPLE, shows various events
crash > trace show
<swapper>-0 [001] 9349.585217: softirq_exit: vec=1
<swapper>-0 [001] 9349.585218: softirq_entry: vec=8
<swapper>-0 [001] 9349.585226: kmem_cache_free: call_site=c015a221 ptr=0xcfb16200
<swapper>-0 [001] 9349.585228: kmem_cache_free: call_site=c0151c32 ptr=0xcfb438c0
<swapper>-0 [001] 9349.585230: sched_process_free: task dhclient-script:3749 [120]
<swapper>-0 [001] 9349.585237: kfree: call_site=c017f13a ptr=(nil)
<swapper>-0 [001] 9349.585239: kmem_cache_free: call_site=c013b8f1 ptr=0xcf056ed0
<swapper>-0 [001] 9349.585241: softirq_exit: vec=8
<...>-3752 [000] 9349.585717: kmem_cache_alloc: call_site=c01b6a34 ptr=0xcf2c50b0 bytes_req=88 bytes_alloc=88 gfp_flags=80d0
<...>-3752 [000] 9349.585732: kmem_cache_alloc: call_site=c01b95fa ptr=0xcf2c61e0 bytes_req=12 bytes_alloc=16 gfp_flags=d0
Signed-off-by: Lai Jiangshan <laijs(a)cn.fujitsu.com>
---
diff --git a/Makefile b/Makefile
index 4996cb2..a14ecc3 100644
--- a/Makefile
+++ b/Makefile
@@ -97,7 +97,7 @@ OBJECT_FILES=main.o tools.o global_data.o memory.o filesys.o help.o task.o \
lkcd_x86_trace.o unwind_v1.o unwind_v2.o unwind_v3.o \
unwind_x86_32_64.o \
xen_hyper.o xen_hyper_command.o xen_hyper_global_data.o \
- xen_hyper_dump_tables.o
+ xen_hyper_dump_tables.o ftrace.o
# These are the current set of crash extensions sources. They are not built
# by default unless the third command line of the "all:" stanza is uncommented.
diff --git a/defs.h b/defs.h
index 1b0950e..3bb54eb 100755
--- a/defs.h
+++ b/defs.h
@@ -512,6 +512,7 @@ struct kernel_table { /* kernel data */
uint kernel_version[3];
uint gcc_version[3];
int runq_siblings;
+ int nr_cpu_ids;
int kernel_NR_CPUS;
long __per_cpu_offset[NR_CPUS];
long *__rq_idx;
@@ -3091,6 +3092,7 @@ void cmd_sys(void); /* kernel.c */
void cmd_irq(void); /* kernel.c */
void cmd_timer(void); /* kernel.c */
void cmd_waitq(void); /* kernel.c */
+void cmd_ftrace(void); /* ftrace.c */
void cmd_sym(void); /* symbols.c */
void cmd_struct(void); /* symbols.c */
void cmd_union(void); /* symbols.c */
@@ -3272,6 +3274,8 @@ int endian_mismatch(char *, char, ulong);
uint16_t swap16(uint16_t, int);
uint32_t swap32(uint32_t, int);
+void ftrace_init(void);
+
/*
* symbols.c
*/
@@ -3526,6 +3530,7 @@ extern char *help_repeat[];
extern char *help_runq[];
extern char *help_search[];
extern char *help_set[];
+extern char *help_ftrace[];
extern char *help_sig[];
extern char *help_struct[];
extern char *help_swap[];
diff --git a/ftrace.c b/ftrace.c
new file mode 100644
index 0000000..febcd05
--- /dev/null
+++ b/ftrace.c
@@ -0,0 +1,2161 @@
+#define _GNU_SOURCE
+#include "defs.h"
+#include <stdio.h>
+#include <ctype.h>
+#include <stdbool.h>
+#include <setjmp.h>
+
+/* TODO: use more correct way to handle the return value of readmem() */
+
+static int verbose = 0;
+
+/*
+ * lockless ring_buffer and old non-lockless ring_buffer are both supported.
+ */
+#define koffset(struct, member) struct##_##member##_offset
+
+static int ftrace_initialized;
+static int ftrace_no_ftrace;
+
+static int koffset(trace_array, buffer);
+static int koffset(tracer, name);
+
+static int lockless_ring_buffer;
+
+static int koffset(ring_buffer, pages);
+static int koffset(ring_buffer, flags);
+static int koffset(ring_buffer, cpus);
+static int koffset(ring_buffer, buffers);
+
+static int koffset(ring_buffer_per_cpu, cpu);
+static int koffset(ring_buffer_per_cpu, pages);
+static int koffset(ring_buffer_per_cpu, head_page);
+static int koffset(ring_buffer_per_cpu, tail_page);
+static int koffset(ring_buffer_per_cpu, commit_page);
+static int koffset(ring_buffer_per_cpu, reader_page);
+static int koffset(ring_buffer_per_cpu, overrun);
+static int koffset(ring_buffer_per_cpu, entries);
+
+static int koffset(buffer_page, read);
+static int koffset(buffer_page, list);
+static int koffset(buffer_page, page);
+
+static int koffset(list_head, next);
+
+static int koffset(ftrace_event_call, list);
+static int koffset(ftrace_event_call, name);
+static int koffset(ftrace_event_call, system);
+static int koffset(ftrace_event_call, id);
+static int koffset(ftrace_event_call, fields);
+
+static int koffset(ftrace_event_field, link);
+static int koffset(ftrace_event_field, name);
+static int koffset(ftrace_event_field, type);
+static int koffset(ftrace_event_field, offset);
+static int koffset(ftrace_event_field, size);
+static int koffset(ftrace_event_field, is_signed);
+
+static int koffset(POINTER_SYM, POINTER) = 0;
+
+struct ring_buffer_per_cpu {
+ ulong kaddr;
+
+ ulong head_page;
+ ulong tail_page;
+ ulong commit_page;
+ ulong reader_page;
+ ulong real_head_page;
+
+ ulong *pages;
+ int head_page_index;
+
+ ulong overrun;
+ ulong entries;
+};
+
+static ulong global_trace;
+static ulong max_tr_trace;
+
+static ulong global_ring_buffer;
+static ulong max_tr_ring_buffer;
+
+static unsigned global_pages;
+static unsigned max_tr_pages;
+
+static struct ring_buffer_per_cpu *global_buffers;
+static struct ring_buffer_per_cpu *max_tr_buffers;
+
+static ulong ftrace_events;
+static ulong current_trace;
+static const char *current_trace_name;
+
+static void *page_tmp;
+
+/* at = ((struct *)ptr)->member */
+#define read_value(at, ptr, struct, member) \
+ do { \
+ if (!readmem(ptr + koffset(struct, member), KVADDR, \
+ &at, sizeof(at), #struct " " #member, \
+ RETURN_ON_ERROR | QUIET)) \
+ error(FATAL, "cannot read value, ptr%lu, %d\n", ptr, __LINE__);\
+ } while (0)
+
+static void init_offsets(void)
+{
+#define init_offset(struct, member) koffset(struct, member) \
+ = MEMBER_OFFSET(#struct, #member);
+
+ init_offset(trace_array, buffer);
+ init_offset(tracer, name);
+
+ init_offset(ring_buffer, pages);
+ init_offset(ring_buffer, flags);
+ init_offset(ring_buffer, cpus);
+ init_offset(ring_buffer, buffers);
+
+ if (MEMBER_SIZE("ring_buffer_per_cpu", "pages") == sizeof(ulong)) {
+ lockless_ring_buffer = 1;
+ if (verbose)
+ fprintf(fp, "lockless\n");
+ }
+
+ init_offset(ring_buffer_per_cpu, cpu);
+ init_offset(ring_buffer_per_cpu, pages);
+ init_offset(ring_buffer_per_cpu, head_page);
+ init_offset(ring_buffer_per_cpu, tail_page);
+ init_offset(ring_buffer_per_cpu, commit_page);
+ init_offset(ring_buffer_per_cpu, reader_page);
+ init_offset(ring_buffer_per_cpu, overrun);
+ init_offset(ring_buffer_per_cpu, entries);
+
+ init_offset(buffer_page, read);
+ init_offset(buffer_page, list);
+ init_offset(buffer_page, page);
+
+ init_offset(list_head, next);
+
+ init_offset(ftrace_event_call, list);
+ init_offset(ftrace_event_call, name);
+ init_offset(ftrace_event_call, system);
+ init_offset(ftrace_event_call, id);
+ init_offset(ftrace_event_call, fields);
+
+ init_offset(ftrace_event_field, link);
+ init_offset(ftrace_event_field, name);
+ init_offset(ftrace_event_field, type);
+ init_offset(ftrace_event_field, offset);
+ init_offset(ftrace_event_field, size);
+ init_offset(ftrace_event_field, is_signed);
+#undef init_offset
+}
+
+static void print_offsets(void)
+{
+ if (!verbose)
+ return;
+
+#define print_offset(struct, member) fprintf(fp, \
+ "koffset(" #struct ", " #member ") = %d\n", koffset(struct, member))
+
+ print_offset(trace_array, buffer);
+ print_offset(tracer, name);
+
+ print_offset(ring_buffer, pages);
+ print_offset(ring_buffer, flags);
+ print_offset(ring_buffer, cpus);
+ print_offset(ring_buffer, buffers);
+
+ print_offset(ring_buffer_per_cpu, cpu);
+ print_offset(ring_buffer_per_cpu, pages);
+ print_offset(ring_buffer_per_cpu, head_page);
+ print_offset(ring_buffer_per_cpu, tail_page);
+ print_offset(ring_buffer_per_cpu, commit_page);
+ print_offset(ring_buffer_per_cpu, reader_page);
+ print_offset(ring_buffer_per_cpu, overrun);
+ print_offset(ring_buffer_per_cpu, entries);
+
+ print_offset(buffer_page, read);
+ print_offset(buffer_page, list);
+ print_offset(buffer_page, page);
+
+ print_offset(list_head, next);
+
+ print_offset(ftrace_event_call, list);
+ print_offset(ftrace_event_call, name);
+ print_offset(ftrace_event_call, system);
+ print_offset(ftrace_event_call, id);
+ print_offset(ftrace_event_call, fields);
+
+ print_offset(ftrace_event_field, link);
+ print_offset(ftrace_event_field, name);
+ print_offset(ftrace_event_field, type);
+ print_offset(ftrace_event_field, offset);
+ print_offset(ftrace_event_field, size);
+ print_offset(ftrace_event_field, is_signed);
+#undef print_offset
+}
+
+static void ftrace_init_pages(struct ring_buffer_per_cpu *cpu_buffer,
+ unsigned nr_pages)
+{
+ unsigned j;
+ ulong head, page;
+ ulong real_head_page = cpu_buffer->head_page;
+
+
+ j = 0;
+ cpu_buffer->pages = calloc(sizeof(ulong), nr_pages);
+
+ if (lockless_ring_buffer) {
+ read_value(head, cpu_buffer->kaddr, ring_buffer_per_cpu, pages);
+ cpu_buffer->pages[j++] = head - koffset(buffer_page, list);
+ } else
+ head = cpu_buffer->kaddr + koffset(ring_buffer_per_cpu, pages);
+
+ page = head;
+ for (;;) {
+ read_value(page, page, list_head, next);
+ if (page & 3) {
+ /* lockless_ring_buffer */
+ page &= ~3;
+ real_head_page = page - koffset(buffer_page, list);
+ }
+
+ if (j == nr_pages)
+ break;
+
+ if (page == head)
+ error(FATAL, "pages 1\n");
+
+ cpu_buffer->pages[j++] = page - koffset(buffer_page, list);
+ }
+
+ if (page != head)
+ error(FATAL, "pages 2\n");
+
+ cpu_buffer->real_head_page = real_head_page;
+ cpu_buffer->head_page_index = -1;
+
+ for (j = 0; j < nr_pages; j++) {
+ if (cpu_buffer->pages[j] == real_head_page) {
+ cpu_buffer->head_page_index = j;
+ break;
+ }
+ }
+
+ if (cpu_buffer->head_page_index == -1)
+ error(FATAL, "error for resolve head_page_index\n");
+}
+
+static void ftrace_init_buffers(struct ring_buffer_per_cpu *buffers,
+ ulong ring_buffer, unsigned pages)
+{
+ int i;
+ ulong buffers_array;
+ ulong *tmp = calloc(sizeof(ulong), kt->nr_cpu_ids);
+
+ read_value(buffers_array, ring_buffer, ring_buffer, buffers);
+
+ if (!readmem(buffers_array, KVADDR, tmp, sizeof(ulong) * kt->nr_cpu_ids,
+ "ring_buffer, buffers, array", RETURN_ON_ERROR|QUIET))
+ error(FATAL, "cannot read ring_buffer's buffers-array\n");
+
+ for (i = 0; i < kt->nr_cpu_ids; i++) {
+ if (!tmp[i])
+ continue;
+
+ buffers[i].kaddr = tmp[i];
+
+#define buffer_read_value(member) read_value(buffers[i].member, \
+ buffers[i].kaddr, ring_buffer_per_cpu, member)
+
+ buffer_read_value(head_page);
+ buffer_read_value(tail_page);
+ buffer_read_value(commit_page);
+ buffer_read_value(reader_page);
+ buffer_read_value(overrun);
+ buffer_read_value(entries);
+#undef buffer_read_value
+
+ ftrace_init_pages(buffers + i, pages);
+
+ if (verbose) {
+ fprintf(fp, "overrun=%lu\n", buffers[i].overrun);
+ fprintf(fp, "entries=%lu\n", buffers[i].entries);
+ }
+ }
+
+ free(tmp);
+}
+
+static void ftrace_init_event_types(void);
+static void ftrace_show_init(void);
+
+void ftrace_init(void)
+{
+ ulong addr;
+ char tmp[128];
+
+ if (!symbol_exists("global_trace")) {
+ ftrace_no_ftrace = 1;
+ ftrace_initialized = 1;
+ return;
+ }
+
+ global_trace = symbol_value("global_trace");
+ max_tr_trace = symbol_value("global_trace");
+
+ init_offsets();
+ print_offsets();
+
+ read_value(global_ring_buffer, global_trace, trace_array, buffer);
+ read_value(max_tr_ring_buffer, max_tr_trace, trace_array, buffer);
+
+ read_value(global_pages, global_ring_buffer, ring_buffer, pages);
+ read_value(max_tr_pages, max_tr_ring_buffer, ring_buffer, pages);
+
+ global_buffers = calloc(sizeof(*global_buffers), kt->nr_cpu_ids);
+ max_tr_buffers = calloc(sizeof(*max_tr_buffers), kt->nr_cpu_ids);
+
+ ftrace_init_buffers(global_buffers, global_ring_buffer, global_pages);
+ ftrace_init_buffers(max_tr_buffers, max_tr_ring_buffer, max_tr_pages);
+
+ page_tmp = malloc(PAGESIZE());
+
+ ftrace_events = symbol_value("ftrace_events");
+ ftrace_init_event_types();
+
+ addr = symbol_value("current_trace");
+ read_value(current_trace, addr, POINTER_SYM, POINTER);
+ read_value(addr, current_trace, tracer, name);
+ read_string(addr, tmp, 128);
+ current_trace_name = strdup(tmp);
+
+ ftrace_initialized = 1;
+
+ ftrace_show_init();
+}
+
+static void ftrace_dump_page(FILE *out, ulong page)
+{
+ ulong raw_page;
+
+ read_value(raw_page, page, buffer_page, page);
+
+ if (!readmem(raw_page, KVADDR, page_tmp, PAGESIZE(), "get page context",
+ RETURN_ON_ERROR | QUIET))
+ error(FATAL, "cannot get page context\n");
+
+ fwrite(page_tmp, 1, PAGESIZE(), out);
+}
+
+static void ftrace_dump_buffer(FILE *out, struct ring_buffer_per_cpu *cpu_buffer,
+ unsigned pages)
+{
+ unsigned i;
+
+ ftrace_dump_page(out, cpu_buffer->reader_page);
+
+ if (cpu_buffer->reader_page == cpu_buffer->commit_page)
+ return;
+
+ i = cpu_buffer->head_page_index;
+ for (;;) {
+ ftrace_dump_page(out, cpu_buffer->pages[i]);
+
+ if (cpu_buffer->pages[i] == cpu_buffer->commit_page)
+ break;
+
+ i++;
+ if (i == pages)
+ i = 0;
+
+ if (i == cpu_buffer->head_page_index) {
+ /* cpu_buffer->commit_page may be corrupted */
+ break;
+ }
+ }
+}
+
+static void ftrace_dump_buffers(const char *per_cpu_path)
+{
+ int i;
+
+ for (i = 0; i < kt->nr_cpu_ids; i++) {
+ char *path;
+ FILE *out;
+
+ if (!global_buffers[i].kaddr)
+ continue;
+
+ asprintf(&path, "%s/cpu%d", per_cpu_path, i);
+ mkdir(path, 0755);
+ free(path);
+
+ asprintf(&path, "%s/cpu%d/trace_pipe_raw", per_cpu_path, i);
+ out = fopen(path, "wb");
+ free(path);
+
+ ftrace_dump_buffer(out, global_buffers + i, global_pages);
+ fclose(out);
+ }
+}
+
+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;
+ struct ftrace_field *fields;
+};
+
+static struct event_type *event_type_cache[MAX_CACHE_ID];
+static struct event_type **event_types;
+static int nr_event_types;
+
+/*
+ * 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 void ftrace_init_event_type(ulong call, struct event_type *aevent_type)
+{
+ ulong fields_addr, pos;
+
+ int nfields = 0, max_fields = 16;
+ struct ftrace_field *fields;
+
+
+ fields_addr = call + koffset(ftrace_event_call, fields);
+ read_value(pos, fields_addr, list_head, next);
+
+ if (pos == 0) {
+ aevent_type->nfields = 0;
+ aevent_type->fields = NULL;
+ if (verbose)
+ fprintf(fp, "no field %lu\n", call);
+ return;
+ }
+
+ fields = malloc(sizeof(*fields) * max_fields);
+
+ while (pos != fields_addr) {
+ ulong field = pos - koffset(ftrace_event_field, link);
+ ulong name_addr, type_addr;
+ char field_name[128], field_type[128];
+ int offset, size, is_signed;
+
+ read_value(name_addr, field, ftrace_event_field, name);
+ read_value(type_addr, field, ftrace_event_field, type);
+ read_value(offset, field, ftrace_event_field, offset);
+ read_value(size, field, ftrace_event_field, size);
+ read_value(is_signed, field, ftrace_event_field, is_signed);
+
+ read_string(name_addr, field_name, 128);
+ read_string(type_addr, field_type, 128);
+
+ if (nfields >= max_fields) {
+ max_fields *= 2;
+ fields = realloc(fields, sizeof(*fields) * max_fields);
+ }
+
+ fields[nfields].name = strdup(field_name);
+ fields[nfields].type = strdup(field_type);
+ fields[nfields].offset = offset;
+ fields[nfields].size = size;
+ fields[nfields].is_signed = is_signed;
+ ftrace_field_access_init(&fields[nfields]);
+ nfields++;
+
+ read_value(pos, pos, list_head, next);
+ }
+
+ aevent_type->nfields = nfields;
+ aevent_type->fields = fields;
+}
+
+static void ftrace_init_event_types(void)
+{
+ ulong event;
+ int max_types = 128;
+
+ event_types = malloc(sizeof(*event_types) * max_types);
+
+ read_value(event, ftrace_events, list_head, next);
+ while (event != ftrace_events) {
+ ulong call = event - koffset(ftrace_event_call, list);
+ ulong name_addr, system_addr;
+ char name[128], system[128];
+ int id;
+
+ struct event_type *aevent_type = malloc(sizeof(*aevent_type));
+
+ read_value(id, call, ftrace_event_call, id);
+ read_value(name_addr, call, ftrace_event_call, name);
+ read_value(system_addr, call, ftrace_event_call, system);
+
+ read_string(name_addr, name, 128);
+ read_string(system_addr, system, 128);
+
+ aevent_type->system = strdup(system);
+ aevent_type->name = strdup(name);
+ aevent_type->id = id;
+
+ if (id < MAX_CACHE_ID)
+ event_type_cache[id] = aevent_type;
+
+ if (nr_event_types >= max_types) {
+ max_types *= 2;
+ event_types = realloc(event_types,
+ sizeof(*event_types) * max_types);
+ }
+ event_types[nr_event_types++] = aevent_type;
+
+ ftrace_init_event_type(call, aevent_type);
+ if (!strcmp("ftrace", aevent_type->system))
+ aevent_type->plugin = 1;
+ else
+ aevent_type->plugin = 0;
+ aevent_type->printer = event_default_print;
+
+ read_value(event, event, list_head, next);
+ }
+}
+
+static struct ftrace_field *find_event_field(struct event_type *t, const char *name)
+{
+ int i;
+ struct ftrace_field *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;
+}
+
+static void ftrace_dump_event_type(struct event_type *t, const char *path)
+{
+ char *format_path;
+ FILE *out;
+ int i;
+
+ asprintf(&format_path, "%s/format", path);
+ out = fopen(format_path, "w");
+ free(format_path);
+
+ fprintf(out, "name: %s\n", t->name);
+ fprintf(out, "ID: %d\n", t->id);
+ fprintf(out, "format:\n");
+
+ for (i = 0; i < t->nfields; i++) {
+ struct ftrace_field *f = &t->fields[i];
+
+ fprintf(out, "\tfield:%s %s;\toffset:%d;\tsize:%d;\n",
+ f->type, f->name, f->offset, f->size);
+ }
+
+ /* TODO */
+ fprintf(out, "\nprint fmt: \"unknow fmt from dump\"\n");
+ fclose(out);
+}
+
+static void ftrace_dump_event_types(const char *events_path)
+{
+ int i;
+
+ for (i = 0; i < nr_event_types; i++) {
+ char *path;
+ struct event_type *t = event_types[i];
+
+ asprintf(&path, "%s/%s", events_path, t->system);
+ mkdir(path, 0755);
+ free(path);
+
+ asprintf(&path, "%s/%s/%s", events_path, t->system, t->name);
+ mkdir(path, 0755);
+
+ ftrace_dump_event_type(t, path);
+ free(path);
+ }
+}
+
+struct ring_buffer_per_cpu_stream {
+ ulong *pages;
+ void *page_tmp;
+ int available_pages;
+ 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)
+{
+ unsigned i, count = 0;
+
+ s->page_tmp = malloc(PAGESIZE());
+ if (!s->page_tmp)
+ return -1;
+
+ s->pages = malloc(sizeof(ulong) * (pages + 1));
+ if (!s->pages) {
+ free(s->page_tmp);
+ return -1;
+ }
+
+ s->pages[count++] = cpu_buffer->reader_page;
+
+ if (cpu_buffer->reader_page == cpu_buffer->commit_page)
+ goto pages_done;
+
+ i = cpu_buffer->head_page_index;
+ for (;;) {
+ s->pages[count++] = cpu_buffer->pages[i];
+
+ if (cpu_buffer->pages[i] == cpu_buffer->commit_page)
+ break;
+
+ i++;
+ if (i == pages)
+ i = 0;
+
+ if (i == cpu_buffer->head_page_index) {
+ /* cpu_buffer->commit_page may be corrupted */
+ break;
+ }
+ }
+
+pages_done:
+ s->available_pages = count;
+ s->curr_page_indx = -1;
+ return 0;
+}
+
+static
+void ring_buffer_per_cpu_stream_destroy(struct ring_buffer_per_cpu_stream *s)
+{
+ free(s->page_tmp);
+ free(s->pages);
+}
+
+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
+void ring_buffer_per_cpu_stream_get_page(struct ring_buffer_per_cpu_stream *s)
+{
+ ulong raw_page;
+
+ read_value(raw_page, s->pages[s->curr_page_indx], buffer_page, page);
+
+ if (!readmem(raw_page, KVADDR, s->page_tmp, PAGESIZE(),
+ "get page context", RETURN_ON_ERROR | QUIET))
+ error(FATAL, "cannot get page context\n");
+
+ s->ts = *(u64 *)s->page_tmp;
+ s->offset = s->page_tmp + PAGE_HEADER_LEN;
+ s->commit = s->offset + *(ulong *)(s->page_tmp + 8) / 4;
+}
+
+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->available_pages)
+ return -1;
+
+again:
+ if ((s->curr_page_indx == -1) || (s->offset >= s->commit)) {
+ s->curr_page_indx++;
+ if (s->curr_page_indx == s->available_pages)
+ return -1;
+
+ ring_buffer_per_cpu_stream_get_page(s);
+ 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\n");
+ 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 ring_buffer_stream_init(struct ring_buffer_stream *s, bool *cpulist)
+{
+ int cpu;
+
+ s->ss = malloc(sizeof(*s->ss) * kt->nr_cpu_ids);
+ s->es = malloc(sizeof(*s->es) * kt->nr_cpu_ids);
+
+ for (cpu = 0; cpu < kt->nr_cpu_ids; cpu++) {
+ s->es[cpu].data = NULL;
+
+ if (!global_buffers[cpu].kaddr)
+ continue;
+
+ if (cpulist && !cpulist[cpu])
+ continue;
+
+ ring_buffer_per_cpu_stream_init(global_buffers + cpu,
+ global_pages, s->ss + cpu);
+ }
+
+ s->ts = 0;
+ s->popped_cpu = kt->nr_cpu_ids;
+ s->pushed = 0;
+}
+
+static
+void ring_buffer_stream_destroy(struct ring_buffer_stream *s, bool *cpulist)
+{
+ int cpu;
+
+ for (cpu = 0; cpu < kt->nr_cpu_ids; cpu++) {
+ if (!global_buffers[cpu].kaddr)
+ continue;
+ if (cpulist && !cpulist[cpu])
+ continue;
+ ring_buffer_per_cpu_stream_destroy(s->ss + cpu);
+ }
+
+ free(s->ss);
+ free(s->es);
+}
+
+/* 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 == kt->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 == kt->nr_cpu_ids) {
+ for (cpu = 0; cpu < kt->nr_cpu_ids; cpu++) {
+ if (!global_buffers[cpu].kaddr)
+ continue;
+
+ ring_buffer_per_cpu_stream_pop_event(s->ss + cpu,
+ s->es + cpu);
+
+ if (!s->es[cpu].data)
+ 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 < kt->nr_cpu_ids; cpu++) {
+ if (!s->es[cpu].data)
+ 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)
+{
+ return (long)(data + *(int16_t *)(data + f->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 (long)(data + *(int16_t *)(data + f->offset));
+}
+
+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) {
+ /* TODO: kernel side may be changed, need fix */
+ f->op = access_error;
+ } else if (strstr(f->type, "char")) {
+ /* TODO: finish kernel side. */
+ f->op = access_string_local;
+ } else {
+ /* TODO: finish kernel side. */
+ f->op = access_other;
+ }
+ } 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\n", current_trace_name);
+}
+
+static void dump_saved_cmdlines(const char *dump_tracing_dir)
+{
+ char *path;
+ FILE *out;
+ int i;
+ struct task_context *tc;
+
+ asprintf(&path, "%s/saved_cmdlines", dump_tracing_dir);
+ out = fopen(path, "w");
+ free(path);
+
+ tc = FIRST_CONTEXT();
+ for (i = 0; i < RUNNING_TASKS(); i++)
+ fprintf(out, "%d %s\n", (int)tc[i].pid, tc[i].comm);
+
+ fclose(out);
+}
+
+static void ftrace_dump(int argc, char *argv[])
+{
+ int c;
+ int dump_meta_data = 0;
+ int dump_symbols = 0;
+ char *dump_tracing_dir;
+ char *path;
+ int ret;
+
+ while ((c = getopt(argc, argv, "sm")) != EOF) {
+ switch(c)
+ {
+ case 's':
+ dump_symbols = 1;
+ break;
+ case 'm':
+ dump_meta_data = 1;
+ break;
+ default:
+ cmd_usage(pc->curcmd, SYNOPSIS);
+ return;
+ }
+ }
+
+ if (argc - optind == 0) {
+ dump_tracing_dir = "dump_tracing_dir";
+ } else if (argc - optind == 1) {
+ dump_tracing_dir = argv[optind];
+ } else {
+ cmd_usage(pc->curcmd, SYNOPSIS);
+ return;
+ }
+
+ ret = mkdir(dump_tracing_dir, 0755);
+ if (ret < 0)
+ return;
+
+ asprintf(&path, "%s/per_cpu", dump_tracing_dir);
+ mkdir(path, 0755);
+ ftrace_dump_buffers(path);
+ free(path);
+
+ if (dump_meta_data) {
+ asprintf(&path, "%s/events", dump_tracing_dir);
+ mkdir(path, 0755);
+ ftrace_dump_event_types(path);
+ free(path);
+
+ dump_saved_cmdlines(dump_tracing_dir);
+ }
+
+ if (dump_symbols) {
+ fprintf(fp, "\n-s option hasn't been implemented.\n");
+ fprintf(fp, "symbols is not dumpped.\n");
+ fprintf(fp, "You can use `sym -l > %s/kallsyms`\n\n",
+ dump_tracing_dir);
+ }
+}
+
+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) { \
+ __access_field##_field = find_event_field(event_type, \
+ field_name); \
+ } \
+ \
+ if (!__access_field##_field) { \
+ event_type->printer = event_default_print; \
+ ring_buffer_stream_push_current_event(&format_context.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, u64 value)
+{
+ 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);
+ else
+ event_printf("%llu", (unsigned long long)value);
+ } else if (f->op == access_string_local) {
+ 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 */
+ }
+}
+
+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 int ftrace_show_disabled;
+
+static void ftrace_show_function_graph_init(void);
+static void ftrace_show_function_init(void);
+static void ftrace_show_trace_event_init(void);
+
+static void ftrace_show_init(void)
+{
+ /* ftrace_event_get_id(), ftrace_event_get_pid() should not failed. */
+ if (!find_event_field(event_types[0], "common_type")) {
+ ftrace_show_disabled = 1;
+ return;
+ }
+
+ if (!find_event_field(event_types[0], "common_pid")) {
+ ftrace_show_disabled = 1;
+ return;
+ }
+
+ ftrace_show_function_init();
+ ftrace_show_function_graph_init();
+ ftrace_show_trace_event_init();
+}
+
+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) {
+ event_printf("<Unknown event type>\n");
+ 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(bool *cpulist, const char *cpulist_str, int len)
+{
+ unsigned a, b;
+ const char *s = cpulist_str;
+
+ memset(cpulist, 0, sizeof(bool) * 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] = true;
+ a++;
+ }
+ if (*s == ',')
+ s++;
+ } while (*s != '\0' && *s != '\n');
+
+ return 0;
+}
+
+static void ftrace_show_function_graph_start(void);
+
+static void ftrace_show(int argc, char *argv[])
+{
+ int c;
+ bool *cpulist = NULL;
+
+ if (ftrace_show_disabled) {
+ fprintf(fp, "trace show is disabled.");
+ return;
+ }
+
+ 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 = alloca(sizeof(bool) * kt->nr_cpu_ids);
+ if (parse_cpulist(cpulist, optarg, kt->nr_cpu_ids) < 0)
+ goto err_arg;
+ break;
+ default:
+ goto err_arg;
+ }
+ }
+
+ if (argc - optind != 0) {
+err_arg:
+ cmd_usage(pc->curcmd, SYNOPSIS);
+ 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);
+
+}
+
+void cmd_ftrace(void)
+{
+ if (ftrace_no_ftrace) {
+ fprintf(fp, "No tracing in this kernel\n");
+ return;
+ }
+
+ if (!ftrace_initialized) {
+ fprintf(fp, "failed to init tracing\n");
+ return;
+ }
+
+ if (argcnt == 1)
+ show_basic_info();
+ else if (!strcmp(args[1], "dump"))
+ ftrace_dump(argcnt - 1, args + 1);
+ else if (!strcmp(args[1], "show"))
+ 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;
+ u64 value;
+
+ f = &t->fields[i];
+ value = f->op(f, fc->event.data);
+ event_printf("%s=", f->name);
+ event_field_print(f, value);
+ if (i)
+ event_printf(", ");
+ }
+
+ event_printf("\n");
+}
+
+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("\n");
+}
+
+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 || !t2)
+ 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)
+ return;
+
+ for (i = 0; i < kt->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(" ------------------------------------------\n");
+ event_printf(" %*d) ", max_bytes_for_cpu, cpu);
+ fn_graph_proc_print(prev_pid);
+ event_printf(" => ");
+ fn_graph_proc_print(pid);
+ event_printf("\n ------------------------------------------\n\n");
+}
+
+/* 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) + '\0' */
+ 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("();\n");
+}
+
+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("() {\n");
+}
+
+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}\n", depth * TRACE_GRAPH_INDENT, "");
+
+ if (gopt_graph_print_overrun) {
+ unsigned long overrun = access_field(t, data, "ret.overrun");
+ event_printf(" (Overruns: %lu)\n", overrun);
+ }
+
+ fn_graph_irq_print(0);
+}
+
+static void ftrace_show_function_graph_init(void)
+{
+ if (strcmp(current_trace_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) * kt->nr_cpu_ids);
+ if (!cpus_prev_pid)
+ return;
+
+ max_bytes_for_cpu = snprintf(NULL, 0, "%d", kt->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\n",
+ (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\n", (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]\n",
+ (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\n",
+ (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\n",
+ (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]\n", 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\n",
+ (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]\n",
+ (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]\n",
+ (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]\n",
+ (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\n", 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\n",
+ (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\n",
+ (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\n",
+ (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\n",
+ (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\n",
+ (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\n",
+ (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\n",
+ (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("\n");
+}
+
+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("\n");
+}
+
+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\n", 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\n", 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
+}
+
diff --git a/global_data.c b/global_data.c
index 581deb2..2c14d69 100755
--- a/global_data.c
+++ b/global_data.c
@@ -103,6 +103,7 @@ struct command_table_entry linux_command_table[] = {
{"runq", cmd_runq, help_runq, REFRESH_TASK_TABLE},
{"search", cmd_search, help_search, 0},
{"set", cmd_set, help_set, REFRESH_TASK_TABLE},
+ {"trace", cmd_ftrace, help_ftrace, 0},
{"sig", cmd_sig, help_sig, REFRESH_TASK_TABLE},
{"struct", cmd_struct, help_struct, 0},
{"swap", cmd_swap, help_swap, 0},
diff --git a/help.c b/help.c
index 5f0189f..f8ddb84 100755
--- a/help.c
+++ b/help.c
@@ -2899,6 +2899,39 @@ char *help_task[] = {
NULL
};
+char *help_ftrace[] = {
+"trace",
+"show or dump the tracing info",
+"[ <show [-c <cpulist>] [-f [no]<flagname>]> | <dump [-sm] <dest-dir>> ]",
+"trace",
+" shows the current tracer and other informations.",
+"",
+"trace show [ -c <cpulist> ] [ -f [no]<flagename> ]",
+" 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 dump [-sm] <dest-dir>",
+" dump ring_buffers to dest-dir. Then you can parse it",
+" by other tracing tools. The dirs and files are generated",
+" the same as debugfs/tracing.",
+" -m: also dump metadata of ftrace.",
+" -s: also dump symbols of the kernel <not implemented>.",
+NULL
+};
+
char *help_sig[] = {
"sig",
"task signal handling",
diff --git a/kernel.c b/kernel.c
index 603b6e9..dd4563d 100755
--- a/kernel.c
+++ b/kernel.c
@@ -132,6 +132,14 @@ kernel_init()
} else
kt->cpus = 1;
+ if (symbol_exists("nr_cpu_ids"))
+ get_symbol_data("nr_cpu_ids", sizeof(int), &kt->nr_cpu_ids);
+ else
+ kt->nr_cpu_ids = 1;
+
+ if (kt->cpus < kt->nr_cpu_ids)
+ kt->cpus = kt->nr_cpu_ids;
+
if ((sp1 = symbol_search("__per_cpu_start")) &&
(sp2 = symbol_search("__per_cpu_end")) &&
(sp1->type == 'A' || sp1->type == 'D') &&
diff --git a/main.c b/main.c
index 5d79eef..9831539 100755
--- a/main.c
+++ b/main.c
@@ -516,6 +516,7 @@ main_loop(void)
net_init();
dev_init();
machdep_init(POST_INIT);
+ ftrace_init();
}
} else
SIGACTION(SIGINT, restart, &pc->sigaction, NULL);
15 years
- 6
- 9
Re: [Crash-utility] How do I get source listing?
by Dave Anderson
----- "John Steinman" <john.steinman46(a)gmail.com> wrote:
> Hi,
>
> How do I get a code listing from the crash prompt?
>
> Like the gdb command "gdb list "function_call".
>
> If anyone knows how to do this please provide me the command syntax.
This works for me:
crash> gdb list <function>
...
crash> gdb list
...
crash> gdb list
...
I can't recall whether it requires the kernel "kernel-devel-<release>" package,
or if just the "kernel-debuginfo-<release>" will suffice -- I've got both
of them installed.
Dave
15 years, 1 month
- 1
- 0
How do I get source listing?
by John Steinman
Hi,
How do I get a code listing from the crash prompt?
Like the gdb command "gdb list "function_call".
If anyone knows how to do this please provide me the command syntax.
Thanks
15 years, 1 month
- 1
- 0
Re: [Crash-utility] [PATCH] crash: Fix the type of pfn_to_pos().
by Dave Anderson
----- "Dave Anderson" <anderson(a)redhat.com> wrote:
> ----- "Ken'ichi Ohmichi" <oomichi(a)mxs.nes.nec.co.jp> wrote:
>
> > Hi,
> >
> > pfn_to_pos() returns the position of the page header corresponding to
> > the argument "pfn", and the value can be larger than "int".
> > So it should be declared as "ulong".
>
> Queued for the next release.
>
> By the way, did you notice this by code inspection, or did you actually
> see a failure with a large vmcore? And if you did see it, what kind of error
> resulted? It appears like it would just read a bogus page descriptor, and
> that could result in a few different error types. Also, I was under the
> impression that the compressed diskdump/kdump page descriptors would be located
> near the beginning of the vmcore, and for one to exist beyond 4GB would be highly
> unusual?
Hi Ken'ich,
Sorry -- I had not read your response to Takao's makedumpfile patch on the kexec
list before I responded to this one, so I see it was by code inspection.
Although I'm still curious as to how much physical memory a system would need
in order for a compressed diskdump/kdump to have a page descriptor that high
in the vmcore? ;-)
Thanks,
Dave
15 years, 1 month
- 2
- 1
Re: [Crash-utility] [PATCH] crash: Fix the type of pfn_to_pos().
by Dave Anderson
----- "Ken'ichi Ohmichi" <oomichi(a)mxs.nes.nec.co.jp> wrote:
> Hi,
>
> pfn_to_pos() returns the position of the page header corresponding to
> the argument "pfn", and the value can be larger than "int".
> So it should be declared as "ulong".
Queued for the next release.
By the way, did you notice this by code inspection, or did you actually
see a failure with a large vmcore? And if you did see it, what kind of error
resulted? It appears like it would just read a bogus page descriptor, and
that could result in a few different error types. Also, I was under the
impression that the compressed diskdump/kdump page descriptors would be located
near the beginning of the vmcore, and for one to exist beyond 4GB would be highly
unusual?
Thanks,
Dave
>
>
> Thanks
> Ken'ichi Ohmichi
>
> Signed-off-by: Ken'ichi Ohmichi <oomichi(a)mxs.nes.nec.co.jp>
> ---
> --- a/diskdump.c 2009-08-19 15:02:16.000000000 +0900
> +++ b/diskdump.c 2009-08-19 15:03:40.000000000 +0900
> @@ -399,10 +399,10 @@ err:
> return FALSE;
> }
>
> -static int
> +static ulong
> pfn_to_pos(ulong pfn)
> {
> - int desc_pos, j, valid;
> + ulong desc_pos, j, valid;
> ulong p1, p2;
>
> if (KDUMP_SPLIT()) {
> @@ -530,7 +530,7 @@ cache_page(physaddr_t paddr)
> int i, ret;
> int found;
> ulong pfn;
> - int desc_pos;
> + ulong desc_pos;
> off_t seek_offset;
> page_desc_t pd;
> const int block_size = dd->block_size;
>
> --
> Crash-utility mailing list
> Crash-utility(a)redhat.com
> https://www.redhat.com/mailman/listinfo/crash-utility
15 years, 1 month
- 1
- 0
[PATCH] crash: Fix the type of pfn_to_pos().
by Ken'ichi Ohmichi
Hi,
pfn_to_pos() returns the position of the page header corresponding to
the argument "pfn", and the value can be larger than "int".
So it should be declared as "ulong".
Thanks
Ken'ichi Ohmichi
Signed-off-by: Ken'ichi Ohmichi <oomichi(a)mxs.nes.nec.co.jp>
---
--- a/diskdump.c 2009-08-19 15:02:16.000000000 +0900
+++ b/diskdump.c 2009-08-19 15:03:40.000000000 +0900
@@ -399,10 +399,10 @@ err:
return FALSE;
}
-static int
+static ulong
pfn_to_pos(ulong pfn)
{
- int desc_pos, j, valid;
+ ulong desc_pos, j, valid;
ulong p1, p2;
if (KDUMP_SPLIT()) {
@@ -530,7 +530,7 @@ cache_page(physaddr_t paddr)
int i, ret;
int found;
ulong pfn;
- int desc_pos;
+ ulong desc_pos;
off_t seek_offset;
page_desc_t pd;
const int block_size = dd->block_size;
15 years, 1 month
- 1
- 0
crash version 4.0-8.12 is available
by Dave Anderson
- Fix to support 2.6.30 and later x86 CONFIG_4KSTACKS kernels, where
the hardirq_ctx[] and softirq_ctx[] NR_CPUS-bounded arrays were
replaced with per-cpu variables. Without the patch, the crash
session would fail during initialization with the error message
"crash: cannot resolve: hardirq_ctx".
(oomichi(a)mxs.nes.nec.co.jp)
- Clean up gdb header files that generate warning messages when
compiling the top-level cmdline.c file with "make warn" or
"make Warn". (anderson(a)redhat.com)
- If an attempt is made to use an x86 vmlinux file on an x86_64 host,
bail out with a "not a supported file format" error immediately
instead of later on when trying to match the linux_banner string.
(anderson(a)redhat.com)
- Fix for "bt" command on x86 Xen hypervisor dumpfiles where a vcpu
received a shutdown NMI while running in an interrupt handler.
Without the patch, the backtrace would indicate "bt: cannot resolve
stack trace", and dump the text symbols on the stack.
(anderson(a)redhat.com)
- Implemented support for the KVM "save-vm" file format, which is
also proposed as the dumpfile format for the "virsh dump" command
for KVM guests.
(pbonzini(a)redhat.com, anderson(a)redhat.com)
- Increase NR_CPUS from 512 to 4096 for x86_64.
(caiqian(a)redhat.com)
- Correct cpu accounting when processors have been taken offline using
a new get_highest_cpu_online() utility function. Without the patch,
commands that have per-cpu displays may not show a cpu's information
and/or may show information for an offline cpu. This patch only
addresses 2.6.30 and later x86_64 kernels in which the per-cpu array
x8664_pda data structures were replaced with per-cpu variables.
(anderson(a)redhat.com)
- Replace the CFLAGS definition in the Makefile with a CRASH_CFLAGS
definition, which in turn contains ${CFLAGS}. This will allow the
issuing of user-defined CFLAGS on the "make" command line, as is done
according to the Fedora build guidelines.
(lkundrak(a)v3.sk)
- Fix for a segmentation violation within the embedded gdb module
during session invocation, when running against kernels built with
Fedora gcc version 4.4.0-12 and later (2.6.31-0.62.rc2.git4.fc12
and later Fedora kernels). The gcc update introduced a more
compact Dwarf 3 DW_AT_data_member location, which in turn required
a patch to all versions of gdb.
(lkundrak(a)v3.sk)
Download from: http://people.redhat.com/anderson
15 years, 1 month
- 1
- 0
vmcore file size 0 on x86_64
by Chandan12 K
Hi,
I am little new in this mailing list. I just wondered if anybody could
help me regarding the vmcore file generation. I ran kexec on my x86_64
machine, and the /proc/vmcore file is created with zero size.
However, even if I read the /dev/oldmem file, I am only able to read till
16M. I guess I am only able to read till the 'X', where X is
crashkernel=Y@X.
Moreover, My machine seems to have 32 bit user space and ofcourse, 64 bit
kernel space.
Appreciate any response.
Chandan Kumar
____________________________________________
=====-----=====-----=====
Notice: The information contained in this e-mail
message and/or attachments to it may contain
confidential or privileged information. If you are
not the intended recipient, any dissemination, use,
review, distribution, printing or copying of the
information contained in this e-mail message
and/or attachments to it are strictly prohibited. If
you have received this communication in error,
please notify us by reply e-mail or telephone and
immediately and permanently delete the message
and any attachments. Thank you
15 years, 1 month
- 2
- 1
Re: [Crash-utility] Error when running crash utility - crash: read error: kernel virtual address: c1399f10 type: "xtime"
by Dave Anderson
----- "Mani" <mani2885(a)gmail.com> wrote:
> Hello,
>
> I am trying to analyse the dump created by the kdump utility. This is what I did
> I took 2.6.25.14 vanilla version of kernel and made two copies of the
> kernel named vmlinuz-2.6.25.14-main (Production kernel) and
> vmlinuz-2.6.25.14-kdump (Crash kernel) by following the procedure
> mentioned in the following website
> http://www.dedoimedo.com/computers/kdump.html
>
> When I run crash utility using the following command
> crash /usr/src/linux-2.6.25.14-main/vmlinux /var/crash/2009-08-08-23:32/vmcore
>
> I get the following error
>
> crash /usr/src/linux-2.6.25.14-main/vmlinux /var/crash/2009-08-08-23:32/vmcore
>
> crash 4.0-6.0.5
> Copyright (C) 2002, 2003, 2004, 2005, 2006, 2007, 2008 Red Hat, Inc.
> Copyright (C) 2004, 2005, 2006 IBM Corporation
> Copyright (C) 1999-2006 Hewlett-Packard Co
> Copyright (C) 2005, 2006 Fujitsu Limited
> Copyright (C) 2006, 2007 VA Linux Systems Japan K.K.
> Copyright (C) 2005 NEC Corporation
> Copyright (C) 1999, 2002, 2007 Silicon Graphics, Inc.
> Copyright (C) 1999, 2000, 2001, 2002 Mission Critical Linux, Inc.
> This program is free software, covered by the GNU General Public License,
> and you are welcome to change it and/or distribute copies of it under
> certain conditions. Enter "help copying" to see the conditions.
> This program has absolutely no warranty. Enter "help warranty" for
> details.
>
> GNU gdb 6.1
> Copyright 2004 Free Software Foundation, Inc.
> GDB is free software, covered by the GNU General Public License, and you are
> welcome to change it and/or distribute copies of it under certain conditions.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB. Type "show warranty" for details.
> This GDB was configured as "i686-pc-linux-gnu"...
>
> crash: read error: kernel virtual address: c1399f10 type: "xtime"
>
>
> I checked for the error and found this link which mentions few
> work-around/fixes for the issue with reading of /dev/mem
> http://www.mail-archive.com/crash-utility@redhat.com/msg01553.html
Alright -- before even talking about the "xtime" read error above --
you've gone off into the weeds...
The CONFIG_STRICT_DEVMEM issue only applies to analyzing the *live* system
with the crash utility, so it's completely irrelevant to your attempt
to analyze a kdump vmcore.
And with respect to CONFIG_STRICT_DEVMEM, you want to *avoid* building
your kernel with it if you want to look at the live system with crash.
If you *add* CONFIG_STRICT_DEVMEM, then you have to work around its
disabling of the usage of /dev/mem. One of the ways to do that is
to try the kretprobe hack. Other than that, you'd have to port the
Red Hat "/dev/crash" driver to your kernel for live system analysis.
So -- don't do this:
> I tried adding CONFIG_STRICT_DEVMEM to the .config file (This
> parameter was not already present in the config file)
> I got the following error while compiling the kernel
>
> scripts/kconfig/mconf arch/x86/Kconfig
> .config:3869:warning: trying to assign nonexistent symbol STRICT_DEVMEM
>
> I tried to create the kretprobe module, it works fine for do_fork()
> but when I give devmem_is_allowed() as the functioin name I get the
> following error
and if you don't build your kernel with CONFIG_STRICT_DEVMEM to begin with,
then there's no need to do this:
> [root@buzzsaw kprobes]# insmod kretprobe_devmem.ko
> insmod: error inserting 'kretprobe_devmem.ko': -1 Operation not
> permitted
In any case, I don't know why the insmod is failing unless you're trying to
do it as a non-root user.
> I am new to the area of kernel debugging. Please let me know how I can
> solve this issue. Thanks
Getting back to the original "xtime" read error issue, I don't
know what's causing it off-hand. Here's what I can suggest:
(1) Update your version of the crash utility. 4.0-8.11 is available
on the upstream site at http://people.redhat.com/anderson. The
easiest way to go is to take the tar.gz file there, un-tar it, go
into the resultant directory, and type "make". The crash binary
will be built into that top-level directory.
(2) Indicate what your kernel's CONFIG_PHYSICAL_START and CONFIG_PHYSICAL_ALIGN
config options are equal to. It's possible that you may be running into
http://people.redhat.com/anderson/crash.changelog.html#4_0_4_5
(3) If that version does not work, then post the output of
"crash -d7 your-vmlinux your-vmcore", and we can go from there.
Thanks,
Dave
15 years, 1 month
- 2
- 1
Error when running crash utility - crash: read error: kernel virtual address: c1399f10 type: "xtime"
by Mani
Hello,
I am trying to analyse the dump created by the kdump utility. This is what I
did
I took 2.6.25.14 vanilla version of kernel and made two copies of the kernel
named vmlinuz-2.6.25.14-main (Production kernel) and
vmlinuz-2.6.25.14-kdump (Crash kernel) by following the procedure mentioned
in the following website
*http://www.dedoimedo.com/computers/kdump.html*
When I run crash utility using the following command
*crash /usr/src/linux-2.6.25.14-main/vmlinux
/var/crash/2009-08-08-23:32/vmcore*
I get the following error
*
crash /usr/src/linux-2.6.25.14-main/vmlinux
/var/crash/2009-08-08-23:32/vmcore
crash 4.0-6.0.5
Copyright (C) 2002, 2003, 2004, 2005, 2006, 2007, 2008 Red Hat, Inc.
Copyright (C) 2004, 2005, 2006 IBM Corporation
Copyright (C) 1999-2006 Hewlett-Packard Co
Copyright (C) 2005, 2006 Fujitsu Limited
Copyright (C) 2006, 2007 VA Linux Systems Japan K.K.
Copyright (C) 2005 NEC Corporation
Copyright (C) 1999, 2002, 2007 Silicon Graphics, Inc.
Copyright (C) 1999, 2000, 2001, 2002 Mission Critical Linux, Inc.
This program is free software, covered by the GNU General Public License,
and you are welcome to change it and/or distribute copies of it under
certain conditions. Enter "help copying" to see the conditions.
This program has absolutely no warranty. Enter "help warranty" for details.
GNU gdb 6.1
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain
conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i686-pc-linux-gnu"...
crash: read error: kernel virtual address: c1399f10 type: "xtime"
*
I checked for the error and found this link which mentions few
work-around/fixes for the issue with reading of /dev/mem
*http://www.mail-archive.com/crash-utility@redhat.com/msg01553.html*
I tried adding CONFIG_STRICT_DEVMEM to the .config file (This parameter was
not already present in the config file)
I got the following error while compiling the kernel
*scripts/kconfig/mconf arch/x86/Kconfig
.config:3869:warning: trying to assign nonexistent symbol STRICT_DEVMEM*
I tried to create the kretprobe module, it works fine for do_fork() but when
I give devmem_is_allowed() as the functioin name I get the following error
*[root@buzzsaw kprobes]# insmod kretprobe_devmem.ko
insmod: error inserting 'kretprobe_devmem.ko': -1 Operation not permitted*
I am new to the area of kernel debugging. Please let me know how I can solve
this issue. Thanks
--
Regards,
Mani
15 years, 1 month
- 1
- 0