tracing: Fix function graph trace_pipe to properly display failed entries
[safe/jmp/linux-2.6] / kernel / trace / trace_functions_graph.c
index c009553..a43d009 100644 (file)
 #include "trace.h"
 #include "trace_output.h"
 
+struct fgraph_cpu_data {
+       pid_t           last_pid;
+       int             depth;
+       int             ignore;
+};
+
+struct fgraph_data {
+       struct fgraph_cpu_data          *cpu_data;
+
+       /* Place to preserve last processed entry. */
+       struct ftrace_graph_ent_entry   ent;
+       struct ftrace_graph_ret_entry   ret;
+       int                             failed;
+       int                             cpu;
+};
+
 #define TRACE_GRAPH_INDENT     2
 
 /* Flag options */
@@ -47,38 +63,50 @@ static struct tracer_flags tracer_flags = {
        .opts = trace_opts
 };
 
-/* pid on the last trace processed */
+static struct trace_array *graph_array;
 
 
 /* Add a function return address to the trace stack on thread info.*/
 int
-ftrace_push_return_trace(unsigned long ret, unsigned long long time,
-                        unsigned long func, int *depth)
+ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
+                        unsigned long frame_pointer)
 {
+       unsigned long long calltime;
        int index;
 
        if (!current->ret_stack)
                return -EBUSY;
 
+       /*
+        * We must make sure the ret_stack is tested before we read
+        * anything else.
+        */
+       smp_rmb();
+
        /* The return trace stack is full */
        if (current->curr_ret_stack == FTRACE_RETFUNC_DEPTH - 1) {
                atomic_inc(&current->trace_overrun);
                return -EBUSY;
        }
 
+       calltime = trace_clock_local();
+
        index = ++current->curr_ret_stack;
        barrier();
        current->ret_stack[index].ret = ret;
        current->ret_stack[index].func = func;
-       current->ret_stack[index].calltime = time;
+       current->ret_stack[index].calltime = calltime;
+       current->ret_stack[index].subtime = 0;
+       current->ret_stack[index].fp = frame_pointer;
        *depth = index;
 
        return 0;
 }
 
 /* Retrieve a function return address to the trace stack on thread info.*/
-void
-ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
+static void
+ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,
+                       unsigned long frame_pointer)
 {
        int index;
 
@@ -92,28 +120,52 @@ ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret)
                return;
        }
 
+#ifdef CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST
+       /*
+        * The arch may choose to record the frame pointer used
+        * and check it here to make sure that it is what we expect it
+        * to be. If gcc does not set the place holder of the return
+        * address in the frame pointer, and does a copy instead, then
+        * the function graph trace will fail. This test detects this
+        * case.
+        *
+        * Currently, x86_32 with optimize for size (-Os) makes the latest
+        * gcc do the above.
+        */
+       if (unlikely(current->ret_stack[index].fp != frame_pointer)) {
+               ftrace_graph_stop();
+               WARN(1, "Bad frame pointer: expected %lx, received %lx\n"
+                    "  from func %ps return to %lx\n",
+                    current->ret_stack[index].fp,
+                    frame_pointer,
+                    (void *)current->ret_stack[index].func,
+                    current->ret_stack[index].ret);
+               *ret = (unsigned long)panic;
+               return;
+       }
+#endif
+
        *ret = current->ret_stack[index].ret;
        trace->func = current->ret_stack[index].func;
        trace->calltime = current->ret_stack[index].calltime;
        trace->overrun = atomic_read(&current->trace_overrun);
        trace->depth = index;
-       barrier();
-       current->curr_ret_stack--;
-
 }
 
 /*
  * Send the trace to the ring-buffer.
  * @return the original return address.
  */
-unsigned long ftrace_return_to_handler(void)
+unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
 {
        struct ftrace_graph_ret trace;
        unsigned long ret;
 
-       ftrace_pop_return_trace(&trace, &ret);
-       trace.rettime = cpu_clock(raw_smp_processor_id());
+       ftrace_pop_return_trace(&trace, &ret, frame_pointer);
+       trace.rettime = trace_clock_local();
        ftrace_graph_return(&trace);
+       barrier();
+       current->curr_ret_stack--;
 
        if (unlikely(!ret)) {
                ftrace_graph_stop();
@@ -125,10 +177,123 @@ unsigned long ftrace_return_to_handler(void)
        return ret;
 }
 
+static int __trace_graph_entry(struct trace_array *tr,
+                               struct ftrace_graph_ent *trace,
+                               unsigned long flags,
+                               int pc)
+{
+       struct ftrace_event_call *call = &event_funcgraph_entry;
+       struct ring_buffer_event *event;
+       struct ring_buffer *buffer = tr->buffer;
+       struct ftrace_graph_ent_entry *entry;
+
+       if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled))))
+               return 0;
+
+       event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT,
+                                         sizeof(*entry), flags, pc);
+       if (!event)
+               return 0;
+       entry   = ring_buffer_event_data(event);
+       entry->graph_ent                        = *trace;
+       if (!filter_current_check_discard(buffer, call, entry, event))
+               ring_buffer_unlock_commit(buffer, event);
+
+       return 1;
+}
+
+int trace_graph_entry(struct ftrace_graph_ent *trace)
+{
+       struct trace_array *tr = graph_array;
+       struct trace_array_cpu *data;
+       unsigned long flags;
+       long disabled;
+       int ret;
+       int cpu;
+       int pc;
+
+       if (unlikely(!tr))
+               return 0;
+
+       if (!ftrace_trace_task(current))
+               return 0;
+
+       if (!ftrace_graph_addr(trace->func))
+               return 0;
+
+       local_irq_save(flags);
+       cpu = raw_smp_processor_id();
+       data = tr->data[cpu];
+       disabled = atomic_inc_return(&data->disabled);
+       if (likely(disabled == 1)) {
+               pc = preempt_count();
+               ret = __trace_graph_entry(tr, trace, flags, pc);
+       } else {
+               ret = 0;
+       }
+       /* Only do the atomic if it is not already set */
+       if (!test_tsk_trace_graph(current))
+               set_tsk_trace_graph(current);
+
+       atomic_dec(&data->disabled);
+       local_irq_restore(flags);
+
+       return ret;
+}
+
+static void __trace_graph_return(struct trace_array *tr,
+                               struct ftrace_graph_ret *trace,
+                               unsigned long flags,
+                               int pc)
+{
+       struct ftrace_event_call *call = &event_funcgraph_exit;
+       struct ring_buffer_event *event;
+       struct ring_buffer *buffer = tr->buffer;
+       struct ftrace_graph_ret_entry *entry;
+
+       if (unlikely(local_read(&__get_cpu_var(ftrace_cpu_disabled))))
+               return;
+
+       event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET,
+                                         sizeof(*entry), flags, pc);
+       if (!event)
+               return;
+       entry   = ring_buffer_event_data(event);
+       entry->ret                              = *trace;
+       if (!filter_current_check_discard(buffer, call, entry, event))
+               ring_buffer_unlock_commit(buffer, event);
+}
+
+void trace_graph_return(struct ftrace_graph_ret *trace)
+{
+       struct trace_array *tr = graph_array;
+       struct trace_array_cpu *data;
+       unsigned long flags;
+       long disabled;
+       int cpu;
+       int pc;
+
+       local_irq_save(flags);
+       cpu = raw_smp_processor_id();
+       data = tr->data[cpu];
+       disabled = atomic_inc_return(&data->disabled);
+       if (likely(disabled == 1)) {
+               pc = preempt_count();
+               __trace_graph_return(tr, trace, flags, pc);
+       }
+       if (!trace->depth)
+               clear_tsk_trace_graph(current);
+       atomic_dec(&data->disabled);
+       local_irq_restore(flags);
+}
+
 static int graph_trace_init(struct trace_array *tr)
 {
-       int ret = register_ftrace_graph(&trace_graph_return,
-                                       &trace_graph_entry);
+       int ret;
+
+       graph_array = tr;
+       ret = register_ftrace_graph(&trace_graph_return,
+                                   &trace_graph_entry);
        if (ret)
                return ret;
        tracing_start_cmdline_record();
@@ -136,49 +301,30 @@ static int graph_trace_init(struct trace_array *tr)
        return 0;
 }
 
+void set_graph_array(struct trace_array *tr)
+{
+       graph_array = tr;
+}
+
 static void graph_trace_reset(struct trace_array *tr)
 {
        tracing_stop_cmdline_record();
        unregister_ftrace_graph();
 }
 
-static inline int log10_cpu(int nb)
-{
-       if (nb / 100)
-               return 3;
-       if (nb / 10)
-               return 2;
-       return 1;
-}
+static int max_bytes_for_cpu;
 
 static enum print_line_t
 print_graph_cpu(struct trace_seq *s, int cpu)
 {
-       int i;
        int ret;
-       int log10_this = log10_cpu(cpu);
-       int log10_all = log10_cpu(cpumask_weight(cpu_online_mask));
-
 
        /*
         * Start with a space character - to make it stand out
         * to the right a bit when trace output is pasted into
         * email:
         */
-       ret = trace_seq_printf(s, " ");
-
-       /*
-        * Tricky - we space the CPU field according to the max
-        * number of online CPUs. On a 2-cpu system it would take
-        * a maximum of 1 digit - on a 128 cpu system it would
-        * take up to 3 digits:
-        */
-       for (i = 0; i < log10_all - log10_this; i++) {
-               ret = trace_seq_printf(s, " ");
-               if (!ret)
-                       return TRACE_TYPE_PARTIAL_LINE;
-       }
-       ret = trace_seq_printf(s, "%d) ", cpu);
+       ret = trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu);
        if (!ret)
                return TRACE_TYPE_PARTIAL_LINE;
 
@@ -190,15 +336,15 @@ print_graph_cpu(struct trace_seq *s, int cpu)
 static enum print_line_t
 print_graph_proc(struct trace_seq *s, pid_t pid)
 {
-       int i;
-       int ret;
-       int len;
-       char comm[8];
-       int spaces = 0;
+       char comm[TASK_COMM_LEN];
        /* sign + log10(MAX_INT) + '\0' */
        char pid_str[11];
+       int spaces = 0;
+       int ret;
+       int len;
+       int i;
 
-       strncpy(comm, trace_find_cmdline(pid), 7);
+       trace_find_cmdline(pid, comm);
        comm[7] = '\0';
        sprintf(pid_str, "%d", pid);
 
@@ -229,18 +375,27 @@ print_graph_proc(struct trace_seq *s, pid_t pid)
 }
 
 
+static enum print_line_t
+print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
+{
+       if (!trace_seq_putc(s, ' '))
+               return 0;
+
+       return trace_print_lat_fmt(s, entry);
+}
+
 /* If the pid changed since the last trace, output this event */
 static enum print_line_t
-verif_pid(struct trace_seq *s, pid_t pid, int cpu, pid_t *last_pids_cpu)
+verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
 {
        pid_t prev_pid;
        pid_t *last_pid;
        int ret;
 
-       if (!last_pids_cpu)
+       if (!data)
                return TRACE_TYPE_HANDLED;
 
-       last_pid = per_cpu_ptr(last_pids_cpu, cpu);
+       last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
 
        if (*last_pid == pid)
                return TRACE_TYPE_HANDLED;
@@ -291,26 +446,49 @@ static struct ftrace_graph_ret_entry *
 get_return_for_leaf(struct trace_iterator *iter,
                struct ftrace_graph_ent_entry *curr)
 {
-       struct ring_buffer_iter *ring_iter;
+       struct fgraph_data *data = iter->private;
+       struct ring_buffer_iter *ring_iter = NULL;
        struct ring_buffer_event *event;
        struct ftrace_graph_ret_entry *next;
 
-       ring_iter = iter->buffer_iter[iter->cpu];
+       /*
+        * If the previous output failed to write to the seq buffer,
+        * then we just reuse the data from before.
+        */
+       if (data && data->failed) {
+               curr = &data->ent;
+               next = &data->ret;
+       } else {
+
+               ring_iter = iter->buffer_iter[iter->cpu];
+
+               /* First peek to compare current entry and the next one */
+               if (ring_iter)
+                       event = ring_buffer_iter_peek(ring_iter, NULL);
+               else {
+                       /*
+                        * We need to consume the current entry to see
+                        * the next one.
+                        */
+                       ring_buffer_consume(iter->tr->buffer, iter->cpu, NULL);
+                       event = ring_buffer_peek(iter->tr->buffer, iter->cpu,
+                                                NULL);
+               }
 
-       /* First peek to compare current entry and the next one */
-       if (ring_iter)
-               event = ring_buffer_iter_peek(ring_iter, NULL);
-       else {
-       /* We need to consume the current entry to see the next one */
-               ring_buffer_consume(iter->tr->buffer, iter->cpu, NULL);
-               event = ring_buffer_peek(iter->tr->buffer, iter->cpu,
-                                       NULL);
-       }
+               if (!event)
+                       return NULL;
 
-       if (!event)
-               return NULL;
+               next = ring_buffer_event_data(event);
 
-       next = ring_buffer_event_data(event);
+               if (data) {
+                       /*
+                        * Save current and next entries for later reference
+                        * if the output fails.
+                        */
+                       data->ent = *curr;
+                       data->ret = *next;
+               }
+       }
 
        if (next->ent.type != TRACE_GRAPH_RET)
                return NULL;
@@ -386,6 +564,7 @@ print_graph_irq(struct trace_iterator *iter, unsigned long addr,
                if (ret == TRACE_TYPE_PARTIAL_LINE)
                        return TRACE_TYPE_PARTIAL_LINE;
        }
+
        /* Proc */
        if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
                ret = print_graph_proc(s, pid);
@@ -419,8 +598,8 @@ print_graph_irq(struct trace_iterator *iter, unsigned long addr,
        return TRACE_TYPE_HANDLED;
 }
 
-static enum print_line_t
-print_graph_duration(unsigned long long duration, struct trace_seq *s)
+enum print_line_t
+trace_print_graph_duration(unsigned long long duration, struct trace_seq *s)
 {
        unsigned long nsecs_rem = do_div(duration, 1000);
        /* log10(ULONG_MAX) + '\0' */
@@ -457,12 +636,23 @@ print_graph_duration(unsigned long long duration, struct trace_seq *s)
                if (!ret)
                        return TRACE_TYPE_PARTIAL_LINE;
        }
+       return TRACE_TYPE_HANDLED;
+}
+
+static enum print_line_t
+print_graph_duration(unsigned long long duration, struct trace_seq *s)
+{
+       int ret;
+
+       ret = trace_print_graph_duration(duration, s);
+       if (ret != TRACE_TYPE_HANDLED)
+               return ret;
 
        ret = trace_seq_printf(s, "|  ");
        if (!ret)
                return TRACE_TYPE_PARTIAL_LINE;
-       return TRACE_TYPE_HANDLED;
 
+       return TRACE_TYPE_HANDLED;
 }
 
 /* Case of a leaf function on its call entry */
@@ -471,6 +661,7 @@ print_graph_entry_leaf(struct trace_iterator *iter,
                struct ftrace_graph_ent_entry *entry,
                struct ftrace_graph_ret_entry *ret_entry, struct trace_seq *s)
 {
+       struct fgraph_data *data = iter->private;
        struct ftrace_graph_ret *graph_ret;
        struct ftrace_graph_ent *call;
        unsigned long long duration;
@@ -481,6 +672,18 @@ print_graph_entry_leaf(struct trace_iterator *iter,
        call = &entry->graph_ent;
        duration = graph_ret->rettime - graph_ret->calltime;
 
+       if (data) {
+               int cpu = iter->cpu;
+               int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
+
+               /*
+                * Comments display at + 1 to depth. Since
+                * this is a leaf function, keep the comments
+                * equal to this depth.
+                */
+               *depth = call->depth - 1;
+       }
+
        /* Overhead */
        ret = print_graph_overhead(duration, s);
        if (!ret)
@@ -500,11 +703,7 @@ print_graph_entry_leaf(struct trace_iterator *iter,
                        return TRACE_TYPE_PARTIAL_LINE;
        }
 
-       ret = seq_print_ip_sym(s, call->func, 0);
-       if (!ret)
-               return TRACE_TYPE_PARTIAL_LINE;
-
-       ret = trace_seq_printf(s, "();\n");
+       ret = trace_seq_printf(s, "%ps();\n", (void *)call->func);
        if (!ret)
                return TRACE_TYPE_PARTIAL_LINE;
 
@@ -512,12 +711,21 @@ print_graph_entry_leaf(struct trace_iterator *iter,
 }
 
 static enum print_line_t
-print_graph_entry_nested(struct ftrace_graph_ent_entry *entry,
-                       struct trace_seq *s, pid_t pid, int cpu)
+print_graph_entry_nested(struct trace_iterator *iter,
+                        struct ftrace_graph_ent_entry *entry,
+                        struct trace_seq *s, int cpu)
 {
-       int i;
-       int ret;
        struct ftrace_graph_ent *call = &entry->graph_ent;
+       struct fgraph_data *data = iter->private;
+       int ret;
+       int i;
+
+       if (data) {
+               int cpu = iter->cpu;
+               int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
+
+               *depth = call->depth;
+       }
 
        /* No overhead */
        ret = print_graph_overhead(-1, s);
@@ -538,11 +746,7 @@ print_graph_entry_nested(struct ftrace_graph_ent_entry *entry,
                        return TRACE_TYPE_PARTIAL_LINE;
        }
 
-       ret = seq_print_ip_sym(s, call->func, 0);
-       if (!ret)
-               return TRACE_TYPE_PARTIAL_LINE;
-
-       ret = trace_seq_printf(s, "() {\n");
+       ret = trace_seq_printf(s, "%ps() {\n", (void *)call->func);
        if (!ret)
                return TRACE_TYPE_PARTIAL_LINE;
 
@@ -554,24 +758,24 @@ print_graph_entry_nested(struct ftrace_graph_ent_entry *entry,
 }
 
 static enum print_line_t
-print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
-                       struct trace_iterator *iter)
+print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
+                    int type, unsigned long addr)
 {
-       int ret;
-       int cpu = iter->cpu;
-       pid_t *last_entry = iter->private;
+       struct fgraph_data *data = iter->private;
        struct trace_entry *ent = iter->ent;
-       struct ftrace_graph_ent *call = &field->graph_ent;
-       struct ftrace_graph_ret_entry *leaf_ret;
+       int cpu = iter->cpu;
+       int ret;
 
        /* Pid */
-       if (verif_pid(s, ent->pid, cpu, last_entry) == TRACE_TYPE_PARTIAL_LINE)
+       if (verif_pid(s, ent->pid, cpu, data) == TRACE_TYPE_PARTIAL_LINE)
                return TRACE_TYPE_PARTIAL_LINE;
 
-       /* Interrupt */
-       ret = print_graph_irq(iter, call->func, TRACE_GRAPH_ENT, cpu, ent->pid);
-       if (ret == TRACE_TYPE_PARTIAL_LINE)
-               return TRACE_TYPE_PARTIAL_LINE;
+       if (type) {
+               /* Interrupt */
+               ret = print_graph_irq(iter, addr, type, cpu, ent->pid);
+               if (ret == TRACE_TYPE_PARTIAL_LINE)
+                       return TRACE_TYPE_PARTIAL_LINE;
+       }
 
        /* Absolute time */
        if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) {
@@ -598,52 +802,75 @@ print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
                        return TRACE_TYPE_PARTIAL_LINE;
        }
 
+       /* Latency format */
+       if (trace_flags & TRACE_ITER_LATENCY_FMT) {
+               ret = print_graph_lat_fmt(s, ent);
+               if (ret == TRACE_TYPE_PARTIAL_LINE)
+                       return TRACE_TYPE_PARTIAL_LINE;
+       }
+
+       return 0;
+}
+
+static enum print_line_t
+print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
+                       struct trace_iterator *iter)
+{
+       struct fgraph_data *data = iter->private;
+       struct ftrace_graph_ent *call = &field->graph_ent;
+       struct ftrace_graph_ret_entry *leaf_ret;
+       static enum print_line_t ret;
+       int cpu = iter->cpu;
+
+       if (print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func))
+               return TRACE_TYPE_PARTIAL_LINE;
+
        leaf_ret = get_return_for_leaf(iter, field);
        if (leaf_ret)
-               return print_graph_entry_leaf(iter, field, leaf_ret, s);
+               ret = print_graph_entry_leaf(iter, field, leaf_ret, s);
        else
-               return print_graph_entry_nested(field, s, iter->ent->pid, cpu);
+               ret = print_graph_entry_nested(iter, field, s, cpu);
+
+       if (data) {
+               /*
+                * If we failed to write our output, then we need to make
+                * note of it. Because we already consumed our entry.
+                */
+               if (s->full) {
+                       data->failed = 1;
+                       data->cpu = cpu;
+               } else
+                       data->failed = 0;
+       }
 
+       return ret;
 }
 
 static enum print_line_t
 print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
                   struct trace_entry *ent, struct trace_iterator *iter)
 {
-       int i;
-       int ret;
-       int cpu = iter->cpu;
-       pid_t *last_pid = iter->private, pid = ent->pid;
        unsigned long long duration = trace->rettime - trace->calltime;
+       struct fgraph_data *data = iter->private;
+       pid_t pid = ent->pid;
+       int cpu = iter->cpu;
+       int ret;
+       int i;
 
-       /* Pid */
-       if (verif_pid(s, pid, cpu, last_pid) == TRACE_TYPE_PARTIAL_LINE)
-               return TRACE_TYPE_PARTIAL_LINE;
-
-       /* Absolute time */
-       if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) {
-               ret = print_graph_abs_time(iter->ts, s);
-               if (!ret)
-                       return TRACE_TYPE_PARTIAL_LINE;
-       }
+       if (data) {
+               int cpu = iter->cpu;
+               int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
 
-       /* Cpu */
-       if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
-               ret = print_graph_cpu(s, cpu);
-               if (ret == TRACE_TYPE_PARTIAL_LINE)
-                       return TRACE_TYPE_PARTIAL_LINE;
+               /*
+                * Comments display at + 1 to depth. This is the
+                * return from a function, we now want the comments
+                * to display at the same level of the bracket.
+                */
+               *depth = trace->depth - 1;
        }
 
-       /* Proc */
-       if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
-               ret = print_graph_proc(s, ent->pid);
-               if (ret == TRACE_TYPE_PARTIAL_LINE)
-                       return TRACE_TYPE_PARTIAL_LINE;
-
-               ret = trace_seq_printf(s, " | ");
-               if (!ret)
-                       return TRACE_TYPE_PARTIAL_LINE;
-       }
+       if (print_graph_prologue(iter, s, 0, 0))
+               return TRACE_TYPE_PARTIAL_LINE;
 
        /* Overhead */
        ret = print_graph_overhead(duration, s);
@@ -684,42 +911,21 @@ print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
 }
 
 static enum print_line_t
-print_graph_comment(struct print_entry *trace, struct trace_seq *s,
-                  struct trace_entry *ent, struct trace_iterator *iter)
+print_graph_comment(struct trace_seq *s,  struct trace_entry *ent,
+                   struct trace_iterator *iter)
 {
-       int i;
+       unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK);
+       struct fgraph_data *data = iter->private;
+       struct trace_event *event;
+       int depth = 0;
        int ret;
-       int cpu = iter->cpu;
-       pid_t *last_pid = iter->private;
-
-       /* Pid */
-       if (verif_pid(s, ent->pid, cpu, last_pid) == TRACE_TYPE_PARTIAL_LINE)
-               return TRACE_TYPE_PARTIAL_LINE;
-
-       /* Absolute time */
-       if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME) {
-               ret = print_graph_abs_time(iter->ts, s);
-               if (!ret)
-                       return TRACE_TYPE_PARTIAL_LINE;
-       }
+       int i;
 
-       /* Cpu */
-       if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU) {
-               ret = print_graph_cpu(s, cpu);
-               if (ret == TRACE_TYPE_PARTIAL_LINE)
-                       return TRACE_TYPE_PARTIAL_LINE;
-       }
+       if (data)
+               depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth;
 
-       /* Proc */
-       if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC) {
-               ret = print_graph_proc(s, ent->pid);
-               if (ret == TRACE_TYPE_PARTIAL_LINE)
-                       return TRACE_TYPE_PARTIAL_LINE;
-
-               ret = trace_seq_printf(s, " | ");
-               if (!ret)
-                       return TRACE_TYPE_PARTIAL_LINE;
-       }
+       if (print_graph_prologue(iter, s, 0, 0))
+               return TRACE_TYPE_PARTIAL_LINE;
 
        /* No overhead */
        ret = print_graph_overhead(-1, s);
@@ -734,18 +940,39 @@ print_graph_comment(struct print_entry *trace, struct trace_seq *s,
        }
 
        /* Indentation */
-       if (trace->depth > 0)
-               for (i = 0; i < (trace->depth + 1) * TRACE_GRAPH_INDENT; i++) {
+       if (depth > 0)
+               for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) {
                        ret = trace_seq_printf(s, " ");
                        if (!ret)
                                return TRACE_TYPE_PARTIAL_LINE;
                }
 
        /* The comment */
-       ret = trace_seq_printf(s, "/* %s", trace->buf);
+       ret = trace_seq_printf(s, "/* ");
        if (!ret)
                return TRACE_TYPE_PARTIAL_LINE;
 
+       switch (iter->ent->type) {
+       case TRACE_BPRINT:
+               ret = trace_print_bprintk_msg_only(iter);
+               if (ret != TRACE_TYPE_HANDLED)
+                       return ret;
+               break;
+       case TRACE_PRINT:
+               ret = trace_print_printk_msg_only(iter);
+               if (ret != TRACE_TYPE_HANDLED)
+                       return ret;
+               break;
+       default:
+               event = ftrace_find_event(ent->type);
+               if (!event)
+                       return TRACE_TYPE_UNHANDLED;
+
+               ret = event->trace(iter, sym_flags);
+               if (ret != TRACE_TYPE_HANDLED)
+                       return ret;
+       }
+
        /* Strip ending newline */
        if (s->buffer[s->len - 1] == '\n') {
                s->buffer[s->len - 1] = '\0';
@@ -763,52 +990,112 @@ print_graph_comment(struct print_entry *trace, struct trace_seq *s,
 enum print_line_t
 print_graph_function(struct trace_iterator *iter)
 {
-       struct trace_seq *s = &iter->seq;
+       struct ftrace_graph_ent_entry *field;
+       struct fgraph_data *data = iter->private;
        struct trace_entry *entry = iter->ent;
+       struct trace_seq *s = &iter->seq;
+       int cpu = iter->cpu;
+       int ret;
+
+       if (data && per_cpu_ptr(data->cpu_data, cpu)->ignore) {
+               per_cpu_ptr(data->cpu_data, cpu)->ignore = 0;
+               return TRACE_TYPE_HANDLED;
+       }
+
+       /*
+        * If the last output failed, there's a possibility we need
+        * to print out the missing entry which would never go out.
+        */
+       if (data && data->failed) {
+               field = &data->ent;
+               iter->cpu = data->cpu;
+               ret = print_graph_entry(field, s, iter);
+               if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) {
+                       per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1;
+                       ret = TRACE_TYPE_NO_CONSUME;
+               }
+               iter->cpu = cpu;
+               return ret;
+       }
 
        switch (entry->type) {
        case TRACE_GRAPH_ENT: {
-               struct ftrace_graph_ent_entry *field;
+               /*
+                * print_graph_entry() may consume the current event,
+                * thus @field may become invalid, so we need to save it.
+                * sizeof(struct ftrace_graph_ent_entry) is very small,
+                * it can be safely saved at the stack.
+                */
+               struct ftrace_graph_ent_entry saved;
                trace_assign_type(field, entry);
-               return print_graph_entry(field, s, iter);
+               saved = *field;
+               return print_graph_entry(&saved, s, iter);
        }
        case TRACE_GRAPH_RET: {
                struct ftrace_graph_ret_entry *field;
                trace_assign_type(field, entry);
                return print_graph_return(&field->ret, s, entry, iter);
        }
-       case TRACE_PRINT: {
-               struct print_entry *field;
-               trace_assign_type(field, entry);
-               return print_graph_comment(field, s, entry, iter);
-       }
        default:
-               return TRACE_TYPE_UNHANDLED;
+               return print_graph_comment(s, entry, iter);
        }
+
+       return TRACE_TYPE_HANDLED;
+}
+
+static void print_lat_header(struct seq_file *s)
+{
+       static const char spaces[] = "                " /* 16 spaces */
+               "    "                                  /* 4 spaces */
+               "                 ";                    /* 17 spaces */
+       int size = 0;
+
+       if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
+               size += 16;
+       if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
+               size += 4;
+       if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
+               size += 17;
+
+       seq_printf(s, "#%.*s  _-----=> irqs-off        \n", size, spaces);
+       seq_printf(s, "#%.*s / _----=> need-resched    \n", size, spaces);
+       seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces);
+       seq_printf(s, "#%.*s|| / _--=> preempt-depth   \n", size, spaces);
+       seq_printf(s, "#%.*s||| / _-=> lock-depth      \n", size, spaces);
+       seq_printf(s, "#%.*s|||| /                     \n", size, spaces);
 }
 
 static void print_graph_headers(struct seq_file *s)
 {
+       int lat = trace_flags & TRACE_ITER_LATENCY_FMT;
+
+       if (lat)
+               print_lat_header(s);
+
        /* 1st line */
-       seq_printf(s, "# ");
+       seq_printf(s, "#");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
                seq_printf(s, "     TIME       ");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
-               seq_printf(s, "CPU");
+               seq_printf(s, " CPU");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
-               seq_printf(s, "  TASK/PID      ");
+               seq_printf(s, "  TASK/PID       ");
+       if (lat)
+               seq_printf(s, "|||||");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
                seq_printf(s, "  DURATION   ");
        seq_printf(s, "               FUNCTION CALLS\n");
 
        /* 2nd line */
-       seq_printf(s, "# ");
+       seq_printf(s, "#");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_ABS_TIME)
                seq_printf(s, "      |         ");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_CPU)
-               seq_printf(s, "|  ");
+               seq_printf(s, " |  ");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_PROC)
-               seq_printf(s, "  |    |        ");
+               seq_printf(s, "   |    |        ");
+       if (lat)
+               seq_printf(s, "|||||");
        if (tracer_flags.val & TRACE_GRAPH_PRINT_DURATION)
                seq_printf(s, "   |   |      ");
        seq_printf(s, "               |   |   |   |\n");
@@ -816,33 +1103,58 @@ static void print_graph_headers(struct seq_file *s)
 
 static void graph_trace_open(struct trace_iterator *iter)
 {
-       /* pid on the last trace processed */
-       pid_t *last_pid = alloc_percpu(pid_t);
+       /* pid and depth on the last trace processed */
+       struct fgraph_data *data;
        int cpu;
 
-       if (!last_pid)
-               pr_warning("function graph tracer: not enough memory\n");
-       else
-               for_each_possible_cpu(cpu) {
-                       pid_t *pid = per_cpu_ptr(last_pid, cpu);
-                       *pid = -1;
-               }
+       iter->private = NULL;
+
+       data = kzalloc(sizeof(*data), GFP_KERNEL);
+       if (!data)
+               goto out_err;
 
-       iter->private = last_pid;
+       data->cpu_data = alloc_percpu(struct fgraph_cpu_data);
+       if (!data->cpu_data)
+               goto out_err_free;
+
+       for_each_possible_cpu(cpu) {
+               pid_t *pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
+               int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
+               int *ignore = &(per_cpu_ptr(data->cpu_data, cpu)->ignore);
+               *pid = -1;
+               *depth = 0;
+               *ignore = 0;
+       }
+
+       iter->private = data;
+
+       return;
+
+ out_err_free:
+       kfree(data);
+ out_err:
+       pr_warning("function graph tracer: not enough memory\n");
 }
 
 static void graph_trace_close(struct trace_iterator *iter)
 {
-       percpu_free(iter->private);
+       struct fgraph_data *data = iter->private;
+
+       if (data) {
+               free_percpu(data->cpu_data);
+               kfree(data);
+       }
 }
 
 static struct tracer graph_trace __read_mostly = {
-       .name           = "function_graph",
+       .name           = "function_graph",
        .open           = graph_trace_open,
+       .pipe_open      = graph_trace_open,
        .close          = graph_trace_close,
+       .pipe_close     = graph_trace_close,
        .wait_pipe      = poll_wait_pipe,
-       .init           = graph_trace_init,
-       .reset          = graph_trace_reset,
+       .init           = graph_trace_init,
+       .reset          = graph_trace_reset,
        .print_line     = print_graph_function,
        .print_header   = print_graph_headers,
        .flags          = &tracer_flags,
@@ -853,6 +1165,8 @@ static struct tracer graph_trace __read_mostly = {
 
 static __init int init_graph_trace(void)
 {
+       max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1);
+
        return register_tracer(&graph_trace);
 }