UFTRACE-RECORD(1)

UFTRACE-RECORD πŸ’– (that's uftrace-record(1) bestie, General Commands Manual energy)

✨ NAME ✨

uftrace-record β€” run a command and record its trace data πŸŽ€


πŸ¦‹ SYNOPSIS πŸ¦‹

uftrace record [options] COMMAND [command-options]

πŸ’œ DESCRIPTION πŸ’œ

okay so picture this: this command runs your COMMAND, quietly gathers all the function trace data from it, and tucks it away into files under the uftrace data directory β€” and it shows you absolutely nothing while it does it. no output, no drama, just vibes and data. 🀫

then later you can come back and inspect all that delicious data using uftrace replay or uftrace report. it's giving "record now, obsess later". πŸ’…


πŸ”₯ RECORD OPTIONS πŸ”₯

  • -A SPEC, --argument=SPEC β€” record function arguments. you can use this more than once, she's flexible like that. implies --srcline. go read ARGUMENTS. πŸ“
  • -R SPEC, --retval=SPEC β€” record function return values. yep, also usable more than once. implies --srcline. ARGUMENTS has the tea. β˜•
  • -P FUNC, --patch=FUNC β€” patch FUNC dynamically. can be used more than once. see DYNAMIC TRACING for the full lore. 🩹
  • -U FUNC, --unpatch=FUNC β€” do NOT apply dynamic patching for FUNC. also repeatable. see DYNAMIC TRACING. 🚫
  • -E EVENT, --event=EVENT β€” enable event tracing. the event has to actually be available on your system, no cap. 🎟️
  • -S SCRIPT_PATH, --script=SCRIPT_PATH β€” run a given script to do extra work at the entry and exit of a function while your target program is running. the type of script is detected by the postfix β€” like `.py' for python. see SCRIPT EXECUTION. πŸ“œ
  • -W, --watch=POINT β€” add a watch point to display POINT if the value changes. see WATCH POINT. πŸ‘€
  • -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 too. implies --srcline. πŸ€–
  • -l, --nest-libcall β€” trace function calls between libraries. by default uftrace only records library calls from the main executable. implies --force. πŸͺ†
  • -k, --kernel β€” trace kernel functions AND user functions. by default the tracing depth is 1 (only kernel entry/exit functions get traced). use the -K/--kernel-depth option to override that. 🐧
  • -K DEPTH, --kernel-depth=DEPTH β€” set kernel max function depth separately. implies --kernel. πŸ“
  • --clock=CLOCK β€” set the clock source for timestamp recording. CLOCK can be one of mono, mono_raw, or boot. default is mono. ⏰
  • --host=HOST β€” send trace data to a given host over the network instead of writing to files. you should run the uftrace recv command on the destination host to receive that data. πŸ“‘
  • --port=PORT β€” when sending data over the network (with --host), use the given port instead of the default (8090). πŸ”Œ
  • --signal=TRG β€” set a trigger on selected signals rather than functions. BUT there are restrictions, so only a few trigger actions are supported for signals. the available actions are: trace_on, trace_off, finish. this option can be used more than once. see TRIGGERS. 🚨
  • --nop β€” do not record any functions. this is a no-op and only meaningful for performance comparisons. literally just standing there, menacingly. 🧍
  • --force β€” allow running uftrace even if some problems occur. so like, when uftrace record finds no mcount symbol (which is generated by the compiler) in the executable, it quits with an error message, because uftrace can't trace the program. HOWEVER, it's possible you're only interested in functions within a dynamically-linked library, in which case this option can be used to make uftrace run the program anyway. also, the -A/--argument and -R/--retval options work only for binaries built with -pg, 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. πŸ’ͺ
  • --time β€” print running time of children in time(1)-style. ⏱️
  • -e, --estimate-return β€” record only ENTRY data for each function. this option is useful when the target program deals with the stack in some way. normally uftrace modifies the task's execution stack frame to hook the return from the function. however, sometimes it makes troubles and it's hard to handle all the cases properly. this option tells uftrace not to hook the return address in order to prevent those problems. the return time is estimated as a half of the execution time of two consecutive functions. πŸ€”

🌸 COMMON OPTIONS 🌸

  • -F FUNC, --filter=FUNC β€” set a filter to trace selected functions and their children functions. can be used more than once. see FILTERS. 🎯
  • -N FUNC, --notrace=FUNC β€” set a filter NOT to trace selected functions and their children functions. also repeatable. see FILTERS. πŸ™…
  • -C FUNC, --caller-filter=FUNC β€” set a filter to trace the callers of selected functions only. repeatable. see FILTERS. πŸ“ž
  • -T TRG, --trigger=TRG β€” set a trigger on selected functions. repeatable. see TRIGGERS. ⚑
  • -D DEPTH, --depth=DEPTH β€” set the global trace limit in nesting level. see FILTERS. πŸͺœ
  • -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. see FILTERS. ⏳
  • -Z SIZE, --size-filter=SIZE β€” do not show functions smaller than SIZE bytes. see FILTERS. πŸ“
  • -L LOCATION, --loc-filter=LOCATION β€” set a filter to trace selected source locations. repeatable. implies --srcline. see FILTERS. πŸ“
  • --no-libcall β€” do not record library function invocations. library calls are normally traced by hooking calls to the resolver function of the dynamic linker in the PLT. you can disable that with this option. 🚷
  • --no-event β€” disable event recording which is used by default. note that explicit event tracing by the --event option is NOT affected by this. implies --no-sched. πŸ”•
  • --no-sched β€” disable schedule event recording which is used by default. πŸ“…
  • --match=TYPE β€” use pattern match using TYPE. possible types are regex and glob. default is regex. 🧩
  • --disable β€” DEPRECATED. use --trace=off instead. ⚠️ (fr fr, it's old, move on)
  • --trace=STATE β€” set uftrace tracing STATE. possible states are on and off. default is on. this is only meaningful when used with a trace_on trigger or with the agent. 🎚️
  • --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. πŸ—‚οΈ

πŸŽ€ RECORD CONFIG OPTIONS πŸŽ€

  • --libmcount-path=PATH β€” load libmcount libraries from this path. this is mostly for testing purposes. πŸ§ͺ
  • -b SIZE, --buffer=SIZE β€” size of the internal buffer in which trace data will be saved. default size is 128k. 🧺
  • --kernel-buffer=SIZE β€” set the kernel tracing buffer size. the default value (in the kernel) is 1408k. 🌰
  • --no-pltbind β€” do not bind dynamic symbol address. this option uses the LD_BIND_NOT 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 --no-libcall option. πŸ”—
  • --max-stack=DEPTH β€” set the max function stack depth for tracing. default is 1024. πŸ₯ž
  • --num-thread=NUM β€” 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). 🧡
  • --libmcount-single β€” use the single thread version of libmcount for faster recording. this is ignored if the target program links with the pthread library. 1️⃣
  • --rt-prio=PRIO β€” boost priority of recording threads to real-time (FIFO) with priority of PRIO. this is particularly useful for high-volume data such as full kernel tracing. πŸš€
  • --keep-pid β€” retain the same pid for the traced program. for some daemon processes, it is important to have the same pid when forked. running under uftrace normally changes the pid as it calls fork() again internally. πŸ†”
  • --no-randomize-addr β€” disable ASLR (Address Space Layout Randomization). it makes the target process fix its address space layout. 🎲 (well, un-🎲)
  • -g, --agent β€” spawn an agent thread in the target. at runtime, the agent receives external commands and can change supported tracing options. see the AGENT section in the uftrace-live(1). πŸ•΅οΈ
  • --srcline β€” enable recording source line in the debug info. πŸ“„

🌸 FILTERS 🌸

okay so, this is the part where uftrace gets picky β€” it can filter out the boring functions for you. πŸ’…

Filtering is highly recommended, fr fr, because it helps you focus on the functions you actually care about and it reduces how much data gets written. Less noise, smaller files, immaculate vibes ✨.

When uftrace is called it receives two types of function filter:

  • an opt-in filter, using -F/--filter
  • an opt-out filter, using -N/--notrace

These filters can be applied either at record time or at replay time, and they can be added and removed at runtime from the client. Peep uftrace-live(1) for the details on agent operations 🫢.


🫢 the opt-in filter

First type is opt-in. By default it doesn't trace anything 😴. But the second one of the functions you named gets executed, tracing starts. And when that function returns, tracing stops again.

So let's say you've got a super simple program that calls a(), b() and c() one after the other:

$ 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

Normally uftrace traces every function from main() all the way down to c():

$ uftrace record ./abc
$ uftrace replay
# 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 */

But the moment you use the -F b filter option, it won't trace main() or a() anymore β€” it only traces b() and c() πŸ‘‘:

$ uftrace record -F b ./abc
$ uftrace replay
# DURATION    TID     FUNCTION
            [ 1234] | b() {
   3.880 us [ 1234] |   c();
   5.475 us [ 1234] | } /* b */

πŸ’… the opt-out filter

Second type is opt-out. Here, by default, everything gets traced. But when one of the functions you specified gets executed, tracing stops. And when that excluded function returns, tracing starts up again ✨.

In the same example above, you can omit b() and all the calls it makes with the -N option:

$ 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 */

🌈 filters with conditions (@if:)

You can set a condition for these filters using the value of an argument. Right now it assumes the argument has an integer value and does the comparison for integers. You add the @if: suffix after the function name, with the comparison expression right there:

$ uftrace record -F main@if:arg1==1  ./abc
$ uftrace replay
# DURATION    TID     FUNCTION
            [ 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 */

And why did that work, bestie? Because the value of the first argument of the main function was 1 ✨. Change the condition and it won't enable the filter at all:

$ uftrace record -F main@if:arg1==2  ./abc
$ uftrace replay
WARN: cannot open record data: uftrace.data: No data available

Also, ofc, it only works when the function actually has arguments πŸ’€.

πŸ‘‘ caller filter (-C)

If you only care about specific functions and you wanna know how they're called, use the caller filter. It makes the function basically act like a leaf, and records the parent functions that lead down to it:

$ uftrace record -C b ./abc
$ uftrace replay
# DURATION    TID     FUNCTION
            [ 1234] | main() {
            [ 1234] |   a() {
   5.475 us [ 1234] |     b();
   6.448 us [ 1234] |   } /* a */
   8.631 us [ 1234] | } /* main */

See how functions that aren't on the calling path just... don't show up? And the function c β€” which is a child of the function b β€” is hidden too 🫣.

Caller filters can be added and removed from the client at runtime, using the @clear suffix for the -C / --caller-filter option.

🧚 limiting depth (-D)

Besides all that, you can limit the nesting level of functions with the -D option:

$ 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 */

Here uftrace only records functions up to a depth of 3, so the leaf function c() got left out. Lowkey important: the -D option works with -F πŸ’–.

⏳ time filter (-t)

Sometimes it's genuinely useful to see only the long-running functions, and that's a whole mood, because there are usually a million tiny functions that nobody cares about. The -t/--time-filter option is the time-based filter β€” it only records functions that run longer than the threshold you give it. In the example above, you might wanna see functions running more than 5 micro-seconds, like this:

$ 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 */
Heads up bestie: the -t/--time-filter option works for user-level functions only. It does not work for recording kernel functions β€” but those can still be hidden in the replay, report, dump and graph commands with the -t/--time-filter option. ✨

πŸŽ€ source location filter (-L)

You can also set a filter to record selected source locations with the -L option:

$ uftrace record -L s-libmain.c t-lib
$ uftrace replay --srcline
# DURATION     TID     FUNCTION [SOURCE]
            [  5043] | main() { /* /home/uftrace/tests/s-libmain.c:16 */
   6.998 us [  5043] |   foo(); /* /home/uftrace/tests/s-libmain.c:11 */
   9.393 us [  5043] | } /* main */

And you can set a filter with the @hide suffix so that selected source locations are not recorded:

$ uftrace record -L s-libmain.c@hide t-lib
$ uftrace replay --srcline
# DURATION     TID     FUNCTION [SOURCE]
            [ 14688] | lib_a() { /* /home/uftrace/tests/s-lib.c:10 */
            [ 14688] |   lib_b() { /* /home/uftrace/tests/s-lib.c:15 */
   1.505 us [ 14688] |     lib_c(); /* /home/uftrace/tests/s-lib.c:20 */
   2.816 us [ 14688] |   } /* lib_b */
   3.181 us [ 14688] | } /* lib_a */

🌸 size filter (-Z)

The -Z/--size-filter option filters out functions that have small sizes. It reads the ELF symbols' size and compares it with the value you gave. One thing to know: the PLT functions may have no symbol size in the ELF format β€” in that case, the PLT entry size is used as the size of the function 🫢.

$ uftrace record -Z 100  t-arg
$ uftrace replay
# DURATION     TID     FUNCTION
            [162500] | main() {
  12.486 us [162500] |   foo();
   0.505 us [162500] |   many();
            [162500] |   pass() {
   0.283 us [162500] |     check();
   1.449 us [162500] |   } /* pass */
  18.478 us [162500] | } /* main */

You can also set triggers on filtered functions β€” scroll down to the TRIGGERS section for that πŸ‘€.

πŸ’œ kernel functions (@kernel)

When kernel function tracing is enabled, you can also set the filters on kernel functions by marking the symbol with the @kernel modifier. This next example will show all user functions and the (kernel) page fault handler:

$ sudo uftrace -k -F '.*page_fault@kernel' ./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 */

πŸ”₯ TRIGGERS πŸ”₯

okay bestie, this is where it gets ✨spicy✨. uftrace can trigger actions on selected function calls β€” with or without filters β€” and/or on signals. here's what's on the menu rn, and the BNF for how you write them:

<trigger>    :=  <symbol> "@" <actions>
<actions>    :=  <action>  | <action> "," <actions>
<action>     :=  "depth="<num> | "trace" | "trace_on" | "trace_off" |
                 "time="<time_spec> | "size="<num> | "read="<read_spec> |
                 "finish" | "filter" | "notrace" | "recover"
                 "filter" | "notrace" | "recover" | "if:"<cond_spec>
<time_unit>  :=  "ns" | "nsec" | "us" | "usec" | "ms" | "msec" | "s" | "sec" | "m" | "min"
<read_spec>  :=  "proc/statm" | "page-fault" | "pmu-cycle" | "pmu-cache" | "pmu-branch"
<cond_spec>  :=  "arg"<num> <cond_op> <num>
<cond_op>    :=  "==" | "!=" | ">" | ">=" | "<" | "<="

(yes, filter, notrace and recover are listed twice in there. iconic. we keep it exactly as it is, no cap πŸ’…)

The depth trigger changes the filter depth while the function is running. so you can have different filter depths for different functions. the way that works is so handy 🫢

here's a whole example showing triggers in action. the global filter max depth is 5, but the moment function b() gets called, it flips to 1 β€” so everything below b() just... doesn't show up. bye πŸ‘‹

$ uftrace record -D 5 -T 'b@depth=1' ./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 */

the backtrace trigger only actually does anything in the replay command. just so we're clear ✨

The trace_on and trace_off actions (and yes, you can drop the _ and just write traceon and traceoff, we love a shortcut) control whether uftrace records the functions you specified or not.

The recover trigger is for some corner cases where the process accesses the callstack directly. ngl, as of now you don't need to call it at all β€” uftrace does that job automatically. it's giving "we already handled it, bestie" πŸ’…

The time trigger changes the time filter setting while the function is executing. so you can apply a different time filter to different functions. obsessed πŸ’–

The read trigger reads some info at runtime. the result gets recorded as (builtin) events at the beginning and the end of the given function. as of now, these are the events on the roster:

  • β€œproc/statm”: process memory stat from /proc filesystem
  • β€œpage-fault”: number of page faults using getrusage(2)
  • β€œpmu-cycle”: cpu cycles and instructions using Linux perf-event syscall
  • β€œpmu-cache”: (cpu) cache-references and misses using Linux perf-event syscall
  • β€œpmu-branch”: branch instructions and misses using Linux perf-event syscall

and the results print as events (comments), like this:

$ 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] |     /* diff:proc/statm (size=+4KB, rss=+0KB, shared=+0KB) */
  18.380 us [ 1234] |   } /* a */
  19.537 us [ 1234] | } /* main */

The finish trigger ends recording. the process is still allowed to keep running, which is lowkey perfect for tracing unterminated processes like a daemon. slay 🌈

The filter and notrace triggers do the exact same thing as -F/--filter and -N/--notrace respectively. and yes, they can carry a condition.

⚠️ Triggers only work for user-level functions for now.

you can also use triggers on signals, bestie. that's done with a signal trigger plus the --signal option. the syntax is similar to function triggers, but only trace_on, trace_off and finish trigger actions are supported. keep that in mind πŸ‘‘

$ uftrace record --signal 'SIGUSR1@finish' ./some-daemon

πŸŽ€ ARGUMENTS πŸŽ€

uftrace can record function arguments and/or return values β€” that's the -A/--argument and -R/--retval options respectively. the syntax is very similar to triggers:

<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" | "o" | "s" | "c" | "f" | "S" | "p"
<size>        :=  "8" | "16" | "32" | "64"
<reg>         :=  <arch-specific register name>  # "rdi", "xmm0", "r0", ...
<stack>       :=  "stack" [ "+" ] <offset>

The -A/--argument option takes a symbol name pattern plus its optional specs. a spec starts with argN, where N is an index into the arguments. the index starts from 1 and lines up with the argument passing order of the calling convention on your system. heads up tho: the indexes of arguments are counted separately for integer (or pointer) and floating-point type, and they can interfere depending on the calling convention. argN is for integer arguments, fpargN is for floating-point arguments. iykyk 🧚

you can optionally specify a format and size for arguments and/or return values. here's the rundown:

  • The β€œd” format (or no format field at all) β€” uftrace treats them as long int type for integers and double for floating-point numbers.
  • The β€œi” format β€” makes it signed integer type.
  • The β€œu” format β€” for unsigned type.
  • both β€œi” and β€œu” print as decimal.
  • The β€œx” format β€” makes it print as hexadecimal.
  • The β€œo” format β€” makes it print as octal.
  • The β€œs” format β€” for null-terminated string type.
  • The β€œc” format β€” for character type.
  • The β€œf” format β€” for floating-point type, and it's generally only meaningful for return value.
  • note that fpargN doesn't take the format field at all, since it's always floating-point.
  • The β€œS” format β€” for std::string, but ngl it only supports libstdc++ library as of yet.
  • The β€œp” format β€” for function pointer. once the target address is recorded, it gets displayed as the function name. cute ✨
⚠️ pls beware when using string type arguments β€” it can crash the program if the (pointer) value is invalid. uftrace does try to keep track of valid ranges of process address space, but it might still miss some corner cases. fr fr 😭

you can also specify a specific register name or stack offset for arguments (but not for return value, sorry bestie). these register names are usable for arguments:

  • x86: rdi, rsi, rdx, rcx, r8, r9 (for integer), xmm[0-7] (for floating-point)
  • arm: r[0-3] (for integer), s[0-15] or d[0-7] (for floating-point)

examples, pls observe πŸ‘‘

$ 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 */
⚠️ note that these arguments and return value are recorded only if the executable was built with the -pg option. executables built with -finstrument-functions will straight up ignore it β€” except for library calls. and recording of arguments and return values only works with user-level functions for now. periodt πŸ’…

okay but here's the fun part: if the target program is built with debug info like DWARF, uftrace can identify the 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 when debug info isn't available. in those cases you don't need to manually specify the spec of the arguments and return value β€” just a function name (or pattern) is enough. in fact, a manual argspec will suppress the automatic argspec. so like, pick a lane bestie 😌

for example, the example above can be written like this instead:

$ 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 */

note that the argument pattern (".") matches any character, so it recorded all (supported) functions. it shows two arguments for β€œmain” and a single string argument for β€œputs”. and if you simply want to see all arguments and return values of every function (if supported), just use the -a/--auto-args option. you're welcome 🫢

🌈 DYNAMIC TRACING 🌈

ok bestie, buckle up, this is the fun part πŸ’…

πŸ¦‹ FULL DYNAMIC TRACING πŸ¦‹

so uftrace can do dynamic function tracing, which you can turn on at runtime (load-time to be precise) on x86_64 and AArch64. πŸŽ€

normally tho, before you can record functions you gotta build your target program with -pg (or -finstrument-functions), and that has a performance cost because literally every function calls mcount(). 😭 it's giving overhead.

with dynamic tracing you can trace only the specific functions you name with -P/--patch, and you can also disable specific functions with -U/--unpatch. and if you have the capstone disassembly engine you don't even need to (re)compile the target with the option above. uftrace can analyze the instructions and (if possible) copy them to a different place and rewrite it to call mcount() function so it can be traced by uftrace. after that the control is passed to the copied instructions and then returned back to the remaining instructions. no cap, it's iconic. ✨

here's the error message you get when you just run uftrace normally, because the binary doesn't call any instrumentation code (i.e. mcount):

$ gcc -o abc tests/s-abc.c
$ uftrace abc
uftrace: /home/namhyung/project/uftrace/cmd-record.c:1305:check_binary
  ERROR: Can't find 'mcount' symbol in the 'abc'.
         It seems not to be compiled with -pg or -finstrument-functions flag
         which generates traceable code.  Please check your binary file.

but when you use the -P patch option, that's when it can dynamically trace a() πŸ’–

$ uftrace record --no-libcall -P a abc
$ uftrace replay
# DURATION    TID     FUNCTION
   0.923 us [19379] | a();

and yesss, you can enable all of the functions using .' (for glob, '*') β€” that's a . matching any character in a regex pattern β€” with the P option:

$ 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 */

now heads up: -U does the opposite of -P, so you can use both together to fine-control everything. the option that comes later overrides the formers. πŸ‘‘

like if you wanna trace all functions except a in the example above:

$ uftrace record --no-libcall -P . -U a  abc
$ uftrace replay
# DURATION    TID     FUNCTION
            [19390] | main() {
            [19390] |   b() {
   0.983 us [19390] |     c();
   2.012 us [19390] |   } /* b */
   3.373 us [19390] | } /* main */
⚠️ the order of the options matters SO much. if you flip it to -U a -P . then it'll trace all the functions, since -P . will be effective for all of them. periodt.

🌸 GCC FENTRY 🌸

so if capstone isn't available, you need to add some more compiler (gcc) options when you build the target program. gcc 5.1 or more recent versions give you -mfentry and -mnop-mcount options, which add instrumentation code (i.e. calling mcount() 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. 🫢

and uftrace can selectively convert it back to call mcount() using the -P option. slay.

$ gcc -pg -mfentry -mnop-mcount -o abc-fentry tests/s-abc.c
$ uftrace record -P . --no-libcall abc-fentry
$ uftrace replay
# DURATION     TID     FUNCTION
            [ 18973] | main() {
            [ 18973] |   a() {
            [ 18973] |     b() {
   0.852 us [ 18973] |       c();
   2.378 us [ 18973] |     } /* b */
   2.909 us [ 18973] |   } /* a */
   3.756 us [ 18973] | } /* main */

πŸ’œ CLANG XRAY πŸ’œ

Clang/LLVM 4.0 ships a dynamic instrumentation technique called X-ray. it's basically a combo of gcc -mfentry -mnop-mcount and -finstrument-functions. and uftrace also supports dynamic tracing on executables built with X-ray. πŸ’«

for example, you can build the target program with clang using the option below and equally use -P option for dynamic tracing, like this:

$ 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 */

✨ PATCHABLE FUNCTION ENTRY ✨

recent compilers in both gcc and clang support another useful option: -fpatchable-function-entry=N[,M], which generates M NOPs before the function entry and N-M NOPs after the function entry. πŸŽ€ you can just use the case when M is 0, so -fpatchable-function-entry=N is enough.

the number of NOPs you need for dynamic tracing depends on the architecture, but x86_64 requires 5 NOPs and AArch64 requires 2 NOPs to dynamically patch a call instruction for uftrace recording. ✨

for example in x86_64, you can build the target program and trace like this:

$ gcc -fpatchable-function-entry=5 -o abc-fpatchable tests/s-abc.c
$ uftrace record -P . abc-fpatchable
$ uftrace replay
# DURATION     TID     FUNCTION
            [  6818] | main() {
            [  6818] |   a() {
            [  6818] |     b() {
            [  6818] |       c() {
   0.926 us [  6818] |         getpid();
   4.158 us [  6818] |       } /* c */
   4.590 us [  6818] |     } /* b */
   4.957 us [  6818] |   } /* a */
   5.593 us [  6818] | } /* main */

and this feature can also be used by explicitly adding the compiler attribute to some specific functions with __attribute__ ((patchable_function_entry (N,M))). for example, the tests/s-abc.c program can be modified like this:

static int c(void)
{
        return 100000;
}

__attribute__((patchable_function_entry(5)))
static int b(void)
{
        return c() + 1;
}

static int a(void)
{
        return b() - 1;
}

__attribute__((patchable_function_entry(5)))
int main(void)
{
        int ret = 0;

        ret += a();
        return ret ? 0 : 1;
}

the attribute is added to function main and b only, and this program can normally be compiled without any additional compiler options β€” but the compiler detects the attributes and adds 5 NOPs at the entry of main and b. 🀯

$ gcc -o abc tests/s-patchable-abc.c
$ uftrace record -P . abc
$ uftrace replay
# DURATION     TID     FUNCTION
            [ 20803] | main() {
   0.342 us [ 20803] |   b();
   1.608 us [ 20803] | } /* main */

with this way, uftrace can selectively trace only the functions the user wants, by explicitly adding the attribute. this approach can collect trace records in a much less intrusive way compared to tracing all the functions enabled by compiler flags. πŸ’…

πŸ“Œ the -fpatchable-function-entry=N[,M] option and its attribute have been supported since gcc-8.1 and clang-10. this dynamic tracing feature can be used in both x86_64 and AArch64 as of now.

🐍 SCRIPT EXECUTION 🐍

the uftrace tool supports script execution for each function entry and exit. the supported script types are Python 2.7, Python 3 and Lua 5.1 as of now. 🌈

you 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. πŸŽ€

$ 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")

the above script can be executed in record time like this:

$ 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

the ctx variable is a dictionary type that contains the info below. 🫢

/* context information passed to uftrace_entry(ctx) and uftrace_exit(ctx) */
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)
};

/* context information passed to uftrace_begin(ctx) */
script_context = {
    bool      record;      # True if it runs at record time, otherwise False
    string    version;     # uftrace version info
    list      cmds;        # execution commands
};

each field in script_context can be read inside the script. pls see uftrace-script(1) for the details about scripting. πŸ’–

✨ WATCH POINT ✨

okay bestie, so the uftrace watch point is literally just there to show you a certain value only when it changes. concept-wise it's the same idea as the watch features in other debuggers πŸ’…, but plot twist: it only actually works at function entry and exit, so it might miss some updates 😭. lowkey important, don't forget it.

as of now, these are the watch points we support:

  • "cpu" β€” the cpu number the current task is running on πŸ‘€
  • "var" β€” reads the value of a global variable, and you give it after the ":"

just like read triggers, the result gets displayed as an event (comment):

$ uftrace -W cpu tests/t-abc
# DURATION     TID     FUNCTION
            [ 19060] | main() {
            [ 19060] |   /* watch:cpu (cpu=8) */
            [ 19060] |   a() {
            [ 19060] |     b() {
            [ 19060] |       c() {
       2.365 us [ 19060] |         getpid();
       8.002 us [ 19060] |       } /* c */
       8.690 us [ 19060] |     } /* b */
       9.350 us [ 19060] |   } /* a */
      12.479 us [ 19060] | } /* main */

and here's how you do the var watchpoints, no cap:

$ uftrace -W var:mydata a.out
# DURATION     TID     FUNCTION
            [239842] | __monstartup() {
            [239842] |   /* watch:var (mydata=7) */
   3.534 us [239842] | } /* __monstartup */
   0.191 us [239842] | __cxa_atexit();
            [239842] | main() {
            [239842] |   foo() {
            [239842] |     /* watch:var (mydata=42) */
   0.381 us [239842] |     bar();
   1.069 us [239842] |   } /* foo */
   2.698 us [239842] | } /* main */

πŸ¦‹ SEE ALSO πŸ¦‹

let these other icons guide you, bestie:


πŸ‘‘ AUTHORS πŸ‘‘

this whole thing was brought to you by Namhyung Kim β€” namhyung@gmail.com πŸ’–. absolute main character energy, fr fr.


and that's the page, gorgeous!! the Uftrace User Manuals, dated Sep, 2018, from the UFTRACE-RECORD(1) era β€” go forth and trace, you slay πŸ’…βœ¨πŸŽ€

πŸ“¦ where this page comes from