Brendan Gregg | 2757f0e | 2016-02-10 01:38:32 -0800 | [diff] [blame] | 1 | Demonstrations of dcsnoop, the Linux eBPF/bcc version. |
| 2 | |
| 3 | |
| 4 | dcsnoop traces directory entry cache (dcache) lookups, and can be used for |
| 5 | further investigation beyond dcstat(8). The output is likely verbose, as |
| 6 | dcache lookups are likely frequent. By default, only failed lookups are shown. |
| 7 | For example: |
| 8 | |
| 9 | # ./dcsnoop.py |
| 10 | TIME(s) PID COMM T FILE |
| 11 | 0.002837 1643 snmpd M net/dev |
| 12 | 0.002852 1643 snmpd M 1643 |
| 13 | 0.002856 1643 snmpd M net |
| 14 | 0.002863 1643 snmpd M dev |
| 15 | 0.002952 1643 snmpd M net/if_inet6 |
| 16 | 0.002964 1643 snmpd M if_inet6 |
| 17 | 0.003180 1643 snmpd M net/ipv4/neigh/eth0/retrans_time_ms |
| 18 | 0.003192 1643 snmpd M ipv4/neigh/eth0/retrans_time_ms |
| 19 | 0.003197 1643 snmpd M neigh/eth0/retrans_time_ms |
| 20 | 0.003203 1643 snmpd M eth0/retrans_time_ms |
| 21 | 0.003206 1643 snmpd M retrans_time_ms |
| 22 | 0.003245 1643 snmpd M ipv6/neigh/eth0/retrans_time_ms |
| 23 | 0.003249 1643 snmpd M neigh/eth0/retrans_time_ms |
| 24 | 0.003252 1643 snmpd M eth0/retrans_time_ms |
| 25 | 0.003255 1643 snmpd M retrans_time_ms |
| 26 | 0.003287 1643 snmpd M conf/eth0/forwarding |
| 27 | 0.003292 1643 snmpd M eth0/forwarding |
| 28 | 0.003295 1643 snmpd M forwarding |
| 29 | 0.003326 1643 snmpd M base_reachable_time_ms |
| 30 | [...] |
| 31 | |
| 32 | I ran a drop caches at the same time as executing this tool. The output shows |
| 33 | the processes, the type of event ("T" column: M == miss, R == reference), |
| 34 | and the filename for the dcache lookup. |
| 35 | |
| 36 | The way the dcache is currently implemented, each component of a path is |
| 37 | checked in turn. The first line, showing "net/dev" from snmp, will be a lookup |
| 38 | for "net" in a directory (that isn't shown here). If it finds "net", it will |
| 39 | then lookup "dev" inside net. You can see this sequence a little later, |
| 40 | starting at time 0.003180, where a pathname is being searched |
| 41 | directory by directory. |
| 42 | |
| 43 | |
| 44 | The -a option will show all lookups, although be warned, the output will be |
| 45 | very verbose. For example: |
| 46 | |
| 47 | # ./dcsnoop |
| 48 | TIME(s) PID COMM T FILE |
| 49 | 0.000000 20279 dcsnoop.py M p_lookup_fast |
| 50 | 0.000010 20279 dcsnoop.py M enable |
| 51 | 0.000013 20279 dcsnoop.py M id |
| 52 | 0.000015 20279 dcsnoop.py M filter |
| 53 | 0.000017 20279 dcsnoop.py M trigger |
| 54 | 0.000019 20279 dcsnoop.py M format |
| 55 | 0.006148 20279 dcsnoop.py R sys/kernel/debug/tracing/trace_pipe |
| 56 | 0.006158 20279 dcsnoop.py R kernel/debug/tracing/trace_pipe |
| 57 | 0.006161 20279 dcsnoop.py R debug/tracing/trace_pipe |
| 58 | 0.006164 20279 dcsnoop.py R tracing/trace_pipe |
| 59 | 0.006166 20279 dcsnoop.py R trace_pipe |
| 60 | 0.015900 1643 snmpd R proc/sys/net/ipv6/conf/lo/forwarding |
| 61 | 0.015901 1643 snmpd R sys/net/ipv6/conf/lo/forwarding |
| 62 | 0.015901 1643 snmpd R net/ipv6/conf/lo/forwarding |
| 63 | 0.015902 1643 snmpd R ipv6/conf/lo/forwarding |
| 64 | 0.015903 1643 snmpd R conf/lo/forwarding |
| 65 | 0.015904 1643 snmpd R lo/forwarding |
| 66 | 0.015905 1643 snmpd M lo/forwarding |
| 67 | 0.015908 1643 snmpd R forwarding |
| 68 | 0.015909 1643 snmpd M forwarding |
| 69 | 0.015937 1643 snmpd R proc/sys/net/ipv6/neigh/lo/base_reachable_time_ms |
| 70 | 0.015937 1643 snmpd R sys/net/ipv6/neigh/lo/base_reachable_time_ms |
| 71 | 0.015938 1643 snmpd R net/ipv6/neigh/lo/base_reachable_time_ms |
| 72 | 0.015939 1643 snmpd R ipv6/neigh/lo/base_reachable_time_ms |
| 73 | 0.015940 1643 snmpd R neigh/lo/base_reachable_time_ms |
| 74 | 0.015941 1643 snmpd R lo/base_reachable_time_ms |
| 75 | 0.015941 1643 snmpd R base_reachable_time_ms |
| 76 | 0.015943 1643 snmpd M base_reachable_time_ms |
| 77 | 0.043569 1876 supervise M 20281 |
| 78 | 0.043573 1886 supervise M 20280 |
| 79 | 0.043582 1886 supervise R supervise/status.new |
| 80 | [...] |
| 81 | |
| 82 | |
| 83 | USAGE message: |
| 84 | |
| 85 | # ./dcsnoop.py -h |
| 86 | usage: dcsnoop.py [-h] [-a] |
| 87 | |
| 88 | Trace directory entry cache (dcache) lookups |
| 89 | |
| 90 | optional arguments: |
| 91 | -h, --help show this help message and exit |
| 92 | -a, --all trace all lookups (default is fails only) |
| 93 | |
| 94 | examples: |
| 95 | ./dcsnoop # trace failed dcache lookups |
| 96 | ./dcsnoop -a # trace all dcache lookups |