Provided by: uftrace_0.17-1_amd64 
NAME
uftrace-graph - Show function call graph
SYNOPSIS
uftrace graph [options] [FUNCTION]
DESCRIPTION
This command shows a function call graph for the binary or the given function in a uftrace record
datafile. If the function name is omitted, whole function call graph will be shown. If a user provides
a function name, it will show backtrace and calling functions. Each function in the output is annotated
with a hit count and the total time spent running that function.
GRAPH OPTIONS
-f FIELD, --output-fields=FIELD
Customize field in the output. Possible values are: total, self and addr. Multiple fields can be
set by using comma. Special field of `none' can be used (solely) to hide all fields. Default is
`total'. See FIELDS.
--task Print task graph instead of normal function graph. Each node in the output shows a process or
thread(printed in green color).
--srcline
Show source location of each function if available.
--format=TYPE
Show format style output. Currently, normal and html styles are supported.
COMMON OPTIONS
-F FUNC, --filter=FUNC
Set filter to trace selected functions and their children functions. This option can be used more
than once. See uftrace-replay(1) for an explanation of filters.
-N FUNC, --notrace=FUNC
Set filter not to trace selected functions and their children functions. This option can be used
more than once. See uftrace-replay(1) for an explanation of filters.
-C FUNC, --caller-filter=FUNC
Set filter to trace callers of selected functions only. This option can be used more than once.
See uftrace-replay(1) for an explanation of filters.
-T TRG, --trigger=TRG
Set trigger on selected functions. This option can be used more than once. See uftrace-replay(1)
for an explanation of triggers.
-D DEPTH, --depth DEPTH
Set trace limit in nesting level.
-t TIME, --time-filter=TIME
Do not show functions which run under the time threshold. If some functions explicitly have the
`trace' trigger applied, those are always traced regardless of execution time.
-Z SIZE, --size-filter=SIZE
Do not show functions smaller than SIZE bytes.
-L LOCATION, --loc-filter=LOCATION
Set filter to trace selected source locations. This option can be used more than once.
--no-libcall
Do not show library calls.
--no-event
Do not show any events. Implies --no-sched.
--no-sched
Do not show schedule events.
--no-sched-preempt
Do not show preempt schedule events but show regular(sleeping) schedule events.
--match=TYPE
Use pattern match using TYPE. Possible types are regex and glob. Default is regex.
--with-syms=DIR
Read symbol data from the .sym files in DIR directory instead of the binary. This can be useful
to deal with stripped binaries. The file name of the main binary should be the same when saved
and used.
COMMON ANALYSIS OPTIONS
-H FUNC, --hide=FUNC
Set filter not to trace selected functions. It doesn’t affect their subtrees, but hides only the
given functions. This option can be used more than once. See uftrace-replay(1) for an
explanation of filters.
--kernel-full
Show all kernel functions called outside of user functions.
--kernel-only
Show kernel functions only without user functions.
--event-full
Show all (user) events outside of user functions.
--tid=TID[,TID,...]
Only print functions called by the given tasks. To see the list of tasks in the data file, you
can use uftrace report --task or uftrace info. This option can also be used more than once.
--demangle=TYPE
Use demangled C++ symbol names for filters, triggers, arguments and/or return values. Possible
values are “full”, “simple” and “no”. Default is “simple” which ignores function arguments and
template parameters.
-r RANGE, --time-range=RANGE
Only show functions executed within the time RANGE. The RANGE can be <start>~<stop> (separated by
“~”) and one of <start> and <stop> can be omitted. The <start> and <stop> are timestamp or
elapsed time if they have <time_unit> postfix, for example `100us'. The timestamp or elapsed time
can be shown with -f time or -f elapsed option respectively in uftrace replay(1).
EXAMPLES
This command show data like below:
$ uftrace record loop
$ uftrace replay
# DURATION TID FUNCTION
[24447] | main() {
[24447] | foo() {
8.134 us [24447] | loop();
7.296 us [24447] | loop();
7.234 us [24447] | loop();
24.324 us [24447] | } /* foo */
[24447] | foo() {
7.234 us [24447] | loop();
7.231 us [24447] | loop();
7.231 us [24447] | loop();
22.302 us [24447] | } /* foo */
[24447] | bar() {
10.100 ms [24447] | usleep();
10.138 ms [24447] | } /* bar */
10.293 ms [24447] | } /* main */
Running the graph command shows function call graph like below:
$ uftrace graph
# Function Call Graph for 'loop' (session: 073f1e84aa8b09d3)
========== FUNCTION CALL GRAPH ==========
10.293 ms : (1) loop
10.293 ms : (1) main
46.626 us : +-(2) foo
44.360 us : | (6) loop
: |
10.138 ms : +-(1) bar
10.100 ms : (1) usleep
The graph root is not a function, but the executing process itself. The left side shows total time
running the function on the right side. The number in parentheses before the function name is the
invocation count. As you can see, main was called once and ran for 10 msec. It called foo twice and
then foo called loop 6 times in total. The printed time is the total execution time for all function
invocations.
It can also be seen that main called bar once and that bar then called usleep once. To minimize nesting,
the output shows calls at the same level if only a single call path exists. Since the nodes usleep and
main are not directly connected, usleep is not called from main directly.
Running the graph command on the main function shows called functions and backtrace like below:
$ uftrace graph main
# Function Call Graph for 'main' (session: 073f1e84aa8b09d3)
=============== BACKTRACE ===============
backtrace #0: hit 1, time 10.293 ms
[0] main (0x4004f0)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME FUNCTION
10.293 ms : (1) main
46.626 us : +-(2) foo
44.360 us : | (6) loop
: |
10.138 ms : +-(1) bar
10.100 ms : (1) usleep
Note that the `main' is the top-level function so it has no backtrace above itself. Running the graph
command on a leaf function looks like below.
$ uftrace graph loop
# Function Call Graph for 'loop' (session: 073f1e84aa8b09d3)
=============== BACKTRACE ===============
backtrace #0: hit 6, time 44.360 us
[0] main (0x4004b0)
[1] foo (0x400622)
[2] loop (0x400f5f6)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME FUNCTION
44.360 us : (6) loop
The backtrace shows that loop is called from foo and that foo is called from main. Since loop is a leaf
function, it didn’t call any other function. In this case, loop was called only from a single path so
backtrace #0 is hit 6 times.
While graph command shows function-level call graph, –task option makes the output in task-level graph
which shows how processes and threads are created. The term here task includes process and thread.
For example, the task graph of GCC compiler can be shown as follows:
$ uftrace record --force /usr/bin/gcc hello.c
$ uftrace graph --task
========== TASK GRAPH ==========
# TOTAL TIME SELF TIME TID TASK NAME
159.854 ms 4.440 ms [ 82723] : gcc
: |
90.951 ms 90.951 ms [ 82734] : +----cc1
: |
17.150 ms 17.150 ms [ 82735] : +----as
: |
45.183 ms 6.076 ms [ 82736] : +----collect2
: |
38.880 ms 38.880 ms [ 82737] : +----ld
The above output shows gcc created cc1, as, and collect2 processes then collect2 created ld process.
TOTAL TIME is the lifetime of the task from its creation to termination, and SELF TIME is also lifetime,
but it excludes internal idle time. TID is the thread id of the task.
The following shows task graph of uftrace recording itself. It shows uftrace created t-abc process, and
also created many threads whose names are all WriterThread.
$ uftrace record -P. ./uftrace record -d uftrace.data.abc t-abc
$ uftrace graph --task
========== TASK GRAPH ==========
# TOTAL TIME SELF TIME TID TASK NAME
404.929 ms 321.692 ms [ 4230] : uftrace
: |
278.662 us 278.662 us [ 4241] : +----t-abc
: |
33.754 ms 4.061 ms [ 4242] : +-WriterThread
27.415 ms 120.992 us [ 4244] : +-WriterThread
27.212 ms 8.119 ms [ 4245] : +-WriterThread
26.754 ms 6.616 ms [ 4248] : +-WriterThread
26.859 ms 8.154 ms [ 4247] : +-WriterThread
26.509 ms 1.645 ms [ 4243] : +-WriterThread
25.320 ms 57.350 us [ 4246] : +-WriterThread
24.757 ms 4.391 ms [ 4249] : +-WriterThread
26.040 ms 3.707 ms [ 4250] : +-WriterThread
24.004 ms 3.999 ms [ 4251] : +-WriterThread
Please note that the indentation depth of thread is different from process.
Running the graph command with --srcline option shows source location in call graph like below:
$ uftrace record --srcline t-abc
$ uftrace graph --srcline
# Function Call Graph for 't-abc' (session: 60195bac953d8736)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME FUNCTION [SOURCE]
8.909 us : (1) t-abc
1.260 us : +-(1) __monstartup
: |
0.179 us : +-(1) __cxa_atexit
: |
7.470 us : +-(1) main [tests/s-abc.c:26]
5.522 us : (1) a [tests/s-abc.c:11]
4.912 us : (1) b [tests/s-abc.c:16]
4.176 us : (1) c [tests/s-abc.c:21]
0.794 us : (1) getpid
FIELDS
The uftrace allows for user to customize the graph output with some of fields. Here the field means info
on the left side of the colon (:) character. By default it uses time only, but you can use other fields
in any order like:
$ uftrace record tests/t-abc
$ uftrace graph -f total,self,addr
# Function Call Graph for 't-sort' (session: b007f4b7cf792878)
========== FUNCTION CALL GRAPH ==========
# TOTAL TIME SELF TIME ADDRESS FUNCTION
10.145 ms 561f652cd610 : (1) t-sort
10.145 ms 39.890 us 561f652cd610 : (1) main
16.773 us 0.734 us 561f652cd7ce : +-(2) foo
16.039 us 16.039 us 561f652cd7a0 : | (6) loop
: |
10.088 ms 14.740 us 561f652cd802 : +-(1) bar
10.073 ms 10.073 ms 561f652cd608 : (1) usleep
Each field has following meaning:
• total: function execution time in total
• self : function execution time excluding its children’s
• addr : address of the function
The default value is `total'. If given field name starts with “+”, then it’ll be appended to the default
fields. So “-f +addr” is as same as “-f total,addr”. And it also accepts a special field name of `none'
which disables the field display and shows function output only.
$ uftrace graph -f none
# Function Call Graph for 't-sort' (session: b007f4b7cf792878)
========== FUNCTION CALL GRAPH ==========
(1) t-sort
(1) main
+-(2) foo
| (6) loop
|
+-(1) bar
(1) usleep
This output can be useful when comparing two different call graph outputs using diff tool.
It also supports field customization for task graph. The default field is set to total,self,tid, but the
field option can also be used as follows:
$ uftrace graph --task -f tid,self
========== TASK GRAPH ==========
# TID SELF TIME TASK NAME
[ 82723] 4.440 ms : gcc
: |
[ 82734] 90.951 ms : +----cc1
: |
[ 82735] 17.150 ms : +----as
: |
[ 82736] 6.076 ms : +----collect2
: |
[ 82737] 38.880 ms : +----ld
Each field has following meaning:
• total: total task lifetime from its creation to termination
• self : task execution time excluding its idle time
• tid : task id (obtained by gettid(2))
It also accepts a special field none, which hides all the fields on the left.
$ uftrace graph --task -f none
========== TASK GRAPH ==========
gcc
|
+----cc1
|
+----as
|
+----collect2
|
+----ld
SEE ALSO
uftrace(1), uftrace-record(1), uftrace-replay(1), uftrace-tui(1)
AUTHORS
Namhyung Kim namhyung@gmail.com
Uftrace User Manuals Sep, 2018 UFTRACE-GRAPH(1)