Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 1 | Demonstrations of opensnoop, the Linux eBPF/bcc version. |
| 2 | |
| 3 | |
| 4 | opensnoop traces the open() syscall system-wide, and prints various details. |
| 5 | Example output: |
| 6 | |
| 7 | # ./opensnoop |
Alexei Starovoitov | bdf0773 | 2016-01-14 10:09:20 -0800 | [diff] [blame] | 8 | PID COMM FD ERR PATH |
| 9 | 17326 <...> 7 0 /sys/kernel/debug/tracing/trace_pipe |
| 10 | 1576 snmpd 9 0 /proc/net/dev |
| 11 | 1576 snmpd 11 0 /proc/net/if_inet6 |
| 12 | 1576 snmpd 11 0 /proc/sys/net/ipv4/neigh/eth0/retrans_time_ms |
| 13 | 1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/eth0/retrans_time_ms |
| 14 | 1576 snmpd 11 0 /proc/sys/net/ipv6/conf/eth0/forwarding |
| 15 | 1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/eth0/base_reachable_time_ms |
| 16 | 1576 snmpd 11 0 /proc/sys/net/ipv4/neigh/lo/retrans_time_ms |
| 17 | 1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/lo/retrans_time_ms |
| 18 | 1576 snmpd 11 0 /proc/sys/net/ipv6/conf/lo/forwarding |
| 19 | 1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/lo/base_reachable_time_ms |
| 20 | 1576 snmpd 9 0 /proc/diskstats |
| 21 | 1576 snmpd 9 0 /proc/stat |
| 22 | 1576 snmpd 9 0 /proc/vmstat |
| 23 | 1956 supervise 9 0 supervise/status.new |
| 24 | 1956 supervise 9 0 supervise/status.new |
| 25 | 17358 run 3 0 /etc/ld.so.cache |
| 26 | 17358 run 3 0 /lib/x86_64-linux-gnu/libtinfo.so.5 |
| 27 | 17358 run 3 0 /lib/x86_64-linux-gnu/libdl.so.2 |
| 28 | 17358 run 3 0 /lib/x86_64-linux-gnu/libc.so.6 |
| 29 | 17358 run -1 6 /dev/tty |
| 30 | 17358 run 3 0 /proc/meminfo |
| 31 | 17358 run 3 0 /etc/nsswitch.conf |
| 32 | 17358 run 3 0 /etc/ld.so.cache |
| 33 | 17358 run 3 0 /lib/x86_64-linux-gnu/libnss_compat.so.2 |
| 34 | 17358 run 3 0 /lib/x86_64-linux-gnu/libnsl.so.1 |
| 35 | 17358 run 3 0 /etc/ld.so.cache |
| 36 | 17358 run 3 0 /lib/x86_64-linux-gnu/libnss_nis.so.2 |
| 37 | 17358 run 3 0 /lib/x86_64-linux-gnu/libnss_files.so.2 |
| 38 | 17358 run 3 0 /etc/passwd |
| 39 | 17358 run 3 0 ./run |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 40 | ^C |
| 41 | |
| 42 | While tracing, the snmpd process opened various /proc files (reading metrics), |
| 43 | and a "run" process read various libraries and config files (looks like it |
| 44 | was starting up: a new process). |
| 45 | |
| 46 | opensnoop can be useful for discovering configuration and log files, if used |
| 47 | during application startup. |
| 48 | |
| 49 | |
| 50 | The -p option can be used to filter on a PID, which is filtered in-kernel. Here |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 51 | I've used it with -T to print timestamps: |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 52 | |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 53 | ./opensnoop -Tp 1956 |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 54 | TIME(s) PID COMM FD ERR PATH |
| 55 | 0.000000000 1956 supervise 9 0 supervise/status.new |
| 56 | 0.000289999 1956 supervise 9 0 supervise/status.new |
| 57 | 1.023068000 1956 supervise 9 0 supervise/status.new |
| 58 | 1.023381997 1956 supervise 9 0 supervise/status.new |
| 59 | 2.046030000 1956 supervise 9 0 supervise/status.new |
| 60 | 2.046363000 1956 supervise 9 0 supervise/status.new |
| 61 | 3.068203997 1956 supervise 9 0 supervise/status.new |
| 62 | 3.068544999 1956 supervise 9 0 supervise/status.new |
| 63 | |
| 64 | This shows the supervise process is opening the status.new file twice every |
| 65 | second. |
| 66 | |
| 67 | |
takumakume | f899037 | 2019-01-02 17:12:14 +0900 | [diff] [blame] | 68 | The -U option include UID on output: |
| 69 | |
| 70 | # ./opensnoop -U |
| 71 | UID PID COMM FD ERR PATH |
| 72 | 0 27063 vminfo 5 0 /var/run/utmp |
| 73 | 103 628 dbus-daemon -1 2 /usr/local/share/dbus-1/system-services |
| 74 | 103 628 dbus-daemon 18 0 /usr/share/dbus-1/system-services |
| 75 | 103 628 dbus-daemon -1 2 /lib/dbus-1/system-services |
| 76 | |
| 77 | |
| 78 | The -u option filtering UID: |
| 79 | |
| 80 | # ./opensnoop -Uu 1000 |
| 81 | UID PID COMM FD ERR PATH |
| 82 | 1000 30240 ls 3 0 /etc/ld.so.cache |
| 83 | 1000 30240 ls 3 0 /lib/x86_64-linux-gnu/libselinux.so.1 |
| 84 | 1000 30240 ls 3 0 /lib/x86_64-linux-gnu/libc.so.6 |
| 85 | 1000 30240 ls 3 0 /lib/x86_64-linux-gnu/libpcre.so.3 |
| 86 | 1000 30240 ls 3 0 /lib/x86_64-linux-gnu/libdl.so.2 |
| 87 | 1000 30240 ls 3 0 /lib/x86_64-linux-gnu/libpthread.so.0 |
| 88 | |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 89 | The -x option only prints failed opens: |
| 90 | |
| 91 | # ./opensnoop -x |
Alexei Starovoitov | bdf0773 | 2016-01-14 10:09:20 -0800 | [diff] [blame] | 92 | PID COMM FD ERR PATH |
| 93 | 18372 run -1 6 /dev/tty |
| 94 | 18373 run -1 6 /dev/tty |
| 95 | 18373 multilog -1 13 lock |
| 96 | 18372 multilog -1 13 lock |
| 97 | 18384 df -1 2 /usr/share/locale/en_US.UTF-8/LC_MESSAGES/coreutils.mo |
| 98 | 18384 df -1 2 /usr/share/locale/en_US.utf8/LC_MESSAGES/coreutils.mo |
| 99 | 18384 df -1 2 /usr/share/locale/en_US/LC_MESSAGES/coreutils.mo |
| 100 | 18384 df -1 2 /usr/share/locale/en.UTF-8/LC_MESSAGES/coreutils.mo |
| 101 | 18384 df -1 2 /usr/share/locale/en.utf8/LC_MESSAGES/coreutils.mo |
| 102 | 18384 df -1 2 /usr/share/locale/en/LC_MESSAGES/coreutils.mo |
| 103 | 18385 run -1 6 /dev/tty |
| 104 | 18386 run -1 6 /dev/tty |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 105 | |
| 106 | This caught a df command failing to open a coreutils.mo file, and trying from |
| 107 | different directories. |
| 108 | |
| 109 | The ERR column is the system error number. Error number 2 is ENOENT: no such |
| 110 | file or directory. |
| 111 | |
| 112 | |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 113 | A maximum tracing duration can be set with the -d option. For example, to trace |
| 114 | for 2 seconds: |
| 115 | |
| 116 | # ./opensnoop -d 2 |
| 117 | PID COMM FD ERR PATH |
| 118 | 2191 indicator-multi 11 0 /sys/block |
| 119 | 2191 indicator-multi 11 0 /sys/block |
| 120 | 2191 indicator-multi 11 0 /sys/block |
| 121 | 2191 indicator-multi 11 0 /sys/block |
| 122 | 2191 indicator-multi 11 0 /sys/block |
| 123 | |
| 124 | |
KarimAllah Ahmed | 765dfe2 | 2016-09-10 12:01:07 +0200 | [diff] [blame] | 125 | The -n option can be used to filter on process name using partial matches: |
| 126 | |
| 127 | # ./opensnoop -n ed |
| 128 | |
| 129 | PID COMM FD ERR PATH |
| 130 | 2679 sed 3 0 /etc/ld.so.cache |
| 131 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libselinux.so.1 |
| 132 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libc.so.6 |
| 133 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libpcre.so.3 |
| 134 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libdl.so.2 |
| 135 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libpthread.so.0 |
| 136 | 2679 sed 3 0 /proc/filesystems |
| 137 | 2679 sed 3 0 /usr/lib/locale/locale-archive |
| 138 | 2679 sed -1 2 |
| 139 | 2679 sed 3 0 /usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache |
| 140 | 2679 sed 3 0 /dev/null |
| 141 | 2680 sed 3 0 /etc/ld.so.cache |
| 142 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libselinux.so.1 |
| 143 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libc.so.6 |
| 144 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libpcre.so.3 |
| 145 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libdl.so.2 |
| 146 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libpthread.so.0 |
| 147 | 2680 sed 3 0 /proc/filesystems |
| 148 | 2680 sed 3 0 /usr/lib/locale/locale-archive |
| 149 | 2680 sed -1 2 |
| 150 | ^C |
| 151 | |
| 152 | This caught the 'sed' command because it partially matches 'ed' that's passed |
| 153 | to the '-n' option. |
| 154 | |
| 155 | |
Tim Douglas | d3583a8 | 2018-12-30 13:18:54 -0500 | [diff] [blame] | 156 | The -e option prints out extra columns; for example, the following output |
| 157 | contains the flags passed to open(2), in octal: |
| 158 | |
| 159 | # ./opensnoop -e |
| 160 | PID COMM FD ERR FLAGS PATH |
| 161 | 28512 sshd 10 0 00101101 /proc/self/oom_score_adj |
| 162 | 28512 sshd 3 0 02100000 /etc/ld.so.cache |
| 163 | 28512 sshd 3 0 02100000 /lib/x86_64-linux-gnu/libwrap.so.0 |
| 164 | 28512 sshd 3 0 02100000 /lib/x86_64-linux-gnu/libaudit.so.1 |
| 165 | 28512 sshd 3 0 02100000 /lib/x86_64-linux-gnu/libpam.so.0 |
| 166 | 28512 sshd 3 0 02100000 /lib/x86_64-linux-gnu/libselinux.so.1 |
| 167 | 28512 sshd 3 0 02100000 /lib/x86_64-linux-gnu/libsystemd.so.0 |
| 168 | 28512 sshd 3 0 02100000 /usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.2 |
| 169 | 28512 sshd 3 0 02100000 /lib/x86_64-linux-gnu/libutil.so.1 |
| 170 | |
| 171 | |
| 172 | The -f option filters based on flags to the open(2) call, for example: |
| 173 | |
| 174 | # ./opensnoop -e -f O_WRONLY -f O_RDWR |
| 175 | PID COMM FD ERR FLAGS PATH |
| 176 | 28084 clear_console 3 0 00100002 /dev/tty |
| 177 | 28084 clear_console -1 13 00100002 /dev/tty0 |
| 178 | 28084 clear_console -1 13 00100001 /dev/tty0 |
| 179 | 28084 clear_console -1 13 00100002 /dev/console |
| 180 | 28084 clear_console -1 13 00100001 /dev/console |
| 181 | 28051 sshd 8 0 02100002 /var/run/utmp |
| 182 | 28051 sshd 7 0 00100001 /var/log/wtmp |
| 183 | |
| 184 | |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 185 | USAGE message: |
| 186 | |
| 187 | # ./opensnoop -h |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 188 | usage: opensnoop [-h] [-T] [-x] [-p PID] [-t TID] [-d DURATION] [-n NAME] |
Tim Douglas | d3583a8 | 2018-12-30 13:18:54 -0500 | [diff] [blame] | 189 | [-e] [-f FLAG_FILTER] |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 190 | |
| 191 | Trace open() syscalls |
| 192 | |
| 193 | optional arguments: |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 194 | -h, --help show this help message and exit |
| 195 | -T, --timestamp include timestamp on output |
takumakume | f899037 | 2019-01-02 17:12:14 +0900 | [diff] [blame] | 196 | -U, --print-uid include UID on output |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 197 | -x, --failed only show failed opens |
| 198 | -p PID, --pid PID trace this PID only |
| 199 | -t TID, --tid TID trace this TID only |
takumakume | f899037 | 2019-01-02 17:12:14 +0900 | [diff] [blame] | 200 | -u UID, --uid UID trace this UID only |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 201 | -d DURATION, --duration DURATION |
| 202 | total duration of trace in seconds |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 203 | -n NAME, --name NAME only print process names containing this name |
Tim Douglas | d3583a8 | 2018-12-30 13:18:54 -0500 | [diff] [blame] | 204 | -e, --extended_fields |
| 205 | show extended fields |
| 206 | -f FLAG_FILTER, --flag_filter FLAG_FILTER |
| 207 | filter on flags argument (e.g., O_WRONLY) |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 208 | |
| 209 | examples: |
| 210 | ./opensnoop # trace all open() syscalls |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 211 | ./opensnoop -T # include timestamps |
takumakume | f899037 | 2019-01-02 17:12:14 +0900 | [diff] [blame] | 212 | ./opensnoop -U # include UID |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 213 | ./opensnoop -x # only show failed opens |
| 214 | ./opensnoop -p 181 # only trace PID 181 |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 215 | ./opensnoop -t 123 # only trace TID 123 |
takumakume | f899037 | 2019-01-02 17:12:14 +0900 | [diff] [blame] | 216 | ./opensnoop -u 1000 # only trace UID 1000 |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 217 | ./opensnoop -d 10 # trace for 10 seconds only |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 218 | ./opensnoop -n main # only print process names containing "main" |
Tim Douglas | d3583a8 | 2018-12-30 13:18:54 -0500 | [diff] [blame] | 219 | ./opensnoop -e # show extended fields |
| 220 | ./opensnoop -f O_WRONLY -f O_RDWR # only print calls for writing |