trace(8)

๐Ÿ“ฆ version 0.36.1, in centos-stream 10, centos-stream 9, fedora 43, fedora 44

๐Ÿ’– trace(8) ๐Ÿ’–

okay bestie, this is the System Manager's Manual page for trace, the tool that's giving main character energy ๐Ÿฆ‹โœจ

๐ŸŒธ NAME ๐ŸŒธ

trace is a tool that probes functions you pick and prints their arguments or return values. It can also run a filter first. It uses Linux eBPF/bcc, so it's giving low-level ๐Ÿ’…

๐ŸŽ€ SYNOPSIS ๐ŸŽ€

trace [-h] [-b BUFFER_PAGES] [-p PID] [-L TID] [--uid UID] [-v] [-Z
STRING_SIZE] [-S] [-M MAX_EVENTS] [-t]
          [-u] [-T] [-C] [-c CGROUP_PATH] [-n NAME] [-f MSG_FILTER] [-B]
the same [-s SYM_FILE_LIST] [-K] [-U] [-a]
          [-I header] [-A]
          probe [probe ...]

Wait, correction, the lines above got mangled. Here's the real one, copied exactly:

trace [-h] [-b BUFFER_PAGES] [-p PID] [-L TID] [--uid UID] [-v] [-Z
STRING_SIZE] [-S] [-M MAX_EVENTS] [-t]
          [-u] [-T] [-C] [-c CGROUP_PATH] [-n NAME] [-f MSG_FILTER] [-B]
[-s SYM_FILE_LIST] [-K] [-U] [-a]
          [-I header] [-A]
          probe [probe ...]

๐Ÿงš DESCRIPTION ๐Ÿงš

okay so trace probes the functions you specify and shows trace messages whenever a certain condition is met ๐Ÿ‘€ You get to control the message format, so you can show function arguments and return values. it's so customizable it's unhinged ๐Ÿ”ฅ

โš ๏ธ bestie, since this uses BPF, only the root user can use this tool. no cap. sorry, not sorry ๐Ÿ™ˆ

๐Ÿฆ‹ REQUIREMENTS ๐Ÿฆ‹

You need CONFIG_BPF and bcc. that's the whole list, no extra steps ๐Ÿ’œ

โœจ OPTIONS โœจ

  • -h โ€” prints the usage message. the "help me" button ๐Ÿ†˜
  • -p PID โ€” only traces functions in the process PID ๐ŸŽฏ
  • -L TID โ€” only traces functions in the thread TID ๐Ÿงต
  • --uid UID โ€” only traces functions from user UID ๐Ÿ‘ค
  • -v โ€” shows the generated BPF program. this is for debugging, so don't panic if it looks like alien code ๐Ÿ‘ฝ
  • -z STRING_SIZE โ€” when collecting string arguments (type char*), it grabs up to STRING_SIZE characters. anything longer gets chopped ๐Ÿช“
  • -s SYM_FILE_LIST โ€” when collecting a stack trace in build id format, it uses this comma separated list to resolve symbols ๐Ÿ”
  • -S โ€” if you set this, trace also shows messages from trace's own process. it's off by default to avoid tracing storms. for example, if you trace the write system call, you don't want trace tracing its own writes to standard output ๐ŸŒช๏ธ
  • -M MAX_EVENTS โ€” prints up to MAX_EVENTS trace messages, then exits ๐Ÿ›‘
  • -t โ€” prints times as offsets from the start of the trace, in seconds โฑ๏ธ
  • -u โ€” prints UNIX timestamps instead of offsets from the trace beginning. requires -t ๐Ÿ’…
  • -T โ€” prints the time column ๐Ÿ•ฐ๏ธ
  • -C โ€” prints the CPU id ๐Ÿง 
  • -c CGROUP_PATH โ€” only traces functions in processes under the CGROUP_PATH hierarchy ๐Ÿ“‚
  • -n NAME โ€” only prints process names containing this name ๐Ÿท๏ธ
  • -f MSG_FILTER โ€” only prints event messages containing this string ๐Ÿ“จ
  • -B โ€” treats the argument of the STRCMP helper as a binary value ๐Ÿค“
  • -K โ€” prints the kernel stack for each event ๐Ÿฅž
  • -U โ€” prints the user stack for each event ๐Ÿฅž
  • -a โ€” prints virtual addresses in kernel and user stacks ๐Ÿ“
  • -I header โ€” extra header files to include in the BPF program. you need this if your filter or print expressions use types or data structures that aren't in the standard headers. for example: 'linux/mm.h' ๐Ÿ“š
  • -A โ€” prints the aggregated amount of each trace. use it together with -M/--max-events ๐Ÿงฎ
  • probe [probe ...] โ€” one or more probes that attach to functions, filter conditions, and print info. see PROBE SYNTAX below ๐ŸŽ€

๐ŸŒˆ PROBE SYNTAX ๐ŸŒˆ

the general probe syntax looks like this, bestie:

[{p,r}]:[library]:function[+offset][(signature)] [(predicate)] ["format
string"[, arguments]]

{t:category:event,u:library:probe} [(predicate)] ["format string"[,
arguments]]
  • {[{p,r}],t,u} โ€” the probe type. p is for function entry, r is for function return, t is for kernel tracepoint, and u is for a USDT probe. the default is p ๐Ÿซถ
  • [library] โ€” the library containing the probe. give the full path to the .so or executable where the function lives, or just the lib name, like c for libc. if you don't give a library, it assumes the kernel. you can also give an executable name without a full path, as long as it's in the PATH, like bash ๐Ÿ—บ๏ธ
  • category โ€” the tracepoint category, like sched or irq ๐ŸŒฟ
  • function โ€” the function to probe. offset is how far past the function's address the probe gets injected. for example kfree_skb+56 in decimal, or kfree_skb+0x38 in hex. this only works with kprobes and uprobes. if you leave it out, it's zero ๐Ÿ“
  • signature โ€” the optional signature of the function. this makes it easier to get at the arguments by name, instead of using arg1, arg2, and so on. for example, (struct timespec *ts) in the signature spot lets you use ts in your filter or print expressions ๐Ÿ’ซ
  • event โ€” the tracepoint event, like block_rq_complete โšก
  • probe โ€” the USDT probe name, like pthread_create ๐Ÿงต
  • [(predicate)] โ€” the filter on the captured data. the message only prints if the filter evaluates to true. it can be any valid C expression that uses arg1, arg2, etc., or retval in a return probe. if you need to, use C cast operators to coerce the arguments to a type. for example, if arg1 is an int, use ((int)arg1 < 0) to trace only calls where arg1 is negative ๐Ÿง
โš ๏ธ only arg1 through arg6 are supported, and only if the function uses the standard x86_64 convention, where the first six arguments are in the RDI, RSI, RDX, RCX, R8, R9 registers. no predicate means every single invocation gets traced ๐ŸŒ

the predicate can also use the STRCMP pseudo-function to compare a predefined string to a string argument. for example: STRCMP("test", arg1). order matters here: the first argument MUST be a quoted literal string, and the second can be a runtime string, usually an argument ๐Ÿ™…โ€โ™€๏ธ

  • ["format string"[, arguments]] โ€” a printf-style format string for the trace message. you can use these specifiers: %s, %d, %u, %lld, %llu, %hd, %hu, %c, %x, %llx. they work the same way as printf's. make sure you pass exactly as many arguments as there are placeholders, or it's gonna be a mess ๐Ÿซ  The specifier replacements can be any C expressions, and they can use the same keywords as the predicate (arg1, arg2, etc.) ๐Ÿ’…

on top of those, you can use %K and %U when the expression is an address that might point to executable code (aka a symbol). trace resolves %K to a kernel symbol, like vfs__read, and %U to a user-space symbol in that process, like sprintf ๐Ÿ”ฎ

in tracepoints, both the predicate and the arguments can refer to the tracepoint format structure, stored in the special args variable. for example, the block:block_rq_complete tracepoint can print or filter by args->nr_sector. to figure out your tracepoint's format, use the tplist tool ๐Ÿ•ต๏ธโ€โ™€๏ธ

in USDT probes, the arg1, ..., argN variables refer to the probe's arguments. to find out which arguments your probe has, use the tplist tool ๐Ÿ”Ž

the predicate and the format specifier replacements for printing can also use these special keywords: $pid and $tgid for the current process's pid and tgid; $uid and $gid for the current user's uid and gid; and $cpu for the current processor number ๐Ÿงš

๐Ÿ“ EXAMPLES ๐Ÿ“

okay here's the fun part ๐ŸŽ‰

Trace all invocations of the open system call, with the name of the file (from userspace) being opened:

# trace '::do_sys_open "%s", arg2@user'

Trace all invocations of the read system call where the number of bytes requested is greater than 20,000:

# trace '::sys_read (arg3 > 20000) "read %d bytes", arg3'

Trace all malloc calls and print the size of the requested allocation:

# trace ':c:malloc "size = %d", arg1'

Trace returns from the readline function in bash and print the return value as a string:

# trace 'r:bash:readline "%s", retval'

Trace the block:block_rq_complete tracepoint and print the number of sectors completed:

# trace 't:block:block_rq_complete "%d sectors", args->nr_sector'

Trace the pthread_create USDT probe from the pthread library and print the address of the thread's start function:

# trace 'u:pthread:pthread_create "start addr = %llx", arg3'

Trace the nanosleep system call and print the sleep duration in nanoseconds:

# trace 'p::SyS_nanosleep(struct timespec *ts) sleep for %lld ns
, ts->tv_nsec'

Trace the inet_pton system call using the build id mechanism and print the stack:

# trace -s /lib/x86_64-linux-gnu/libc.so.6,/bin/ping
'p:c:inet_pton' -U

๐Ÿซง SOURCE ๐Ÿซง

this is from bcc ๐Ÿ’–

https://github.com/iovisor/bcc

also check out the bcc distribution for a companion _examples.txt file. it has example usage, output, and commentary for this tool ๐Ÿ“–

๐Ÿ’ป OS ๐Ÿ’ป

Linux ๐Ÿง

๐Ÿงช STABILITY ๐Ÿงช

Unstable - in development. ๐Ÿšง so expect some wobbles ๐Ÿ™ˆ

๐Ÿ‘‘ AUTHOR ๐Ÿ‘‘

Sasha Goldshtein ๐Ÿซถ


bestie, this page lives in the USER COMMANDS section and was dated 2016-02-18, with trace(8) as its name ๐ŸŒธ go forth and trace responsibly ๐Ÿ’…โœจ

๐Ÿ“ฆ where this page comes from