Skip to content
  • Steven Rostedt's avatar
    ftrace: Add function names to dangling } in function graph tracer · f1c7f517
    Steven Rostedt authored
    
    
    The function graph tracer is currently the most invasive tracer
    in the ftrace family. It can easily overflow the buffer even with
    10megs per CPU. This means that events can often be lost.
    
    On start up, or after events are lost, if the function return is
    recorded but the function enter was lost, all we get to see is the
    exiting '}'.
    
    Here is how a typical trace output starts:
    
     [tracing] cat trace
     # tracer: function_graph
     #
     # CPU  DURATION                  FUNCTION CALLS
     # |     |   |                     |   |   |   |
      0) + 91.897 us   |                  }
      0) ! 567.961 us  |                }
      0)   <========== |
      0) ! 579.083 us  |                _raw_spin_lock_irqsave();
      0)   4.694 us    |                _raw_spin_unlock_irqrestore();
      0) ! 594.862 us  |              }
      0) ! 603.361 us  |            }
      0) ! 613.574 us  |          }
      0) ! 623.554 us  |        }
      0)   3.653 us    |        fget_light();
      0)               |        sock_poll() {
    
    There are a series of '}' with no matching "func() {". There's no information
    to what functions these ending brackets belong to.
    
    This patch adds a stack on the per cpu structure used in outputting
    the function graph tracer to keep track of what function was outputted.
    Then on a function exit event, it checks the depth to see if the
    function exit has a matching entry event. If it does, then it only
    prints the '}', otherwise it adds the function name after the '}'.
    
    This allows function exit events to show what function they belong to
    at trace output startup, when the entry was lost due to ring buffer
    overflow, or even after a new task is scheduled in.
    
    Here is what the above trace will look like after this patch:
    
     [tracing] cat trace
     # tracer: function_graph
     #
     # CPU  DURATION                  FUNCTION CALLS
     # |     |   |                     |   |   |   |
      0) + 91.897 us   |                  } (irq_exit)
      0) ! 567.961 us  |                } (smp_apic_timer_interrupt)
      0)   <========== |
      0) ! 579.083 us  |                _raw_spin_lock_irqsave();
      0)   4.694 us    |                _raw_spin_unlock_irqrestore();
      0) ! 594.862 us  |              } (add_wait_queue)
      0) ! 603.361 us  |            } (__pollwait)
      0) ! 613.574 us  |          } (tcp_poll)
      0) ! 623.554 us  |        } (sock_poll)
      0)   3.653 us    |        fget_light();
      0)               |        sock_poll() {
    
    Signed-off-by: default avatarSteven Rostedt <rostedt@goodmis.org>
    f1c7f517