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 | |
| 68 | The -x option only prints failed opens: |
| 69 | |
| 70 | # ./opensnoop -x |
Alexei Starovoitov | bdf0773 | 2016-01-14 10:09:20 -0800 | [diff] [blame] | 71 | PID COMM FD ERR PATH |
| 72 | 18372 run -1 6 /dev/tty |
| 73 | 18373 run -1 6 /dev/tty |
| 74 | 18373 multilog -1 13 lock |
| 75 | 18372 multilog -1 13 lock |
| 76 | 18384 df -1 2 /usr/share/locale/en_US.UTF-8/LC_MESSAGES/coreutils.mo |
| 77 | 18384 df -1 2 /usr/share/locale/en_US.utf8/LC_MESSAGES/coreutils.mo |
| 78 | 18384 df -1 2 /usr/share/locale/en_US/LC_MESSAGES/coreutils.mo |
| 79 | 18384 df -1 2 /usr/share/locale/en.UTF-8/LC_MESSAGES/coreutils.mo |
| 80 | 18384 df -1 2 /usr/share/locale/en.utf8/LC_MESSAGES/coreutils.mo |
| 81 | 18384 df -1 2 /usr/share/locale/en/LC_MESSAGES/coreutils.mo |
| 82 | 18385 run -1 6 /dev/tty |
| 83 | 18386 run -1 6 /dev/tty |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 84 | |
| 85 | This caught a df command failing to open a coreutils.mo file, and trying from |
| 86 | different directories. |
| 87 | |
| 88 | The ERR column is the system error number. Error number 2 is ENOENT: no such |
| 89 | file or directory. |
| 90 | |
| 91 | |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 92 | A maximum tracing duration can be set with the -d option. For example, to trace |
| 93 | for 2 seconds: |
| 94 | |
| 95 | # ./opensnoop -d 2 |
| 96 | PID COMM FD ERR PATH |
| 97 | 2191 indicator-multi 11 0 /sys/block |
| 98 | 2191 indicator-multi 11 0 /sys/block |
| 99 | 2191 indicator-multi 11 0 /sys/block |
| 100 | 2191 indicator-multi 11 0 /sys/block |
| 101 | 2191 indicator-multi 11 0 /sys/block |
| 102 | |
| 103 | |
KarimAllah Ahmed | 765dfe2 | 2016-09-10 12:01:07 +0200 | [diff] [blame] | 104 | The -n option can be used to filter on process name using partial matches: |
| 105 | |
| 106 | # ./opensnoop -n ed |
| 107 | |
| 108 | PID COMM FD ERR PATH |
| 109 | 2679 sed 3 0 /etc/ld.so.cache |
| 110 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libselinux.so.1 |
| 111 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libc.so.6 |
| 112 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libpcre.so.3 |
| 113 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libdl.so.2 |
| 114 | 2679 sed 3 0 /lib/x86_64-linux-gnu/libpthread.so.0 |
| 115 | 2679 sed 3 0 /proc/filesystems |
| 116 | 2679 sed 3 0 /usr/lib/locale/locale-archive |
| 117 | 2679 sed -1 2 |
| 118 | 2679 sed 3 0 /usr/lib/x86_64-linux-gnu/gconv/gconv-modules.cache |
| 119 | 2679 sed 3 0 /dev/null |
| 120 | 2680 sed 3 0 /etc/ld.so.cache |
| 121 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libselinux.so.1 |
| 122 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libc.so.6 |
| 123 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libpcre.so.3 |
| 124 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libdl.so.2 |
| 125 | 2680 sed 3 0 /lib/x86_64-linux-gnu/libpthread.so.0 |
| 126 | 2680 sed 3 0 /proc/filesystems |
| 127 | 2680 sed 3 0 /usr/lib/locale/locale-archive |
| 128 | 2680 sed -1 2 |
| 129 | ^C |
| 130 | |
| 131 | This caught the 'sed' command because it partially matches 'ed' that's passed |
| 132 | to the '-n' option. |
| 133 | |
| 134 | |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 135 | USAGE message: |
| 136 | |
| 137 | # ./opensnoop -h |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 138 | usage: opensnoop [-h] [-T] [-x] [-p PID] [-t TID] [-d DURATION] [-n NAME] |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 139 | |
| 140 | Trace open() syscalls |
| 141 | |
| 142 | optional arguments: |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 143 | -h, --help show this help message and exit |
| 144 | -T, --timestamp include timestamp on output |
| 145 | -x, --failed only show failed opens |
| 146 | -p PID, --pid PID trace this PID only |
| 147 | -t TID, --tid TID trace this TID only |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 148 | -d DURATION, --duration DURATION |
| 149 | total duration of trace in seconds |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 150 | -n NAME, --name NAME only print process names containing this name |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 151 | |
| 152 | examples: |
| 153 | ./opensnoop # trace all open() syscalls |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 154 | ./opensnoop -T # include timestamps |
Brendan Gregg | bedd150 | 2015-09-17 21:52:52 -0700 | [diff] [blame] | 155 | ./opensnoop -x # only show failed opens |
| 156 | ./opensnoop -p 181 # only trace PID 181 |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 157 | ./opensnoop -t 123 # only trace TID 123 |
Paul Chaignon | 702de38 | 2018-01-28 13:41:35 +0100 | [diff] [blame] | 158 | ./opensnoop -d 10 # trace for 10 seconds only |
Dina Goldshtein | 99a3bc8 | 2016-10-10 21:37:36 +0300 | [diff] [blame] | 159 | ./opensnoop -n main # only print process names containing "main" |