.\" Automatically generated by Pandoc 2.2.1
.\"
.TH "UFTRACE\-RECORD" "1" "May, 2016" "Uftrace User Manuals" ""
.hy
.SH NAME
.PP
uftrace\-record \- Run a command and record its trace data
.SH SYNOPSIS
.PP
uftrace record [\f[I]options\f[]] COMMAND [\f[I]command\-options\f[]]
.SH DESCRIPTION
.PP
This command runs COMMAND and gathers function trace data from it, and
saves it into files under the uftrace data directory \- without
displaying anything.
.PP
This data can then be inspected later on, using \f[C]uftrace\ replay\f[]
or \f[C]uftrace\ report\f[].
.SH OPTIONS
.TP
.B \-b \f[I]SIZE\f[], \-\-buffer=\f[I]SIZE\f[]
Size of internal buffer in which trace data will be saved.
Default size is 128k.
.RS
.RE
.TP
.B \-F \f[I]FUNC\f[], \-\-filter=\f[I]FUNC\f[]
Set filter to trace selected functions only.
This option can be used more than once.
See \f[I]FILTERS\f[].
.RS
.RE
.TP
.B \-N \f[I]FUNC\f[], \-\-notrace=\f[I]FUNC\f[]
Set filter not to trace selected functions (or the functions called
underneath them).
This option can be used more than once.
See \f[I]FILTERS\f[].
.RS
.RE
.TP
.B \-T \f[I]TRG\f[], \-\-trigger=\f[I]TRG\f[]
Set trigger on selected functions.
This option can be used more than once.
See \f[I]TRIGGERS\f[].
.RS
.RE
.TP
.B \-t \f[I]TIME\f[], \-\-time\-filter=\f[I]TIME\f[]
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.
.RS
.RE
.TP
.B \-\-force
Allow running uftrace even if some problems occur.
When \f[C]uftrace\ record\f[] finds no mcount symbol (which is generated
by compiler) in the executable, it quits with an error message since
uftrace can not trace the program.
However, it is possible that the user is only interested in functions
within a dynamically\-linked library, in which case this option can be
used to cause uftrace to run the program regardless.
Also, the \f[C]\-A\f[]/\f[C]\-\-argument\f[] and
\f[C]\-R\f[]/\f[C]\-\-retval\f[] options work only for binaries built
with \f[C]\-pg\f[], so uftrace will normally exit when it tries to run
binaries built without that option.
This option ignores the warning and goes on tracing without the argument
and/or return value.
.RS
.RE
.TP
.B \-L \f[I]PATH\f[], \-\-library\-path=\f[I]PATH\f[]
Load necessary internal libraries from this path.
This is for testing purposes.
.RS
.RE
.TP
.B \-\-no\-libcall
Do not record library function invocations.
Library calls are normally traced by hooking the dynamic linker's
resolve function in the PLT.
One can disable it with this option.
.RS
.RE
.TP
.B \-\-no\-pltbind
Do not bind dynamic symbol address.
This option uses the \f[C]LD_BIND_NOT\f[] environment variable to trace
library function calls which might be missing due to concurrent (first)
accesses.
It is not meaningful to use this option with the
\f[C]\-\-no\-libcall\f[] option.
.RS
.RE
.TP
.B \-\-nest\-libcall
Trace function calls between libraries.
By default, uftrace only record library call from the main executable.
Implies \f[C]\-\-force\f[].
.RS
.RE
.TP
.B \-D \f[I]DEPTH\f[], \-\-depth=\f[I]DEPTH\f[]
Set global trace limit in nesting level.
.RS
.RE
.TP
.B \-\-max\-stack=\f[I]DEPTH\f[]
Set the max function stack depth for tracing.
Default is 1024.
.RS
.RE
.TP
.B \-\-nop
Do not record any functions.
This is a no\-op and only meaningful for performance comparisons.
.RS
.RE
.TP
.B \-\-time
Print running time of children in \f[C]time\f[](1)\-style.
.RS
.RE
.TP
.B \-k, \-\-kernel
Trace kernel functions as well as user functions.
Only kernel entry/exit functions will be traced by default.
Use the \f[C]\-\-kernel\-depth\f[] option to override this.
.RS
.RE
.TP
.B \-H \f[I]HOST\f[], \-\-host=\f[I]HOST\f[]
Send trace data to given host via the network, not writing to files.
The \f[C]uftrace\ recv\f[] command should be run on the destination host
to receive the data.
.RS
.RE
.TP
.B \-\-port=\f[I]PORT\f[]
When sending data to the network (with \f[C]\-H\f[]), use the given port
instead of the default (8090).
.RS
.RE
.TP
.B \-\-disable
Start uftrace with tracing disabled.
This is only meaningful when used with a \f[C]trace_on\f[] trigger.
.RS
.RE
.TP
.B \-A \f[I]SPEC\f[], \-\-argument=\f[I]SPEC\f[]
Record function arguments.
This option can be used more than once.
See \f[I]ARGUMENTS\f[].
.RS
.RE
.TP
.B \-R \f[I]SPEC\f[], \-\-retval=\f[I]SPEC\f[]
Record function return values.
This option can be used more than once.
See \f[I]ARGUMENTS\f[].
.RS
.RE
.TP
.B \-a, \-\-auto\-args
Automatically record arguments and return values of known functions.
These are usually functions in standard (C language or system) libraries
but if debug info is available it includes functions in the user
program.
.RS
.RE
.TP
.B \-\-num\-thread=\f[I]NUM\f[]
Use NUM threads to record trace data.
Default is 1/4 of online CPUs (but when full kernel tracing is enabled,
it will use the full number of CPUs).
.RS
.RE
.TP
.B \-\-libmcount\-single
Use single thread version of libmcount for faster recording.
This is ignored if the target program calls \f[C]pthread_create()\f[].
.RS
.RE
.TP
.B \-\-rt\-prio=\f[I]PRIO\f[]
Boost priority of recording threads to real\-time (FIFO) with priority
of \f[I]PRIO\f[].
This is particularly useful for high\-volume data such as full kernel
tracing.
.RS
.RE
.TP
.B \-K \f[I]DEPTH\f[], \-\-kernel\-depth=\f[I]DEPTH\f[]
Set kernel max function depth separately.
Implies \f[C]\-\-kernel\f[].
.RS
.RE
.TP
.B \-\-kernel\-buffer=\f[I]SIZE\f[]
Set kernel tracing buffer size.
The default value (in the kernel) is 1408k.
.RS
.RE
.TP
.B \-P \f[I]FUNC\f[], \-\-patch=\f[I]FUNC\f[]
Patch FUNC dynamically.
This is only applicable binaries built by gcc with
\f[C]\-pg\ \-mfentry\ \-mnop\-mcount\f[] or clang with
\f[C]\-fxray\-instrument\f[].
This option can be used more than once.
See \f[I]DYNAMIC TRACING\f[].
.RS
.RE
.TP
.B \-E \f[I]EVENT\f[], \-\-event=\f[I]EVENT\f[]
Enable event tracing.
The event should be available on the system.
.RS
.RE
.TP
.B \-\-no\-event
Disable event recording which is used by default.
Note that explicit event tracing by \f[C]\-\-event\f[] option is not
affected by this.
.RS
.RE
.TP
.B \-\-keep\-pid
Retain same pid for traced program.
For some daemon processes, it is important to have same pid when forked.
Running under uftrace normally changes pid as it calls fork() again
internally.
.RS
.RE
.TP
.B \-S \f[I]SCRIPT_PATH\f[], \-\-script=\f[I]SCRIPT_PATH\f[]
Add a script to do additional work at the entry and exit of function.
The type of script is detected by the postfix such as `.py' for python.
.RS
.RE
.TP
.B \[en]match=\f[I]TYPE\f[]
Use pattern match using TYPE.
Possible types are \f[C]regex\f[] and \f[C]glob\f[].
Default is \f[C]regex\f[].
.RS
.RE
.TP
.B \[en]no\-randomize\-addr
Disable ASLR (Address Space Layout Randomization).
It makes the target process fix its address space layout.
.RS
.RE
.SH FILTERS
.PP
The uftrace tool supports filtering out uninteresting functions.
Filtering is highly recommended since it helps users focus on the
interesting functions and reduces the data size.
When uftrace is called it receives two types of function filter; an
opt\-in filter with \f[C]\-F\f[]/\f[C]\-\-filter\f[] and an opt\-out
filter with \f[C]\-N\f[]/\f[C]\-\-notrace\f[].
These filters can be applied either at record time or replay time.
.PP
The first one is an opt\-in filter.
By default, it doesn't trace anything.
But when one of the specified functions is executed, tracing is started.
When the function returns, tracing is stopped again.
.PP
For example, consider a simple program which calls \f[C]a()\f[],
\f[C]b()\f[] and \f[C]c()\f[] in turn.
.IP
.nf
\f[C]
$\ cat\ abc.c
void\ c(void)\ {
\ \ \ \ /*\ do\ nothing\ */
}

void\ b(void)\ {
\ \ \ \ c();
}

void\ a(void)\ {
\ \ \ \ b();
}

int\ main(void)\ {
\ \ \ \ a();
\ \ \ \ return\ 0;
}

$\ gcc\ \-pg\ \-o\ abc\ abc.c
\f[]
.fi
.PP
Normally uftrace will trace all the functions from \f[C]main()\f[] to
\f[C]c()\f[].
.IP
.nf
\f[C]
$\ uftrace\ ./abc
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ 138.494\ us\ [\ 1234]\ |\ __cxa_atexit();
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ main()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ a()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ \ \ b()\ {
\ \ \ 3.880\ us\ [\ 1234]\ |\ \ \ \ \ \ \ c();
\ \ \ 5.475\ us\ [\ 1234]\ |\ \ \ \ \ }\ /*\ b\ */
\ \ \ 6.448\ us\ [\ 1234]\ |\ \ \ }\ /*\ a\ */
\ \ \ 8.631\ us\ [\ 1234]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
But when the \f[C]\-F\ b\f[] filter option is used, it will not trace
\f[C]main()\f[] or \f[C]a()\f[] but only \f[C]b()\f[] and \f[C]c()\f[].
.IP
.nf
\f[C]
$\ uftrace\ record\ \-F\ b\ ./abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ b()\ {
\ \ \ 3.880\ us\ [\ 1234]\ |\ \ \ c();
\ \ \ 5.475\ us\ [\ 1234]\ |\ }\ /*\ b\ */
\f[]
.fi
.PP
The second type of filter is opt\-out.
By default, everything is traced, but when one of the specified
functions is executed, tracing stops.
When the excluded function returns, tracing is started again.
.PP
In the above example, you can omit the function \f[C]b()\f[] and all
calls it makes with the \f[C]\-N\f[] option.
.IP
.nf
\f[C]
$\ uftrace\ record\ \-N\ b\ ./abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ 138.494\ us\ [\ 1234]\ |\ __cxa_atexit();
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ main()\ {
\ \ \ 6.448\ us\ [\ 1234]\ |\ \ \ a();
\ \ \ 8.631\ us\ [\ 1234]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
In addition, you can limit the print nesting level with the \f[C]\-D\f[]
option.
.IP
.nf
\f[C]
$\ uftrace\ record\ \-D\ 3\ ./abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ 138.494\ us\ [\ 1234]\ |\ __cxa_atexit();
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ main()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ a()\ {
\ \ \ 5.475\ us\ [\ 1234]\ |\ \ \ \ \ b();
\ \ \ 6.448\ us\ [\ 1234]\ |\ \ \ }\ /*\ a\ */
\ \ \ 8.631\ us\ [\ 1234]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
In the above example, uftrace only prints functions up to a depth of 3,
so leaf function \f[C]c()\f[] was omitted.
Note that the \f[C]\-D\f[] option works with \f[C]\-F\f[].
.PP
Sometimes it's useful to see long\-running functions only.
This is good because there are usually many tiny functions that are not
interesting.
The \f[C]\-t\f[]/\f[C]\-\-time\-filter\f[] option implements the
time\-based filter that only records functions which run longer than the
given threshold.
In the above example, the user might want to see functions running more
than 5 microseconds like below:
.IP
.nf
\f[C]
$\ uftrace\ record\ \-t\ 5us\ ./abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ 138.494\ us\ [\ 1234]\ |\ __cxa_atexit();
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ main()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ a()\ {
\ \ \ 5.475\ us\ [\ 1234]\ |\ \ \ \ \ b();
\ \ \ 6.448\ us\ [\ 1234]\ |\ \ \ }\ /*\ a\ */
\ \ \ 8.631\ us\ [\ 1234]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
The \f[C]\-t\f[]/\f[C]\-\-time\-filter\f[] option works for user\-level
functions only.
It does not work for recording kernel functions, but they can be hidden
in replay, report, dump and graph commands with
\f[C]\-t\f[]/\f[C]\-\-time\-filter\f[] option.
.PP
You can also set triggers on filtered functions.
See \f[I]TRIGGERS\f[] section below for details.
.PP
When kernel function tracing is enabled, you can also set the filters on
kernel functions by marking the symbol with the \f[C]\@kernel\f[]
modifier.
The following example will show all user functions and the (kernel) page
fault handler.
.IP
.nf
\f[C]
$\ sudo\ uftrace\ \-k\ \-F\ \[aq].*page_fault\@kernel\[aq]\ ./abc
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ \ \ \ \ \ \ \ \ [14721]\ |\ main()\ {
\ \ 7.713\ us\ [14721]\ |\ \ \ __do_page_fault();
\ \ 6.600\ us\ [14721]\ |\ \ \ __do_page_fault();
\ \ 6.544\ us\ [14721]\ |\ \ \ __do_page_fault();
\ \ \ \ \ \ \ \ \ \ \ [14721]\ |\ \ \ a()\ {
\ \ \ \ \ \ \ \ \ \ \ [14721]\ |\ \ \ \ \ b()\ {
\ \ \ \ \ \ \ \ \ \ \ [14721]\ |\ \ \ \ \ \ \ c()\ {
\ \ 0.860\ us\ [14721]\ |\ \ \ \ \ \ \ \ \ getpid();
\ \ 2.346\ us\ [14721]\ |\ \ \ \ \ \ \ }\ /*\ c\ */
\ \ 2.956\ us\ [14721]\ |\ \ \ \ \ }\ /*\ b\ */
\ \ 3.340\ us\ [14721]\ |\ \ \ }\ /*\ a\ */
\ 79.086\ us\ [14721]\ |\ }\ /*\ main\ */
\f[]
.fi
.SH TRIGGERS
.PP
The uftrace tool supports triggering actions on selected function calls
with or without filters.
Currently supported triggers are listed below.
The BNF for trigger specification is:
.IP
.nf
\f[C]
<trigger>\ \ \ \ :=\ \ <symbol>\ "\@"\ <actions>
<actions>\ \ \ \ :=\ \ <action>\ \ |\ <action>\ ","\ <actions>
<action>\ \ \ \ \ :=\ \ "depth="<num>\ |\ "trace"\ |\ "trace_on"\ |\ "trace_off"\ |
\ \ \ \ \ \ \ \ \ \ \ \ \ \ \ \ \ "time="<time_spec>\ |\ "read="<read_spec>\ |\ "finish"\ |
\ \ \ \ \ \ \ \ \ \ \ \ \ \ \ \ \ "filter"\ |\ "notrace"\ |\ "recover"
<time_spec>\ \ :=\ \ <num>\ [\ <time_unit>\ ]
<time_unit>\ \ :=\ \ "ns"\ |\ "us"\ |\ "ms"\ |\ "s"
<read_spec>\ \ :=\ \ "proc/statm"\ |\ "page\-fault"\ |\ "pmu\-cycle"\ |\ "pmu\-cache"\ |
\ \ \ \ \ \ \ \ \ \ \ \ \ \ \ \ \ "pmu\-branch"
\f[]
.fi
.PP
The \f[C]depth\f[] trigger is to change filter depth during execution of
the function.
It can be used to apply different filter depths for different functions.
.PP
The following example shows how triggers work.
The global filter maximum depth is 5, but when function \f[C]b()\f[] is
called, it is changed to 1, so functions below \f[C]b()\f[] will not
shown.
.IP
.nf
\f[C]
$\ uftrace\ record\ \-D\ 5\ \-T\ \[aq]b\@depth=1\[aq]\ ./abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ 138.494\ us\ [\ 1234]\ |\ __cxa_atexit();
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ main()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ a()\ {
\ \ \ 5.475\ us\ [\ 1234]\ |\ \ \ \ \ b();
\ \ \ 6.448\ us\ [\ 1234]\ |\ \ \ }\ /*\ a\ */
\ \ \ 8.631\ us\ [\ 1234]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
The \f[C]backtrace\f[] trigger is only meaningful in the replay command.
.PP
The \f[C]traceon\f[] and \f[C]traceoff\f[] actions (the \f[C]_\f[] can
be omitted from \f[C]trace_on\f[] and \f[C]trace_off\f[]) control
whether uftrace records the specified functions or not.
.PP
The `recover' trigger is for some corner cases in which the process
accesses the callstack directly.
During tracing of the v8 javascript engine, for example, it kept getting
segfaults in the garbage collection stage.
It was because v8 incorporates the return address into compiled code
objects(?).
The \f[C]recover\f[] trigger restores the original return address at the
function entry point and resets to the uftrace return hook address again
at function exit.
I was managed to work around the segfault by setting the
\f[C]recover\f[] trigger on the related function (specifically
\f[C]ExitFrame::Iterate\f[]).
.PP
The `time' trigger is to change time filter setting during execution of
the function.
It can be used to apply differernt time filter for different functions.
.PP
The \f[C]read\f[] trigger is to read some information at runtime.
The result will be recorded as (builtin) events at the beginning and the
end of a given function.
As of now, following events are supported:
.IP \[bu] 2
\[lq]proc/statm\[rq]: process memory stat from /proc filesystem
.IP \[bu] 2
\[lq]page\-fault\[rq]: number of page faults using getrusage(2)
.IP \[bu] 2
\[lq]pmu\-cycle\[rq]: cpu cycles and instructions using Linux
perf\-event syscall
.IP \[bu] 2
\[lq]pmu\-cache\[rq]: (cpu) cache\-references and misses using Linux
perf\-event syscall
.IP \[bu] 2
\[lq]pmu\-branch\[rq]: branch instructions and misses using Linux
perf\-event syscall
.PP
The results are printed in comments like below.
.IP
.nf
\f[C]
$\ uftrace\ record\ \-T\ a\@read=proc/statm\ ./abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ main()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ a()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ \ \ /*\ read:proc/statm\ (size=6808KB,\ rss=776KB,\ shared=712KB)\ */
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ \ \ b()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ \ \ \ \ c()\ {
\ \ \ 1.448\ us\ [\ 1234]\ |\ \ \ \ \ \ \ \ \ getpid();
\ \ 10.270\ us\ [\ 1234]\ |\ \ \ \ \ \ \ }\ /*\ c\ */
\ \ 11.250\ us\ [\ 1234]\ |\ \ \ \ \ }\ /*\ b\ */
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ \ \ /*\ read2:proc/statm\ (size=+4KB,\ rss=+0KB,\ shared=+0KB)\ */
\ \ 18.380\ us\ [\ 1234]\ |\ \ \ }\ /*\ a\ */
\ \ 19.537\ us\ [\ 1234]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
The `finish' trigger is to end recording.
The process still can run and this can be useful to trace unterminated
processes like daemon.
.PP
The `filter' and `notrace' triggers have same effect as
\f[C]\-F\f[]/\f[C]\-\-filter\f[] and \f[C]\-N\f[]/\f[C]\-\-notrace\f[]
options respectively.
.PP
Triggers only work for user\-level functions for now.
.SH ARGUMENTS
.PP
The uftrace tool supports recording function arguments and/or return
values using the \f[C]\-A\f[]/\f[C]\-\-argument\f[] and
\f[C]\-R\f[]/\f[C]\-\-retval\f[] options respectively.
The syntax is very similar to that of triggers:
.IP
.nf
\f[C]
<argument>\ \ \ \ :=\ \ <symbol>\ "\@"\ <specs>
<specs>\ \ \ \ \ \ \ :=\ \ <spec>\ |\ <spec>\ ","\ <spec>
<spec>\ \ \ \ \ \ \ \ :=\ \ (\ <int_spec>\ |\ <float_spec>\ |\ <ret_spec>\ )
<int_spec>\ \ \ \ :=\ \ "arg"\ N\ [\ "/"\ <format>\ [\ <size>\ ]\ ]\ [\ "%"\ (\ <reg>\ |\ <stack>\ )\ ]
<float_spec>\ \ :=\ \ "fparg"\ N\ [\ "/"\ (\ <size>\ |\ "80"\ )\ ]\ [\ "%"\ (\ <reg>\ |\ <stack>\ )\ ]
<ret_spec>\ \ \ \ :=\ \ "retval"\ [\ "/"\ <format>\ [\ <size>\ ]\ ]
<format>\ \ \ \ \ \ :=\ \ "d"\ |\ "i"\ |\ "u"\ |\ "x"\ |\ "s"\ |\ "c"\ |\ "f"\ |\ "S"\ |\ "p"
<size>\ \ \ \ \ \ \ \ :=\ \ "8"\ |\ "16"\ |\ "32"\ |\ "64"
<reg>\ \ \ \ \ \ \ \ \ :=\ \ <arch\-specific\ register\ name>\ \ #\ "rdi",\ "xmm0",\ "r0",\ ...
<stack>\ \ \ \ \ \ \ :=\ \ "stack"\ [\ "+"\ ]\ <offset>
\f[]
.fi
.PP
The \f[C]\-A\f[]/\f[C]\-\-argument\f[] option takes argN where N is an
index of the arguments.
The index starts from 1 and corresponds to the argument passing order of
the calling convention on the system.
Note that the indexes of arguments are separately counted for integer
(or pointer) and floating\-point type, and they can interfere depending
on the calling convention.
The argN is for integer arguments and fpargN is for floating\-point
arguments.
.PP
Users can optionally specify a format and size for the arguments and/or
return values.
The \[lq]d\[rq] format or without format field, uftrace treats them as
`long int' type for integers and `double' for floating\-point numbers.
The \[lq]i\[rq] format makes it signed integer type and \[lq]u\[rq]
format is for unsigned type.
Both are printed as decimal while \[lq]x\[rq] format makes it printed as
hexadecimal.
The \[lq]s\[rq] format is for null\-terminated string type and
\[lq]c\[rq] format is for character type.
The \[lq]f\[rq] format is for floating\-point type and is meaningful
only for return value (generally).
Note that fpargN doesn't take the format field since it's always
floating\-point.
The \[lq]S\[rq] format is for std::string, but it only supports
libstdc++ library as of yet.
Finally, the \[lq]p\[rq] format is for function pointer.
Once the target address is recorded, it will be displayed as function
name.
.PP
Please beware when using string type arguments since it can crash the
program if the (pointer) value is invalid.
.PP
It is also possible to specify a certain register name or stack offset
for arguments (but not for return value).
The following register names can be used for argument:
.IP \[bu] 2
x86: rdi, rsi, rdx, rcx, r8, r9 (for integer), xmm[0\-7] (for
floating\-point)
.IP \[bu] 2
arm: r[0\-3] (for integer), s[0\-15] or d[0\-7] (for floating\-point)
.PP
Examples are below:
.IP
.nf
\f[C]
$\ uftrace\ record\ \-A\ main\@arg1/x\ \-R\ main\@retval/i32\ ./abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ 138.494\ us\ [\ 1234]\ |\ __cxa_atexit();
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ main(0x1)\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ a()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [\ 1234]\ |\ \ \ \ \ b()\ {
\ \ \ 3.880\ us\ [\ 1234]\ |\ \ \ \ \ \ \ c();
\ \ \ 5.475\ us\ [\ 1234]\ |\ \ \ \ \ }\ /*\ b\ */
\ \ \ 6.448\ us\ [\ 1234]\ |\ \ \ }\ /*\ a\ */
\ \ \ 8.631\ us\ [\ 1234]\ |\ }\ =\ 0;\ /*\ main\ */

$\ uftrace\ record\ \-A\ puts\@arg1/s\ \-R\ puts\@retval\ ./hello
Hello\ world

$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ 1.457\ us\ [21534]\ |\ __monstartup();
\ \ \ 0.997\ us\ [21534]\ |\ __cxa_atexit();
\ \ \ \ \ \ \ \ \ \ \ \ [21534]\ |\ main()\ {
\ \ \ 7.226\ us\ [21534]\ |\ \ \ puts("Hello\ world")\ =\ 12;
\ \ \ 8.708\ us\ [21534]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
Note that these arguments and return value are recorded only if the
executable was built with the \f[C]\-pg\f[] option.
Executables built with \f[C]\-finstrument\-functions\f[] will ignore it
except for library calls.
Recording of arguments and return values only works with user\-level
functions for now.
.PP
If the target program is built with debug info like DWARF, uftrace can
identify number of arguments and their types automatically (when built
with libdw).
Also arguments and return value of some well\-known library functions
are provided even if the debug info is not available.
In these cases user don't need to specify format of the arguments and
return value manually \- just function name (or pattern) is enough.
In fact, manual argspec will suppress the automatic argspec.
.PP
For example, the above example can be written like below:
.IP
.nf
\f[C]
$\ uftrace\ record\ \-A\ .\ \-R\ main\ ./hello
Hello\ world

$\ uftrace\ replay\ \-F\ main
#\ DURATION\ \ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ \ \ \ \ \ \ \ \ \ [\ 18948]\ |\ main(1,\ 0x7ffeeb7590b8)\ {
\ \ \ 7.183\ us\ [\ 18948]\ |\ \ \ puts("Hello\ world");
\ \ \ 9.832\ us\ [\ 18948]\ |\ }\ =\ 0;\ /*\ main\ */
\f[]
.fi
.PP
Note that argument pattern (\[lq].\[rq]) matches to any character so it
recorded all (supported) functions.
It shows two arguments for \[lq]main\[rq] and a single string argument
for \[lq]puts\[rq].
If you simply want to see all arguments and return values of every
functions (if supported), use \f[C]\-a\f[]/\f[C]\-\-auto\-args\f[]
option.
.SH DYNAMIC TRACING
.PP
The uftrace tool supports dynamic function tracing which can be enabled
at runtime (load\-time, to be precise) on x86_64.
Before recording functions, normally you need to build the target
program with \f[C]\-pg\f[] (or \f[C]\-finstrument\-functions\f[]), then
it has some performance impact because all functions call
\f[C]mcount()\f[].
.PP
With dynamic tracing, you can trace specific functions only given by the
\f[C]\-P\f[]/\f[C]\-\-patch\f[] option.
However you need to add some more compiler (gcc) options when building
the target program.
The gcc 5.1 or more recent versions provide \f[C]\-mfentry\f[] and
\f[C]\-mnop\-mcount\f[] options which add instrumentation code
(i.e.\ calling \f[C]mcount()\f[] function) at the very beginning of a
function and convert the instruction to a NOP.
Then it has almost zero performance overhead when running in a normal
condition.
The uftrace can convert it back to call \f[C]mcount()\f[] if users want
to (using \f[C]\-P\f[] option).
.PP
The following example shows a error message when normally running
uftrace with the executable built with
\f[C]\-pg\ \-mfentry\ \-mnop\-mcount\f[].
Because the binary doesn't call any instrumentation code (i.e.
`mcount').
.IP
.nf
\f[C]
$\ gcc\ \-o\ abc\ \-pg\ \-mfentry\ \-mnop\-mcount\ tests/s\-abc.c
$\ uftrace\ abc
uftrace:\ /home/namhyung/project/uftrace/cmd\-record.c:1305:check_binary
\ \ ERROR:\ Can\[aq]t\ find\ \[aq]mcount\[aq]\ symbol\ in\ the\ \[aq]abc\[aq].
\ \ \ \ \ \ \ \ \ It\ seems\ not\ to\ be\ compiled\ with\ \-pg\ or\ \-finstrument\-functions\ flag
\ \ \ \ \ \ \ \ \ which\ generates\ traceable\ code.\ \ Please\ check\ your\ binary\ file.
\f[]
.fi
.PP
But when the \f[C]\-P\ a\f[] patch option is used, and then only it can
dynamically trace \f[C]a()\f[].
.IP
.nf
\f[C]
$\ uftrace\ record\ \-\-no\-libcall\ \-P\ a\ abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ 0.923\ us\ [19379]\ |\ a();
\f[]
.fi
.PP
In addition, you can enable all functions at load time using `.' that
matches to any character in a regex pattern with \f[C]P\f[] option.
.IP
.nf
\f[C]
$\ uftrace\ record\ \-\-no\-libcall\ \-P\ .\ abc
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ \ \ \ \ \ \ \ \ \ [19387]\ |\ main()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [19387]\ |\ \ \ a()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [19387]\ |\ \ \ \ \ b()\ {
\ \ \ 0.940\ us\ [19387]\ |\ \ \ \ \ \ \ c();
\ \ \ 2.030\ us\ [19387]\ |\ \ \ \ \ }\ /*\ b\ */
\ \ \ 2.451\ us\ [19387]\ |\ \ \ }\ /*\ a\ */
\ \ \ 3.289\ us\ [19387]\ |\ }\ /*\ main\ */
\f[]
.fi
.PP
Clang/LLVM 4.0 provides a dynamic instrumentation technique called
X\-ray (http://llvm.org/docs/XRay.html).
It's similar to a combination of \f[C]gcc\ \-mfentry\ \-mnop\-mcount\f[]
and \f[C]\-finstrument\-functions\f[].
The uftrace also supports dynamic tracing on the executables built with
the \f[C]X\-ray\f[].
.PP
For example, you can build the target program by clang with the below
option and equally use \f[C]\-P\f[] option for dynamic tracing like
below:
.IP
.nf
\f[C]
$\ clang\ \-fxray\-instrument\ \-fxray\-instruction\-threshold=1\ \-o\ abc\-xray\ \ tests/s\-abc.c
$\ uftrace\ record\ \-P\ main\ abc\-xray
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ \ \ \ \ \ \ \ \ \ [11093]\ |\ main()\ {
\ \ \ 1.659\ us\ [11093]\ |\ \ \ getpid();
\ \ \ 5.963\ us\ [11093]\ |\ }\ /*\ main\ */

$\ uftrace\ record\ \-P\ .\ abc\-xray
$\ uftrace\ replay
#\ DURATION\ \ \ \ TID\ \ \ \ \ FUNCTION
\ \ \ \ \ \ \ \ \ \ \ \ [11098]\ |\ main()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [11098]\ |\ \ \ a()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [11098]\ |\ \ \ \ \ b()\ {
\ \ \ \ \ \ \ \ \ \ \ \ [11098]\ |\ \ \ \ \ \ \ c()\ {
\ \ \ 0.753\ us\ [11098]\ |\ \ \ \ \ \ \ \ \ getpid();
\ \ \ 1.430\ us\ [11098]\ |\ \ \ \ \ \ \ }\ /*\ c\ */
\ \ \ 1.915\ us\ [11098]\ |\ \ \ \ \ }\ /*\ b\ */
\ \ \ 2.405\ us\ [11098]\ |\ \ \ }\ /*\ a\ */
\ \ \ 3.005\ us\ [11098]\ |\ }\ /*\ main\ */
\f[]
.fi
.SH SCRIPT EXECUTION
.PP
The uftrace tool supports script execution for each function entry and
exit.
The supported script is only Python 2.7 as of now.
.PP
The user can write four functions.
`uftrace_entry' and `uftrace_exit' are executed whenever each function
is executed at the entry and exit.
However `uftrace_begin' and `uftrace_end' are only executed once when
the target program begins and ends.
.IP
.nf
\f[C]
$\ cat\ scripts/simple.py
def\ uftrace_begin(ctx):
\ \ \ \ print("program\ begins...")

def\ uftrace_entry(ctx):
\ \ \ \ func\ =\ ctx["name"]
\ \ \ \ print("entry\ :\ "\ +\ func\ +\ "()")

def\ uftrace_exit(ctx):
\ \ \ \ func\ =\ ctx["name"]
\ \ \ \ print("exit\ \ :\ "\ +\ func\ +\ "()")

def\ uftrace_end():
\ \ \ \ print("program\ is\ finished")
\f[]
.fi
.PP
The above script can be executed in record time as follows:
.IP
.nf
\f[C]
$\ uftrace\ record\ \-S\ scripts/simple.py\ \-F\ main\ tests/t\-abc
program\ begins...
entry\ :\ main()
entry\ :\ a()
entry\ :\ b()
entry\ :\ c()
entry\ :\ getpid()
exit\ \ :\ getpid()
exit\ \ :\ c()
exit\ \ :\ b()
exit\ \ :\ a()
exit\ \ :\ main()
program\ is\ finished
\f[]
.fi
.PP
The `ctx' variable is a dictionary type that contains the below
information.
.IP
.nf
\f[C]
/*\ context\ information\ passed\ to\ script\ */
script_context\ =\ {
\ \ \ \ int\ \ \ \ \ \ \ tid;
\ \ \ \ int\ \ \ \ \ \ \ depth;
\ \ \ \ long\ \ \ \ \ \ timestamp;
\ \ \ \ long\ \ \ \ \ \ duration;\ \ \ \ #\ exit\ only
\ \ \ \ long\ \ \ \ \ \ address;
\ \ \ \ string\ \ \ \ name;
\ \ \ \ list\ \ \ \ \ \ args;\ \ \ \ \ \ \ \ #\ entry\ only\ (if\ available)
\ \ \ \ value\ \ \ \ \ retval;\ \ \ \ \ \ #\ exit\ \ only\ (if\ available)
};
\f[]
.fi
.PP
Each field in `script_context' can be read inside the script.
Please see \f[C]uftrace\-script\f[](1) for details about scripting.
.SH SEE ALSO
.PP
\f[C]uftrace\f[](1), \f[C]uftrace\-replay\f[](1),
\f[C]uftrace\-report\f[](1), \f[C]uftrace\-recv\f[](1),
\f[C]uftrace\-script\f[](1), \f[C]uftrace\-tui\f[](1)
.SH AUTHORS
Namhyung Kim <namhyung@gmail.com>.