UFTRACE-REPLAY(1)

πŸ’– uftrace-replay β€” the manual, but make it make sense ✨

okay bestie, this is the uftrace-replay(1) page from the General Commands Manual section, and it is long, so we're doing it in parts. Part 1, lesgo 🫢


🌸 NAME 🌸

uftrace-replay β€” print the recorded function trace πŸŽ€


πŸ¦‹ SYNOPSIS πŸ¦‹

uftrace replay [options]

✨ DESCRIPTION ✨

So basically? This command prints the trace data you already recorded with the uftrace-record(1) command. πŸŽ₯

And the traced functions come out in time order, shaped like a C program. It's giving "your program but narrated". Iconic.


πŸ’… REPLAY OPTIONS πŸ’…

the main character options, periodt

  • -f FIELD, --output-fields=FIELD β€” customize what fields show up in the output. possible values are: duration, tid, addr, time, delta, elapsed, task and module. you can stack multiple fields with a comma. there's also a special none field you can use (solely, meaning on its own) to hide all the fields. default is duration,tid. more deets in FIELDS. πŸ’–
  • --flat β€” print the flat format instead of the C-like format. ngl this one is usually for debugging and testing purposes.
  • --column-view β€” show each task in its own separate column. makes it so much easier to tell functions in different tasks apart. πŸ™Œ
  • --column-offset=DEPTH β€” when you're using --column-view, this sets how much offset goes between each task. default is 8.
  • --task-newline β€” drops a new line in whenever the task changes. again, easy peasy for telling different tasks' functions apart. ✨
  • --no-comment β€” don't show comments of returned functions.
  • --libname β€” show libname name along with the function name.
  • --srcline β€” show the source location of each function, if it's available. πŸ“
  • --format=TYPE β€” show format-style output. right now normal and html styles are supported.
  • --no-args β€” don't show function arguments and return values.

🫢 COMMON OPTIONS 🫢

the shared ones, iykyk

  • -F FUNC, --filter=FUNC β€” set a filter to trace selected functions and their children functions. you can use this option more than once. see FILTERS. 🌈
  • -N FUNC, --notrace=FUNC β€” set a filter to not trace selected functions and their children functions. can be used more than once. see FILTERS.
  • -C FUNC, --caller-filter=FUNC β€” set a filter to trace the callers of selected functions only. can be used more than once. see FILTERS.
  • -T TRG, --trigger=TRG β€” set a trigger on selected functions. can be used more than once. see TRIGGERS. πŸ”₯
  • -D DEPTH, --depth DEPTH β€” set the trace limit in nesting level. see FILTERS.
  • -t TIME, --time-filter=TIME β€” do not show functions that run under the time threshold. but!! if some functions explicitly have the trace trigger applied, those are always traced no matter how fast they ran. 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. can be used more than once. see FILTERS.
  • --no-libcall β€” don't show library calls.
  • --no-event β€” don't show any events. implies --no-sched.
  • --no-sched β€” don't show schedule events.
  • --no-sched-preempt β€” don't show preempt schedule events, but do still show regular (sleeping) schedule events.
  • --match=TYPE β€” use pattern matching with TYPE. possible types are regex and glob. default is regex.
  • --disable β€” ⚠️ DEPRECATED. use --trace=off instead.
  • --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 the DIR directory instead of from the binary. super handy for dealing with stripped binaries. πŸ’€ the file name of the main binary should be the same when it was saved and when it's used.

πŸ‘‘ COMMON ANALYSIS OPTIONS πŸ‘‘

  • -H FUNC, --hide=FUNC β€” set a filter to not trace selected functions. it doesn't affect their subtrees at all β€” it only hides the given functions themselves. can be used more than once. see FILTERS. πŸ™ˆ
  • --kernel-full β€” show all kernel functions and events that occurred outside of user functions.
  • --kernel-only β€” show kernel functions only, no 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 a <time_unit> postfix, for example 100us. the timestamp or elapsed time can be shown with -f time or -f elapsed option respectively. see FILTERS. ⭐

more parts coming, don't go anywhere bestie πŸ’œ

✨ FILTERS ✨

okay bestie so uftrace has this whole filtering thing where you can yeet the uninteresting functions out of your trace πŸ’…. When uftrace is called it receives two types of function filter; an opt-in filter with -F/--filter and an opt-out filter with -N/--notrace. These filters can be applied either at record time or replay time. periodt.


The first one is an opt-in filter ✨. By default, it doesn’t show anything. But when one of the specified functions is met, printing is started. When the function returns, printing is stopped again. it's giving spotlight πŸŽ€.

For example, consider a simple program which calls a(), b() and c() in turn.

$ 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 replay will show all the functions from main() to 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 */

But when the -F b filter option is used, it will not show main() or a() but only b() and c(). Note that the filter was set on uftrace replay, not at record time. 😌

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

The second type of filter is opt-out 🫢. When used, everything is shown by default, but printing stops once one of the specified functions is met. When the given function returns, printing is started again.

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

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

The filter condition can be applied to uftrace replay. But it’d work only if arguments are saved by uftrace record. πŸ‘€

You can hide the function b() only without affecting the calls it makes in its subtree functions with -H option.

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

The above -H option is especially useful when hiding std namespace functions in C++ programs by using -H ^std:: option setting. 🧚

If users only care about specific functions and want to know how they are called, one can use the caller filter. It makes the function as leaf and prints the parent functions to the function. main character energy fr fr πŸ‘‘

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

In the above example, functions not in the calling path were not shown. Also the function c' - which is a child of the function b' - is also hidden.

In addition, you can limit the print nesting level with -D option.

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

In the above example, uftrace only prints functions up to a depth of 3, so leaf function c() was omitted. Note that the -D option also works with -F. πŸ’…

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 -t/--time-filter 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:

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

You can also see replay output with different time threshold for the same recorded data. πŸ¦‹

$ uftrace replay -t 6us
# DURATION    TID     FUNCTION
 138.494 us [ 1234] | __cxa_atexit();
          [ 1234] | main() {
 6.448 us [ 1234] |   a();
 8.631 us [ 1234] | } /* main */

In addition, The -r option can show functions executed within the given time range. When using this option, you can see TIMESTAMP or ELAPSED fields as well as DURATION and TID. ⏳

$ uftrace replay -r 502716.387320101~502716.387322389
#     TIMESTAMP      DURATION    TID     FUNCTION
502716.387320101   0.289 us [ 6126] |   fgets();
502716.387320584            [ 6126] |   get_values_from() {
502716.387320709   0.245 us [ 6126] |     strdup();
502716.387321172   0.144 us [ 6126] |     strsep();
502716.387321542   0.223 us [ 6126] |     atoi();
502716.387321983   0.239 us [ 6126] |     atoi();
502716.387322389   1.805 us [ 6126] |   } /* get_values_from */
$ uftrace replay -r 40us~ | head -10
#  ELAPSED   DURATION    TID     FUNCTION
  40.141 us            [ 6126] |   get_values_from() {
  40.269 us   0.249 us [ 6126] |     strdup();
  40.756 us   0.149 us [ 6126] |     strsep();
  41.119 us   0.235 us [ 6126] |     atoi();
  41.578 us   0.211 us [ 6126] |     atoi();
  41.957 us   1.816 us [ 6126] |   } /* get_values_from */
  42.124 us   0.220 us [ 6126] |   fgets();
  42.529 us            [ 6126] |   get_values_from() {
  42.645 us   0.236 us [ 6126] |     strdup();

In addition, you can set filter to trace selected source locations with -L option. For this option, the --srcline option is required when using record command. πŸ“

$ uftrace record --srcline t-lib
$ uftrace replay --srcline -L s-libmain.c
# 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 */

You can set filter with the @hide suffix not to trace selected source locations. πŸ™ˆ

$ uftrace replay -L libmain*@hide
# DURATION     TID     FUNCTION
          [   866] | lib_a() {
          [   866] |   lib_b() {
 1.576 us [   866] |     lib_c();
 2.833 us [   866] |   } /* lib_b */
 3.132 us [   866] | } /* lib_a */

The -Z/--size-filter option is to filter functions that has small sizes. It reads symbols size from the .sym files and compare it with the given value. Note that .sym files might not have the precise value of the function size as it doesn’t save the size value. It calculate the function size from the difference of two adjacent function addresses. So if the compiler aligns the function start addresses by padding NOP instructions at the end, it could have slightly bigger size than the actual value. πŸ’€

$ uftrace record  t-arg
$ uftrace replay -Z 100
# 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. See TRIGGERS section below for details. πŸ”₯

πŸ’₯ TRIGGERS πŸ’₯

Okay bestie, this is the part where uftrace gets main character energy ✨. uftrace can trigger actions on function calls β€” with or without filters. Right now the supported triggers are depth, backtrace, trace_on and trace_off. And the BNF for trigger specs is, and I quote, exactly this:

<trigger>    :=  <symbol> "@" <actions>
<actions>    :=  <action>  | <action> "," <actions>
<action>     :=  "depth="<num> | "backtrace" | "trace_on" | "trace_off" |
                 "color="<color> | "time="<time_spec> | "size="<num> |
                 "filter" | "notrace" | "hide" | "if:"<cond_spec>
<time_spec>  :=  <num> [ <time_unit> ]
<time_unit>  :=  "ns" | "nsec" | "us" | "usec" | "ms" | "msec" | "s" | "sec" | "m" | "min"
<cond_spec>  :=  "arg"<num> <cond_op> <num>
<cond_op>    :=  "==" | "!=" | ">" | ">=" | "<" | "<="
  • The depth trigger changes the filter depth while the function is executing, so you can lowkey apply different filter depths to different functions πŸ‘‘.
  • The backtrace trigger prints a stack backtrace at replay time.
  • The color trigger changes the color of the function in replay output πŸ’…. The supported colors are red, green, blue, yellow, magenta, cyan, bold, and gray.
  • The trace_on and trace_off actions (and yes, you can drop the _ and just write traceon / traceoff, we love minimalism πŸŽ€) control whether uftrace shows functions or not. Important vibe check: this trigger runs at replay time, not run time, which means it can handle kernel functions too 🧚. Compare that to triggers used under uftrace record.
  • The time trigger changes the time filter setting during execution of the function, so you can apply a different time filter per function.
  • The filter and notrace triggers do the same thing as -F/--filter and -N/--notrace respectively. And they can carry a condition πŸ’–.
  • The hide trigger does the same thing as -H/--hide (it hides the given functions) β€” but heads up, it does not affect the functions in their subtree, unlike the notrace trigger. Different energy, fr fr.

Here's the demo where triggers show off. We set a filter on function b() with the backtrace action, and change the max filter depth under b() to 2:

$ uftrace record ./abc
$ uftrace replay -T 'b@filter,backtrace,depth=2'
# DURATION    TID     FUNCTION
  backtrace [ 1234] | /* [ 0] main */
  backtrace [ 1234] | /* [ 1] a */
            [ 1234] | b() {
   3.880 us [ 1234] |   c();
   5.475 us [ 1234] | } /* b */

Slay. Look at that backtrace just vibing up top. 😭✨


🌈 FIELDS 🌈

uftrace lets you customize the replay output with a bunch of fields. And when we say "field", we mean the info on the left side of the pipe (|) character 🫢. By default it uses the duration and tid fields, but bestie, you can use other fields in any order you want, like this:

$ uftrace replay -f time,delta,duration,addr
#     TIMESTAMP      TIMEDELTA  DURATION     ADDRESS     FUNCTION
    74469.340757350              1.583 us       4004d0 | __monstartup();
    74469.340762221   4.871 us   0.766 us       4004f0 | __cxa_atexit();
    74469.340764847   2.626 us                  4006b1 | main() {
    74469.340765061   0.214 us                  400656 |   a() {
    74469.340765195   0.134 us                  400669 |     b() {
    74469.340765344   0.149 us                  40067c |       c() {
    74469.340765524   0.180 us   0.742 us       4004b0 |         getpid();
    74469.340766935   1.411 us   1.591 us       40067c |       } /* c */
    74469.340767195   0.260 us   2.000 us       400669 |     } /* b */
    74469.340767372   0.177 us   2.311 us       400656 |   } /* a */
    74469.340767541   0.169 us   2.694 us       4006b1 | } /* main */

what each field actually means πŸ‘‡

  • tid β€” task id (obtained by gettid(2))
  • duration β€” function execution time
  • time β€” timestamp at the execution
  • delta β€” difference between two timestamp in a task
  • elapsed β€” elapsed time from the first timestamp
  • addr β€” address of the function
  • task β€” task name (comm)
  • module β€” library or executable name of the function

The default value is duration,tid. πŸ’‘ And here's a cute trick: if the field name you give starts with +, it gets appended to the default fields. So -f +time is exactly the same as -f duration,tid,time. Obsessed with the efficiency honestly.

It also accepts a very special field name, none, which disables the field display and shows function output only. ✨ periodt.


πŸ‘€ SEE ALSO πŸ‘€


🌸 AUTHORS 🌸

Namhyung Kim namhyung@gmail.com


And that's the whole page, bestie!! πŸŽ€ This was the Uftrace User Manuals edition, dated Sep, 2018, and that's genuinely all 3 parts. Go forth, replay your traces, trigger your actions, and customize your fields like the icon you are. πŸ’–βœ¨πŸ¦‹ no cap, iykyk πŸ‘‘

πŸ“¦ where this page comes from