linux/scripts/tracing/draw_functrace.py

130 lines
3.5 KiB
Python
Raw Normal View History

#!/usr/bin/env python
# SPDX-License-Identifier: GPL-2.0-only
"""
Copyright 2008 (c) Frederic Weisbecker <fweisbec@gmail.com>
This script parses a trace provided by the function tracer in
kernel/trace/trace_functions.c
The resulted trace is processed into a tree to produce a more human
view of the call stack by drawing textual but hierarchical tree of
calls. Only the functions's names and the call time are provided.
Usage:
Be sure that you have CONFIG_FUNCTION_TRACER
# mount -t tracefs nodev /sys/kernel/tracing
# echo function > /sys/kernel/tracing/current_tracer
$ cat /sys/kernel/tracing/trace_pipe > ~/raw_trace_func
Wait some times but not too much, the script is a bit slow.
Break the pipe (Ctrl + Z)
scripts/tracing: fix the bug that can't parse raw_trace_func Since commit 77271ce4b2c0 ("tracing: Add irq, preempt-count and need resched info to default trace output"), the default trace output format has been changed to: <idle>-0 [009] d.h. 22420.068695: _raw_spin_lock_irqsave <-hrtimer_interrupt <idle>-0 [000] ..s. 22420.068695: _nohz_idle_balance <-run_rebalance_domains <idle>-0 [011] d.h. 22420.068695: account_process_tick <-update_process_times origin trace output format:(before v3.2.0) # tracer: nop # # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | migration/0-6 [000] 50.025810: rcu_note_context_switch <-__schedule migration/0-6 [000] 50.025812: trace_rcu_utilization <-rcu_note_context_switch migration/0-6 [000] 50.025813: rcu_sched_qs <-rcu_note_context_switch migration/0-6 [000] 50.025815: rcu_preempt_qs <-rcu_note_context_switch migration/0-6 [000] 50.025817: trace_rcu_utilization <-rcu_note_context_switch migration/0-6 [000] 50.025818: debug_lockdep_rcu_enabled <-__schedule migration/0-6 [000] 50.025820: debug_lockdep_rcu_enabled <-__schedule The draw_functrace.py(introduced in v2.6.28) can't parse the new version format trace_func, So we need modify draw_functrace.py to adapt the new version trace output format. Link: https://lkml.kernel.org/r/20210611022107.608787-1-suhui@zeku.com Cc: stable@vger.kernel.org Fixes: 77271ce4b2c0 tracing: Add irq, preempt-count and need resched info to default trace output Signed-off-by: Hui Su <suhui@zeku.com> Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
2021-06-11 05:21:07 +03:00
$ scripts/tracing/draw_functrace.py < ~/raw_trace_func > draw_functrace
Then you have your drawn trace in draw_functrace
"""
import sys, re
class CallTree:
""" This class provides a tree representation of the functions
call stack. If a function has no parent in the kernel (interrupt,
syscall, kernel thread...) then it is attached to a virtual parent
called ROOT.
"""
ROOT = None
def __init__(self, func, time = None, parent = None):
self._func = func
self._time = time
if parent is None:
self._parent = CallTree.ROOT
else:
self._parent = parent
self._children = []
def calls(self, func, calltime):
""" If a function calls another one, call this method to insert it
into the tree at the appropriate place.
@return: A reference to the newly created child node.
"""
child = CallTree(func, calltime, self)
self._children.append(child)
return child
def getParent(self, func):
""" Retrieve the last parent of the current node that
has the name given by func. If this function is not
on a parent, then create it as new child of root
@return: A reference to the parent.
"""
tree = self
while tree != CallTree.ROOT and tree._func != func:
tree = tree._parent
if tree == CallTree.ROOT:
child = CallTree.ROOT.calls(func, None)
return child
return tree
def __repr__(self):
return self.__toString("", True)
def __toString(self, branch, lastChild):
if self._time is not None:
s = "%s----%s (%s)\n" % (branch, self._func, self._time)
else:
s = "%s----%s\n" % (branch, self._func)
i = 0
if lastChild:
branch = branch[:-1] + " "
while i < len(self._children):
if i != len(self._children) - 1:
s += "%s" % self._children[i].__toString(branch +\
" |", False)
else:
s += "%s" % self._children[i].__toString(branch +\
" |", True)
i += 1
return s
class BrokenLineException(Exception):
"""If the last line is not complete because of the pipe breakage,
we want to stop the processing and ignore this line.
"""
pass
class CommentLineException(Exception):
""" If the line is a comment (as in the beginning of the trace file),
just ignore it.
"""
pass
def parseLine(line):
line = line.strip()
if line.startswith("#"):
raise CommentLineException
scripts/tracing: fix the bug that can't parse raw_trace_func Since commit 77271ce4b2c0 ("tracing: Add irq, preempt-count and need resched info to default trace output"), the default trace output format has been changed to: <idle>-0 [009] d.h. 22420.068695: _raw_spin_lock_irqsave <-hrtimer_interrupt <idle>-0 [000] ..s. 22420.068695: _nohz_idle_balance <-run_rebalance_domains <idle>-0 [011] d.h. 22420.068695: account_process_tick <-update_process_times origin trace output format:(before v3.2.0) # tracer: nop # # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | migration/0-6 [000] 50.025810: rcu_note_context_switch <-__schedule migration/0-6 [000] 50.025812: trace_rcu_utilization <-rcu_note_context_switch migration/0-6 [000] 50.025813: rcu_sched_qs <-rcu_note_context_switch migration/0-6 [000] 50.025815: rcu_preempt_qs <-rcu_note_context_switch migration/0-6 [000] 50.025817: trace_rcu_utilization <-rcu_note_context_switch migration/0-6 [000] 50.025818: debug_lockdep_rcu_enabled <-__schedule migration/0-6 [000] 50.025820: debug_lockdep_rcu_enabled <-__schedule The draw_functrace.py(introduced in v2.6.28) can't parse the new version format trace_func, So we need modify draw_functrace.py to adapt the new version trace output format. Link: https://lkml.kernel.org/r/20210611022107.608787-1-suhui@zeku.com Cc: stable@vger.kernel.org Fixes: 77271ce4b2c0 tracing: Add irq, preempt-count and need resched info to default trace output Signed-off-by: Hui Su <suhui@zeku.com> Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
2021-06-11 05:21:07 +03:00
m = re.match("[^]]+?\\] +([a-z.]+) +([0-9.]+): (\\w+) <-(\\w+)", line)
if m is None:
raise BrokenLineException
scripts/tracing: fix the bug that can't parse raw_trace_func Since commit 77271ce4b2c0 ("tracing: Add irq, preempt-count and need resched info to default trace output"), the default trace output format has been changed to: <idle>-0 [009] d.h. 22420.068695: _raw_spin_lock_irqsave <-hrtimer_interrupt <idle>-0 [000] ..s. 22420.068695: _nohz_idle_balance <-run_rebalance_domains <idle>-0 [011] d.h. 22420.068695: account_process_tick <-update_process_times origin trace output format:(before v3.2.0) # tracer: nop # # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | migration/0-6 [000] 50.025810: rcu_note_context_switch <-__schedule migration/0-6 [000] 50.025812: trace_rcu_utilization <-rcu_note_context_switch migration/0-6 [000] 50.025813: rcu_sched_qs <-rcu_note_context_switch migration/0-6 [000] 50.025815: rcu_preempt_qs <-rcu_note_context_switch migration/0-6 [000] 50.025817: trace_rcu_utilization <-rcu_note_context_switch migration/0-6 [000] 50.025818: debug_lockdep_rcu_enabled <-__schedule migration/0-6 [000] 50.025820: debug_lockdep_rcu_enabled <-__schedule The draw_functrace.py(introduced in v2.6.28) can't parse the new version format trace_func, So we need modify draw_functrace.py to adapt the new version trace output format. Link: https://lkml.kernel.org/r/20210611022107.608787-1-suhui@zeku.com Cc: stable@vger.kernel.org Fixes: 77271ce4b2c0 tracing: Add irq, preempt-count and need resched info to default trace output Signed-off-by: Hui Su <suhui@zeku.com> Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
2021-06-11 05:21:07 +03:00
return (m.group(2), m.group(3), m.group(4))
def main():
CallTree.ROOT = CallTree("Root (Nowhere)", None, None)
tree = CallTree.ROOT
for line in sys.stdin:
try:
calltime, callee, caller = parseLine(line)
except BrokenLineException:
break
except CommentLineException:
continue
tree = tree.getParent(caller)
tree = tree.calls(callee, calltime)
print(CallTree.ROOT)
if __name__ == "__main__":
main()