opensnoop

README.md

@@ -66,6 +66,7 @@ Tools:
 
 - tools/[biosnoop](tools/biosnoop): Trace block device I/O with PID and latency. [Examples](tools/biosnoop_example.txt).
 - tools/[funccount](tools/funccount): Count kernel function calls. [Examples](tools/funccount_example.txt).
+- tools/[opensnoop](tools/opensnoop): Trace open() syscalls. [Examples](tools/opensnoop_example.txt).
 - tools/[pidpersec](tools/pidpersec): Count new processes (via fork). [Examples](tools/pidpersec_example.txt).
 - tools/[syncsnoop](tools/syncsnoop): Trace sync() syscall. [Examples](tools/syncsnoop_example.txt).
 - tools/[vfscount](tools/vfscount) tools/[vfscount.c](tools/vfscount.c): Count VFS calls. [Examples](tools/vfscount_example.txt).

man/man8/opensnoop.8

@@ -0,0 +1,86 @@
+.TH opensnoop 8 "2015-08-18" "USER COMMANDS"
+.SH NAME
+opensnoop \- Trace open() syscalls. Uses Linux eBPF/bcc.
+.SH SYNOPSIS
+.B opensnoop [\-h] [\-t] [\-x] [\-p PID]
+.SH DESCRIPTION
+opensnoop traces the open() syscall, showing which processes are attempting
+to open which files. This can be useful for determining the location of config
+and log files, or for troubleshooting applications that are failing, especially
+on startup.
+
+This works by tracing the kernel sys_open() function using dynamic tracing, and
+will need updating to match any changes to this function.
+
+Since this uses BPF, only the root user can use this tool.
+.SH REQUIREMENTS
+CONFIG_BPF and bcc.
+.SH OPTIONS
+.TP
+\-h
+Print usage message.
+.TP
+\-t
+Include a timestamp column.
+.TP
+\-x
+Only print failed opens.
+.TP
+\-p PID
+Trace this process ID only (filtered in-kernel).
+.SH EXAMPLES
+.TP
+Trace all open() syscalls:
+#
+.B opensnoop
+.TP
+Trace all open() syscalls, and include timestamps:
+#
+.B opensnoop \-t
+.TP
+Trace only open() syscalls that failed:
+#
+.B opensnoop \-x
+.TP
+Trace PID 181 only:
+#
+.B opensnoop \-p 181
+.SH FIELDS
+.TP
+TIME(s)
+Time of the call, in seconds.
+.TP
+PID
+Process ID
+.TP
+COMM
+Process name
+.TP
+FD
+File descriptor (if success), or -1 (if failed)
+.TP
+ERR
+Error number (see the system's errno.h)
+.TP
+PATH
+Open path
+.SH OVERHEAD
+This traces the kernel open function and prints output for each event. As the
+rate of this is generally expected to be low (< 1000/s), the overhead is also
+expected to be negligible. If you have an application that is calling a high
+rate of open()s, then test and understand overhead before use.
+.SH SOURCE
+This is from bcc.
+.IP
+https://github.com/iovisor/bcc
+.PP
+Also look in the bcc distribution for a companion _examples.txt file containing
+example usage, output, and commentary for this tool.
+.SH OS
+Linux
+.SH STABILITY
+Unstable - in development.
+.SH AUTHOR
+Brendan Gregg
+.SH SEE ALSO
+funccount(1)

tools/opensnoop

@@ -0,0 +1,109 @@
+#!/usr/bin/python
+#
+# opensnoop Trace open() syscalls.
+# For Linux, uses BCC, eBPF. Embedded C.
+#
+# USAGE: opensnoop [-h] [-t] [-x] [-p PID]
+#
+# Copyright (c) 2015 Brendan Gregg.
+# Licensed under the Apache License, Version 2.0 (the "License")
+#
+# 17-Sep-2015 Brendan Gregg Created this.
+
+from __future__ import print_function
+from bcc import BPF
+import argparse
+
+# arguments
+examples = """examples:
+ ./opensnoop # trace all open() syscalls
+ ./opensnoop -t # include timestamps
+ ./opensnoop -x # only show failed opens
+ ./opensnoop -p 181 # only trace PID 181
+"""
+parser = argparse.ArgumentParser(
+ description="Trace open() syscalls",
+ formatter_class=argparse.RawDescriptionHelpFormatter,
+ epilog=examples)
+parser.add_argument("-t", "--timestamp", action="store_true",
+ help="include timestamp on output")
+parser.add_argument("-x", "--failed", action="store_true",
+ help="only show failed opens")
+parser.add_argument("-p", "--pid",
+ help="trace this PID only")
+args = parser.parse_args()
+debug = 0
+
+# define BPF program
+bpf_text = """
+#include <uapi/linux/ptrace.h>
+
+BPF_HASH(args_filename, u32, const char *);
+
+int kprobe__sys_open(struct pt_regs *ctx, const char __user *filename)
+{
+ u32 pid = bpf_get_current_pid_tgid();
+
+ FILTER
+ args_filename.update(&pid, &filename);
+
+ return 0;
+};
+
+int kretprobe__sys_open(struct pt_regs *ctx)
+{
+ const char **filenamep;
+ int ret = ctx->ax;
+ u32 pid = bpf_get_current_pid_tgid();
+
+ filenamep = args_filename.lookup(&pid);
+ if (filenamep == 0) {
+ // missed entry
+ return 0;
+ }
+
+ bpf_trace_printk("%s %d\\n", *filenamep, ret);
+ args_filename.delete(&pid);
+
+ return 0;
+}
+"""
+if args.pid:
+ bpf_text = bpf_text.replace('FILTER',
+ 'if (pid != %s) { return 0; }' % args.pid)
+else:
+ bpf_text = bpf_text.replace('FILTER', '')
+if debug:
+ print(bpf_text)
+
+# initialize BPF
+b = BPF(text=bpf_text)
+
+# header
+if args.timestamp:
+ print("%-14s" % ("TIME(s)"), end="")
+print("%-6s %-16s %4s %3s %s" % ("PID", "COMM", "FD", "ERR", "PATH"))
+
+start_ts = 0
+
+# format output
+while 1:
+ (task, pid, cpu, flags, ts, msg) = b.trace_fields()
+ (filenamp, ret_s) = msg.split(" ")
+
+ ret = int(ret_s)
+ if (args.failed and (ret >= 0)):
+ continue
+
+ # split return value into FD and errno columns
+ if ret >= 0:
+ fd_s = ret; err = 0
+ else:
+ fd_s = "-1"; err = - ret
+
+ # print columns
+ if args.timestamp:
+ if start_ts == 0:
+ start_ts = ts
+ print("%-14.9f" % (ts - start_ts), end="")
+ print("%-6d %-16s %4s %3s %s" % (pid, task, fd_s, err, filenamp))

tools/opensnoop_example.txt

@@ -0,0 +1,115 @@
+Demonstrations of opensnoop, the Linux eBPF/bcc version.
+
+
+opensnoop traces the open() syscall system-wide, and prints various details.
+Example output:
+
+# ./opensnoop
+PID COMM FD ERR PATH
+17326 <...> 7 0 /sys/kernel/debug/tracing/trace_pipe
+1576 snmpd 9 0 /proc/net/dev
+1576 snmpd 11 0 /proc/net/if_inet6
+1576 snmpd 11 0 /proc/sys/net/ipv4/neigh/eth0/retrans_time_ms
+1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/eth0/retrans_time_ms
+1576 snmpd 11 0 /proc/sys/net/ipv6/conf/eth0/forwarding
+1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/eth0/base_reachable_time_ms
+1576 snmpd 11 0 /proc/sys/net/ipv4/neigh/lo/retrans_time_ms
+1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/lo/retrans_time_ms
+1576 snmpd 11 0 /proc/sys/net/ipv6/conf/lo/forwarding
+1576 snmpd 11 0 /proc/sys/net/ipv6/neigh/lo/base_reachable_time_ms
+1576 snmpd 9 0 /proc/diskstats
+1576 snmpd 9 0 /proc/stat
+1576 snmpd 9 0 /proc/vmstat
+1956 supervise 9 0 supervise/status.new
+1956 supervise 9 0 supervise/status.new
+17358 run 3 0 /etc/ld.so.cache
+17358 run 3 0 /lib/x86_64-linux-gnu/libtinfo.so.5
+17358 run 3 0 /lib/x86_64-linux-gnu/libdl.so.2
+17358 run 3 0 /lib/x86_64-linux-gnu/libc.so.6
+17358 run -1 6 /dev/tty
+17358 run 3 0 /proc/meminfo
+17358 run 3 0 /etc/nsswitch.conf
+17358 run 3 0 /etc/ld.so.cache
+17358 run 3 0 /lib/x86_64-linux-gnu/libnss_compat.so.2
+17358 run 3 0 /lib/x86_64-linux-gnu/libnsl.so.1
+17358 run 3 0 /etc/ld.so.cache
+17358 run 3 0 /lib/x86_64-linux-gnu/libnss_nis.so.2
+17358 run 3 0 /lib/x86_64-linux-gnu/libnss_files.so.2
+17358 run 3 0 /etc/passwd
+17358 run 3 0 ./run
+^C
+
+While tracing, the snmpd process opened various /proc files (reading metrics),
+and a "run" process read various libraries and config files (looks like it
+was starting up: a new process).
+
+opensnoop can be useful for discovering configuration and log files, if used
+during application startup.
+
+
+The -p option can be used to filter on a PID, which is filtered in-kernel. Here
+I've used it with -t to print timestamps:
+
+ ./opensnoop -tp 1956
+TIME(s) PID COMM FD ERR PATH
+0.000000000 1956 supervise 9 0 supervise/status.new
+0.000289999 1956 supervise 9 0 supervise/status.new
+1.023068000 1956 supervise 9 0 supervise/status.new
+1.023381997 1956 supervise 9 0 supervise/status.new
+2.046030000 1956 supervise 9 0 supervise/status.new
+2.046363000 1956 supervise 9 0 supervise/status.new
+3.068203997 1956 supervise 9 0 supervise/status.new
+3.068544999 1956 supervise 9 0 supervise/status.new
+
+This shows the supervise process is opening the status.new file twice every
+second.
+
+
+The -x option only prints failed opens:
+
+# ./opensnoop -x
+PID COMM FD ERR PATH
+18372 run -1 6 /dev/tty
+18373 run -1 6 /dev/tty
+18373 multilog -1 13 lock
+18372 multilog -1 13 lock
+18384 df -1 2 /usr/share/locale/en_US.UTF-8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale/en_US.utf8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale/en_US/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale/en.UTF-8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale/en.utf8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale/en/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale-langpack/en_US.UTF-8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale-langpack/en_US.utf8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale-langpack/en_US/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale-langpack/en.UTF-8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale-langpack/en.utf8/LC_MESSAGES/coreutils.mo
+18384 df -1 2 /usr/share/locale-langpack/en/LC_MESSAGES/coreutils.mo
+18385 run -1 6 /dev/tty
+18386 run -1 6 /dev/tty
+
+This caught a df command failing to open a coreutils.mo file, and trying from
+different directories.
+
+The ERR column is the system error number. Error number 2 is ENOENT: no such
+file or directory.
+
+
+USAGE message:
+
+# ./opensnoop -h
+usage: opensnoop [-h] [-t] [-x] [-p PID]
+
+Trace open() syscalls
+
+optional arguments:
+ -h, --help show this help message and exit
+ -t, --timestamp include timestamp on output
+ -x, --failed only show failed opens
+ -p PID, --pid PID trace this PID only
+
+examples:
+ ./opensnoop # trace all open() syscalls
+ ./opensnoop -t # include timestamps
+ ./opensnoop -x # only show failed opens
+ ./opensnoop -p 181 # only trace PID 181