some bcc examples and tools
diff --git a/examples/bitehist.c b/examples/bitehist.c
new file mode 100644
index 0000000..e4e6772
--- /dev/null
+++ b/examples/bitehist.c
@@ -0,0 +1,48 @@
+/*
+ * bitehist.c Block I/O size histogram.
+ * For Linux, uses BCC, eBPF. See .py file.
+ *
+ * Based on eBPF sample tracex2 by Alexi Starovoitov.
+ * Copyright (c) 2013-2015 PLUMgrid, http://plumgrid.com
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of version 2 of the GNU General Public
+ * License as published by the Free Software Foundation.
+ *
+ * 15-Aug-2015 Brendan Gregg Created this.
+ */
+
+#include <uapi/linux/ptrace.h>
+#include "../../linux-4.2-rc5/include/linux/blkdev.h"
+
+BPF_TABLE("array", int, u64, dist, 64);
+
+static unsigned int log2(unsigned int v)
+{
+ unsigned int r;
+ unsigned int shift;
+
+ r = (v > 0xFFFF) << 4; v >>= r;
+ shift = (v > 0xFF) << 3; v >>= shift; r |= shift;
+ shift = (v > 0xF) << 2; v >>= shift; r |= shift;
+ shift = (v > 0x3) << 1; v >>= shift; r |= shift;
+ r |= (v >> 1);
+ return r;
+}
+
+static unsigned int log2l(unsigned long v)
+{
+ unsigned int hi = v >> 32;
+ if (hi)
+ return log2(hi) + 32 + 1;
+ else
+ return log2(v) + 1;
+}
+
+int do_request(struct pt_regs *ctx, struct request *req)
+{
+ int index = log2l(req->__data_len / 1024);
+ u64 *leaf = dist.lookup(&index);
+ if (leaf) (*leaf)++;
+
+ return 0;
+}
diff --git a/examples/bitehist.py b/examples/bitehist.py
new file mode 100755
index 0000000..ae2112b
--- /dev/null
+++ b/examples/bitehist.py
@@ -0,0 +1,109 @@
+#!/usr/bin/python
+#
+# bitehist.py Block I/O size histogram.
+# For Linux, uses BCC, eBPF. See .c file.
+#
+# Written as a basic example of using a histogram to show a distribution.
+#
+# USAGE: bitehist.py [interval [count]]
+#
+# The default interval is 5 seconds. A Ctrl-C will print the partially
+# gathered histogram then exit.
+#
+# Copyright (c) 2015 Brendan Gregg.
+# Licensed under the Apache License, Version 2.0 (the "License")
+#
+# 15-Aug-2015 Brendan Gregg Created this.
+
+from bpf import BPF
+from ctypes import c_ushort, c_int, c_ulonglong
+from time import sleep
+from sys import argv
+
+def usage():
+ print("USAGE: %s [interval [count]]" % argv[0])
+ exit()
+
+# arguments
+interval = 5
+count = -1
+if len(argv) > 1:
+ try:
+ interval = int(argv[1])
+ if interval == 0:
+ raise
+ if len(argv) > 2:
+ count = int(argv[2])
+ except: # also catches -h, --help
+ usage()
+
+# load BPF program
+b = BPF(src_file = "bitehist.c")
+BPF.attach_kprobe(b.load_func("do_request", BPF.KPROBE), "blk_start_request")
+dist = b.get_table("dist", c_int, c_ulonglong)
+dist_max = 64
+
+# header
+print("Tracing... Hit Ctrl-C to end.")
+last = {}
+for i in range(1, dist_max + 1):
+ last[i] = 0
+
+# functions
+stars_max = 38
+def stars(val, val_max, width):
+ i = 0
+ text = ""
+ while (1):
+ if (i > (width * val / val_max) - 1) or (i > width - 1):
+ break
+ text += "*"
+ i += 1
+ if val > val_max:
+ text = text[:-1] + "+"
+ return text
+
+def print_log2_hist(d, val_type):
+ idx_max = -1
+ val_max = 0
+ for i in range(1, dist_max + 1):
+ try:
+ val = dist[c_int(i)].value - last[i]
+ if (val > 0):
+ idx_max = i
+ if (val > val_max):
+ val_max = val
+ except:
+ break
+ if idx_max > 0:
+ print(" %-15s : count distribution" % val_type);
+ for i in range(1, idx_max + 1):
+ low = (1 << i) >> 1
+ high = (1 << i) - 1
+ if (low == high):
+ low -= 1
+ try:
+ val = dist[c_int(i)].value - last[i]
+ print("%8d -> %-8d : %-8d |%-*s|" % (low, high, val,
+ stars_max, stars(val, val_max, stars_max)))
+ last[i] = dist[c_int(i)].value
+ except:
+ break
+
+# output
+loop = 0
+do_exit = 0
+while (1):
+ if count > 0:
+ loop += 1
+ if loop > count:
+ exit()
+ try:
+ sleep(interval)
+ except KeyboardInterrupt:
+ pass; do_exit = 1
+
+ print
+ print_log2_hist(dist, "kbytes")
+ if do_exit:
+ exit()
diff --git a/examples/bitehist_example.txt b/examples/bitehist_example.txt
new file mode 100644
index 0000000..5af66e1
--- /dev/null
+++ b/examples/bitehist_example.txt
@@ -0,0 +1,70 @@
+Demonstrations of bitehist.py, the Linux eBPF/bcc version.
+
+This prints a power-of-2 histogram to show the block I/O size distribution.
+By default, a summary is printed every five seconds:
+
+# ./bitehist.py
+Tracing... Hit Ctrl-C to end.
+
+ kbytes : count distribution
+ 0 -> 1 : 0 | |
+ 2 -> 3 : 0 | |
+ 4 -> 7 : 26 |************* |
+ 8 -> 15 : 3 |* |
+ 16 -> 31 : 5 |** |
+ 32 -> 63 : 6 |*** |
+ 64 -> 127 : 7 |*** |
+ 128 -> 255 : 75 |**************************************|
+
+ kbytes : count distribution
+ 0 -> 1 : 0 | |
+ 2 -> 3 : 0 | |
+ 4 -> 7 : 83 |**************************************|
+ 8 -> 15 : 2 | |
+ 16 -> 31 : 6 |** |
+ 32 -> 63 : 6 |** |
+ 64 -> 127 : 5 |** |
+ 128 -> 255 : 21 |********* |
+^C
+ kbytes : count distribution
+ 0 -> 1 : 0 | |
+ 2 -> 3 : 0 | |
+ 4 -> 7 : 8 |**************************************|
+
+The first output shows a bimodal distribution. The largest mode of 75 I/O were
+between 128 and 255 Kbytes in size, and another mode of 26 I/O were between 4
+and 7 Kbytes in size.
+
+The next output summary shows the workload is doing more 4 - 7 Kbyte I/O.
+
+The final output is partial, showing what was measured until Ctrl-C was hit.
+
+
+For an output interval of one second, and three summaries:
+
+# ./bitehist.py 1 3
+Tracing... Hit Ctrl-C to end.
+
+ kbytes : count distribution
+ 0 -> 1 : 0 | |
+ 2 -> 3 : 0 | |
+ 4 -> 7 : 4 |**************************************|
+
+ kbytes : count distribution
+ 0 -> 1 : 0 | |
+ 2 -> 3 : 0 | |
+ 4 -> 7 : 5 |**************************************|
+ 8 -> 15 : 0 | |
+ 16 -> 31 : 0 | |
+ 32 -> 63 : 1 |******* |
+
+ kbytes : count distribution
+ 0 -> 1 : 0 | |
+ 2 -> 3 : 0 | |
+ 4 -> 7 : 4 |**************************************|
+
+
+Full usage:
+
+# ./bitehist.py -h
+USAGE: ./bitehist.py [interval [count]]
diff --git a/examples/disksnoop.c b/examples/disksnoop.c
new file mode 100644
index 0000000..cd24583
--- /dev/null
+++ b/examples/disksnoop.c
@@ -0,0 +1,48 @@
+/*
+ * disksnoop.c Trace block device I/O: basic version of iosnoop.
+ * For Linux, uses BCC, eBPF. See .py file.
+ *
+ * Copyright (c) 2015 Brendan Gregg.
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of version 2 of the GNU General Public
+ * License as published by the Free Software Foundation.
+ *
+ * 11-Aug-2015 Brendan Gregg Created this.
+ */
+
+#include <uapi/linux/ptrace.h>
+#include "../../linux-4.2-rc5/include/linux/blkdev.h"
+
+struct key_t {
+ struct request *req;
+};
+BPF_TABLE("hash", struct key_t, u64, start, 10240);
+
+int do_request(struct pt_regs *ctx, struct request *req) {
+ struct key_t key = {};
+ u64 ts;
+
+ // stash start timestamp by request ptr
+ ts = bpf_ktime_get_ns();
+ key.req = req;
+ start.update(&key, &ts);
+
+ return 0;
+}
+
+int do_completion(struct pt_regs *ctx, struct request *req) {
+ struct key_t key = {};
+ u64 *tsp, delta;
+
+ key.req = req;
+ tsp = start.lookup(&key);
+
+ if (tsp != 0) {
+ delta = bpf_ktime_get_ns() - *tsp;
+ bpf_trace_printk("%d %x %d\n", req->__data_len,
+ req->cmd_flags, delta / 1000);
+ start.delete(&key);
+ }
+
+ return 0;
+}
diff --git a/examples/disksnoop.py b/examples/disksnoop.py
new file mode 100755
index 0000000..11e5ab6
--- /dev/null
+++ b/examples/disksnoop.py
@@ -0,0 +1,52 @@
+#!/usr/bin/python
+#
+# disksnoop.py Trace block device I/O: basic version of iosnoop.
+# For Linux, uses BCC, eBPF. See .c file.
+#
+# Written as a basic example of tracing latency.
+#
+# Copyright (c) 2015 Brendan Gregg.
+# Licensed under the Apache License, Version 2.0 (the "License")
+#
+# 11-Aug-2015 Brendan Gregg Created this.
+
+from bpf import BPF
+import sys
+
+REQ_WRITE = 1 # from include/linux/blk_types.h
+
+# load BPF program
+b = BPF(src_file="disksnoop.c")
+BPF.attach_kprobe(b.load_func("do_request", BPF.KPROBE), "blk_start_request")
+BPF.attach_kprobe(b.load_func("do_completion", BPF.KPROBE), "blk_update_request")
+
+# header
+print "%-18s %-2s %-7s %8s" % ("TIME(s)", "T", "BYTES", "LAT(ms)")
+
+# open trace pipe
+try:
+ trace = open("/sys/kernel/debug/tracing/trace_pipe", "r")
+except:
+ print >> sys.stderr, "ERROR: opening trace_pipe"
+ exit(1)
+
+# format output
+while 1:
+ try:
+ line = trace.readline().rstrip()
+ except KeyboardInterrupt:
+ pass; exit()
+ prolog, time_s, colon, bytes_s, flags_s, us_s = \
+ line.rsplit(" ", 5)
+
+ time_s = time_s[:-1] # strip trailing ":"
+ flags = int(flags_s, 16)
+ if flags & REQ_WRITE:
+ type_s = "W"
+ elif bytes_s == "0": # see blk_fill_rwbs() for logic
+ type_s = "M"
+ else:
+ type_s = "R"
+ ms = float(int(us_s, 10)) / 1000
+
+ print "%-18s %-2s %-7s %8.2f" % (time_s, type_s, bytes_s, ms)
diff --git a/examples/disksnoop_example.txt b/examples/disksnoop_example.txt
new file mode 100644
index 0000000..8352912
--- /dev/null
+++ b/examples/disksnoop_example.txt
@@ -0,0 +1,40 @@
+Demonstrations of disksnoop.py, the Linux eBPF/bcc version.
+
+
+This traces block I/O, a prints a line to summarize each I/O completed:
+
+# ./disksnoop.py
+TIME(s) T BYTES LAT(ms)
+16458043.435457 W 4096 2.73
+16458043.435981 W 4096 3.24
+16458043.436012 W 4096 3.13
+16458043.437326 W 4096 4.44
+16458044.126545 R 4096 42.82
+16458044.129872 R 4096 3.24
+16458044.130705 R 4096 0.73
+16458044.142813 R 4096 12.01
+16458044.147302 R 4096 4.33
+16458044.148117 R 4096 0.71
+16458044.148950 R 4096 0.70
+16458044.164332 R 4096 15.29
+16458044.168003 R 4096 3.58
+16458044.171676 R 4096 3.59
+16458044.172453 R 4096 0.72
+16458044.173213 R 4096 0.71
+16458044.173989 R 4096 0.72
+16458044.174739 R 4096 0.70
+16458044.190334 R 4096 15.52
+16458044.196608 R 4096 6.17
+16458044.203091 R 4096 6.35
+
+The output includes a basic timestamp (in seconds), the type of I/O (W == write,
+R == read, M == metadata), the size of the I/O in bytes, and the latency (or
+duration) of the I/O in milliseconds.
+
+The latency is measured from I/O request to the device, to the device
+completion. This excludes latency spent queued in the OS.
+
+Most of the I/O in this example were 0.7 and 4 milliseconds in duration. There
+was an outlier of 42.82 milliseconds, a read which followed many writes (the
+high latency may have been caused by the writes still being serviced on the
+storage device).
diff --git a/examples/vfsreadlat.c b/examples/vfsreadlat.c
new file mode 100644
index 0000000..2d3141c
--- /dev/null
+++ b/examples/vfsreadlat.c
@@ -0,0 +1,73 @@
+/*
+ * vfsreadlat.c VFS read latency distribution.
+ * For Linux, uses BCC, eBPF. See .py file.
+ *
+ * Based on eBPF sample tracex2 by Alexi Starovoitov.
+ * Copyright (c) 2013-2015 PLUMgrid, http://plumgrid.com
+ * This program is free software; you can redistribute it and/or
+ * modify it under the terms of version 2 of the GNU General Public
+ * License as published by the Free Software Foundation.
+ *
+ * 15-Aug-2015 Brendan Gregg Created this.
+ */
+
+#include <uapi/linux/ptrace.h>
+
+struct key_t {
+ u32 pid;
+};
+
+BPF_TABLE("hash", struct key_t, u64, start, 10240);
+BPF_TABLE("array", int, u64, dist, 64);
+
+static unsigned int log2(unsigned int v)
+{
+ unsigned int r;
+ unsigned int shift;
+
+ r = (v > 0xFFFF) << 4; v >>= r;
+ shift = (v > 0xFF) << 3; v >>= shift; r |= shift;
+ shift = (v > 0xF) << 2; v >>= shift; r |= shift;
+ shift = (v > 0x3) << 1; v >>= shift; r |= shift;
+ r |= (v >> 1);
+ return r;
+}
+
+static unsigned int log2l(unsigned long v)
+{
+ unsigned int hi = v >> 32;
+ if (hi)
+ return log2(hi) + 32 + 1;
+ else
+ return log2(v) + 1;
+}
+
+int do_entry(struct pt_regs *ctx)
+{
+ struct key_t key = {};
+ u64 ts, *val, zero = 0;
+
+ key.pid = bpf_get_current_pid_tgid();
+ ts = bpf_ktime_get_ns();
+ start.update(&key, &ts);
+ return 0;
+}
+
+int do_return(struct pt_regs *ctx)
+{
+ struct key_t key = {};
+ u64 *tsp, delta;
+
+ key.pid = bpf_get_current_pid_tgid();
+ tsp = start.lookup(&key);
+
+ if (tsp != 0) {
+ delta = bpf_ktime_get_ns() - *tsp;
+ int index = log2l(delta / 1000);
+ u64 *leaf = dist.lookup(&index);
+ if (leaf) (*leaf)++;
+ start.delete(&key);
+ }
+
+ return 0;
+}
diff --git a/examples/vfsreadlat.py b/examples/vfsreadlat.py
new file mode 100755
index 0000000..798ccf1
--- /dev/null
+++ b/examples/vfsreadlat.py
@@ -0,0 +1,110 @@
+#!/usr/bin/python
+#
+# vfsreadlat.py VFS read latency distribution.
+# For Linux, uses BCC, eBPF. See .c file.
+#
+# Written as a basic example of a function latency distribution histogram.
+#
+# USAGE: vfsreadlat.py [interval [count]]
+#
+# The default interval is 5 seconds. A Ctrl-C will print the partially
+# gathered histogram then exit.
+#
+# Copyright (c) 2015 Brendan Gregg.
+# Licensed under the Apache License, Version 2.0 (the "License")
+#
+# 15-Aug-2015 Brendan Gregg Created this.
+
+from bpf import BPF
+from ctypes import c_ushort, c_int, c_ulonglong
+from time import sleep
+from sys import argv
+
+def usage():
+ print("USAGE: %s [interval [count]]" % argv[0])
+ exit()
+
+# arguments
+interval = 5
+count = -1
+if len(argv) > 1:
+ try:
+ interval = int(argv[1])
+ if interval == 0:
+ raise
+ if len(argv) > 2:
+ count = int(argv[2])
+ except: # also catches -h, --help
+ usage()
+
+# load BPF program
+b = BPF(src_file = "vfsreadlat.c")
+BPF.attach_kprobe(b.load_func("do_entry", BPF.KPROBE), "vfs_read")
+BPF.attach_kretprobe(b.load_func("do_return", BPF.KPROBE), "vfs_read")
+dist = b.get_table("dist", c_int, c_ulonglong)
+dist_max = 64
+
+# header
+print("Tracing... Hit Ctrl-C to end.")
+last = {}
+for i in range(1, dist_max + 1):
+ last[i] = 0
+
+# functions
+stars_max = 38
+def stars(val, val_max, width):
+ i = 0
+ text = ""
+ while (1):
+ if (i > (width * val / val_max) - 1) or (i > width - 1):
+ break
+ text += "*"
+ i += 1
+ if val > val_max:
+ text = text[:-1] + "+"
+ return text
+
+def print_log2_hist(d, val_type):
+ idx_max = -1
+ val_max = 0
+ for i in range(1, dist_max + 1):
+ try:
+ val = dist[c_int(i)].value - last[i]
+ if (val > 0):
+ idx_max = i
+ if (val > val_max):
+ val_max = val
+ except:
+ break
+ if idx_max > 0:
+ print(" %-15s : count distribution" % val_type);
+ for i in range(1, idx_max + 1):
+ low = (1 << i) >> 1
+ high = (1 << i) - 1
+ if (low == high):
+ low -= 1
+ try:
+ val = dist[c_int(i)].value - last[i]
+ print("%8d -> %-8d : %-8d |%-*s|" % (low, high, val,
+ stars_max, stars(val, val_max, stars_max)))
+ last[i] = dist[c_int(i)].value
+ except:
+ break
+
+# output
+loop = 0
+do_exit = 0
+while (1):
+ if count > 0:
+ loop += 1
+ if loop > count:
+ exit()
+ try:
+ sleep(interval)
+ except KeyboardInterrupt:
+ pass; do_exit = 1
+
+ print
+ print_log2_hist(dist, "usecs")
+ if do_exit:
+ exit()
diff --git a/examples/vfsreadlat_example.txt b/examples/vfsreadlat_example.txt
new file mode 100644
index 0000000..1d95f6a
--- /dev/null
+++ b/examples/vfsreadlat_example.txt
@@ -0,0 +1,63 @@
+Demonstrations of vfsreadlat.py, the Linux eBPF/bcc version.
+
+
+This example traces the latency of vfs_read (time from call to return), printing
+it as a histogram distribution. By default, output is every five seconds:
+
+# ./vfsreadlat.py
+Tracing... Hit Ctrl-C to end.
+
+ usecs : count distribution
+ 0 -> 1 : 4457 |*************************************+|
+ 2 -> 3 : 447 |*** |
+ 4 -> 7 : 2059 |***************** |
+ 8 -> 15 : 1179 |********** |
+ 16 -> 31 : 63 | |
+ 32 -> 63 : 0 | |
+ 64 -> 127 : 2 | |
+ 128 -> 255 : 0 | |
+ 256 -> 511 : 3 | |
+ 512 -> 1023 : 1 | |
+ 1024 -> 2047 : 3 | |
+ 2048 -> 4095 : 2 | |
+ 4096 -> 8191 : 0 | |
+ 8192 -> 16383 : 0 | |
+ 16384 -> 32767 : 0 | |
+ 32768 -> 65535 : 0 | |
+ 65536 -> 131071 : 4 | |
+ 131072 -> 262143 : 2 | |
+ 262144 -> 524287 : 0 | |
+ 524288 -> 1048575 : 4 | |
+^C
+ usecs : count distribution
+ 0 -> 1 : 241 |*************************************+|
+ 2 -> 3 : 17 |** |
+ 4 -> 7 : 2 | |
+ 8 -> 15 : 4 | |
+ 16 -> 31 : 2 | |
+ 32 -> 63 : 0 | |
+ 64 -> 127 : 1 | |
+ 128 -> 255 : 0 | |
+ 256 -> 511 : 1 | |
+ 512 -> 1023 : 1 | |
+ 1024 -> 2047 : 0 | |
+ 2048 -> 4095 : 1 | |
+ 4096 -> 8191 : 0 | |
+ 8192 -> 16383 : 0 | |
+ 16384 -> 32767 : 0 | |
+ 32768 -> 65535 : 0 | |
+ 65536 -> 131071 : 0 | |
+ 131072 -> 262143 : 0 | |
+ 262144 -> 524287 : 0 | |
+ 524288 -> 1048575 : 1 | |
+
+These examples show outliers in the 524 - 1048 milliseconds range. Since
+vfs_read() will catch many types of events, this could be anything including
+keystroke latency on ssh sessions. Further drilling with bcc will be necessary
+to identify more details.
+
+
+Full usage:
+
+# ./vfsreadlat.py -h
+USAGE: ./vfsreadlat.py [interval [count]]