Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 1 | #!/usr/bin/python |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 2 | # @lint-avoid-python-3-compatibility-imports |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 3 | # |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 4 | # biolatency Summarize block device I/O latency as a histogram. |
| 5 | # For Linux, uses BCC, eBPF. |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 6 | # |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 7 | # USAGE: biolatency [-h] [-T] [-Q] [-m] [-D] [interval] [count] |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 8 | # |
| 9 | # Copyright (c) 2015 Brendan Gregg. |
| 10 | # Licensed under the Apache License, Version 2.0 (the "License") |
| 11 | # |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 12 | # 20-Sep-2015 Brendan Gregg Created this. |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 13 | |
| 14 | from __future__ import print_function |
| 15 | from bcc import BPF |
| 16 | from time import sleep, strftime |
| 17 | import argparse |
| 18 | |
| 19 | # arguments |
| 20 | examples = """examples: |
| 21 | ./biolatency # summarize block I/O latency as a histogram |
| 22 | ./biolatency 1 10 # print 1 second summaries, 10 times |
| 23 | ./biolatency -mT 1 # 1s summaries, milliseconds, and timestamps |
| 24 | ./biolatency -Q # include OS queued time in I/O time |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 25 | ./biolatency -D # show each disk device separately |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 26 | """ |
| 27 | parser = argparse.ArgumentParser( |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 28 | description="Summarize block device I/O latency as a histogram", |
| 29 | formatter_class=argparse.RawDescriptionHelpFormatter, |
| 30 | epilog=examples) |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 31 | parser.add_argument("-T", "--timestamp", action="store_true", |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 32 | help="include timestamp on output") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 33 | parser.add_argument("-Q", "--queued", action="store_true", |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 34 | help="include OS queued time in I/O time") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 35 | parser.add_argument("-m", "--milliseconds", action="store_true", |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 36 | help="millisecond histogram") |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 37 | parser.add_argument("-D", "--disks", action="store_true", |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 38 | help="print a histogram per disk device") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 39 | parser.add_argument("interval", nargs="?", default=99999999, |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 40 | help="output interval, in seconds") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 41 | parser.add_argument("count", nargs="?", default=99999999, |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 42 | help="number of outputs") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 43 | args = parser.parse_args() |
| 44 | countdown = int(args.count) |
| 45 | debug = 0 |
| 46 | |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 47 | # define BPF program |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 48 | bpf_text = """ |
| 49 | #include <uapi/linux/ptrace.h> |
| 50 | #include <linux/blkdev.h> |
| 51 | |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 52 | typedef struct disk_key { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 53 | char disk[DISK_NAME_LEN]; |
| 54 | u64 slot; |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 55 | } disk_key_t; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 56 | BPF_HASH(start, struct request *); |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 57 | STORAGE |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 58 | |
| 59 | // time block I/O |
| 60 | int trace_req_start(struct pt_regs *ctx, struct request *req) |
| 61 | { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 62 | u64 ts = bpf_ktime_get_ns(); |
| 63 | start.update(&req, &ts); |
| 64 | return 0; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 65 | } |
| 66 | |
| 67 | // output |
| 68 | int trace_req_completion(struct pt_regs *ctx, struct request *req) |
| 69 | { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 70 | u64 *tsp, delta; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 71 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 72 | // fetch timestamp and calculate delta |
| 73 | tsp = start.lookup(&req); |
| 74 | if (tsp == 0) { |
| 75 | return 0; // missed issue |
| 76 | } |
| 77 | delta = bpf_ktime_get_ns() - *tsp; |
| 78 | FACTOR |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 79 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 80 | // store as histogram |
| 81 | STORE |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 82 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 83 | start.delete(&req); |
| 84 | return 0; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 85 | } |
| 86 | """ |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 87 | |
| 88 | # code substitutions |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 89 | if args.milliseconds: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 90 | bpf_text = bpf_text.replace('FACTOR', 'delta /= 1000000;') |
| 91 | label = "msecs" |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 92 | else: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 93 | bpf_text = bpf_text.replace('FACTOR', 'delta /= 1000;') |
| 94 | label = "usecs" |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 95 | if args.disks: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 96 | bpf_text = bpf_text.replace('STORAGE', |
| 97 | 'BPF_HISTOGRAM(dist, disk_key_t);') |
| 98 | bpf_text = bpf_text.replace('STORE', |
| 99 | 'disk_key_t key = {.slot = bpf_log2l(delta)}; ' + |
| 100 | 'bpf_probe_read(&key.disk, sizeof(key.disk), ' + |
| 101 | 'req->rq_disk->disk_name); dist.increment(key);') |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 102 | else: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 103 | bpf_text = bpf_text.replace('STORAGE', 'BPF_HISTOGRAM(dist);') |
| 104 | bpf_text = bpf_text.replace('STORE', |
| 105 | 'dist.increment(bpf_log2l(delta));') |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 106 | if debug: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 107 | print(bpf_text) |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 108 | |
| 109 | # load BPF program |
| 110 | b = BPF(text=bpf_text) |
| 111 | if args.queued: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 112 | b.attach_kprobe(event="blk_account_io_start", fn_name="trace_req_start") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 113 | else: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 114 | b.attach_kprobe(event="blk_start_request", fn_name="trace_req_start") |
| 115 | b.attach_kprobe(event="blk_mq_start_request", fn_name="trace_req_start") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 116 | b.attach_kprobe(event="blk_account_io_completion", |
| 117 | fn_name="trace_req_completion") |
| 118 | |
| 119 | print("Tracing block device I/O... Hit Ctrl-C to end.") |
| 120 | |
| 121 | # output |
| 122 | exiting = 0 if args.interval else 1 |
| 123 | dist = b.get_table("dist") |
| 124 | while (1): |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 125 | try: |
| 126 | sleep(int(args.interval)) |
| 127 | except KeyboardInterrupt: |
| 128 | exiting = 1 |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 129 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 130 | print() |
| 131 | if args.timestamp: |
| 132 | print("%-8s\n" % strftime("%H:%M:%S"), end="") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 133 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 134 | dist.print_log2_hist(label, "disk") |
| 135 | dist.clear() |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 136 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 137 | countdown -= 1 |
| 138 | if exiting or countdown == 0: |
| 139 | exit() |