execsnoop_example.txt

Demonstrations of execsnoop, the Linux ftrace version.


Here's execsnoop showing what's really executed by "man ls":

# ./execsnoop 
Tracing exec()s. Ctrl-C to end.
   PID   PPID ARGS
 22898  22004 man ls
 22905  22898 preconv -e UTF-8
 22908  22898 pager -s
 22907  22898 nroff -mandoc -rLL=164n -rLT=164n -Tutf8
 22906  22898 tbl
 22911  22910 locale charmap
 22912  22907 groff -mtty-char -Tutf8 -mandoc -rLL=164n -rLT=164n
 22913  22912 troff -mtty-char -mandoc -rLL=164n -rLT=164n -Tutf8
 22914  22912 grotty

Many commands. This is particularly useful for understanding application
startup.


Another use for execsnoop is identifying short-lived processes. Eg, with the -t
option to see timestamps:

# ./execsnoop -t
Tracing exec()s. Ctrl-C to end.
TIMEs               PID   PPID ARGS
7419756.154031     8185   8181 mawk -W interactive -v o=1 -v opt_name=0 -v name= [...]
7419756.154131     8186   8184 cat -v trace_pipe
7419756.245264     8188   1698 ./run
7419756.245691     8189   1696 ./run
7419756.246212     8187   1689 ./run
7419756.278993     8190   1693 ./run
7419756.278996     8191   1692 ./run
7419756.288430     8192   1695 ./run
7419756.290115     8193   1691 ./run
7419756.292406     8194   1699 ./run
7419756.293986     8195   1690 ./run
7419756.294149     8196   1686 ./run
7419756.296527     8197   1687 ./run
7419756.296973     8198   1697 ./run
7419756.298356     8200   1685 ./run
7419756.298683     8199   1688 ./run
7419757.269883     8201   1696 ./run
[...]

So we're running many "run" commands every second. The PPID is included, so I
can debug this further (they are "supervise" processes).

Short-lived processes can consume CPU and not be visible from top(1), and can
be the source of hidden performance issues.


Run -h to print the USAGE message:

# ./execsnoop -h
USAGE: execsnoop [-hrt] [-a argc] [-d secs] [name]
                 -d seconds      # trace duration, and use buffers
                 -a argc         # max args to show (default 8)
                 -r              # include re-execs
                 -t              # include time (seconds)
                 -h              # this usage message
                 name            # process name to match (REs allowed)
  eg,
       execsnoop                 # watch exec()s live (unbuffered)
       execsnoop -d 1            # trace 1 sec (buffered)
       execsnoop grep            # trace process names containing grep
       execsnoop 'log$'          # filenames ending in "log"

See the man page and example file for more info.