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 | # |
Nathan Scott | f5fb9af | 2018-01-17 09:39:59 +1100 | [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, |
Nathan Scott | 1a197db | 2018-01-21 09:14:27 +1100 | [diff] [blame] | 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") |
Nathan Scott | f5fb9af | 2018-01-17 09:39:59 +1100 | [diff] [blame] | 43 | parser.add_argument("--ebpf", action="store_true", |
| 44 | help=argparse.SUPPRESS) |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 45 | args = parser.parse_args() |
| 46 | countdown = int(args.count) |
| 47 | debug = 0 |
| 48 | |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 49 | # define BPF program |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 50 | bpf_text = """ |
| 51 | #include <uapi/linux/ptrace.h> |
| 52 | #include <linux/blkdev.h> |
| 53 | |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 54 | typedef struct disk_key { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 55 | char disk[DISK_NAME_LEN]; |
| 56 | u64 slot; |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 57 | } disk_key_t; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 58 | BPF_HASH(start, struct request *); |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 59 | STORAGE |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 60 | |
| 61 | // time block I/O |
| 62 | int trace_req_start(struct pt_regs *ctx, struct request *req) |
| 63 | { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 64 | u64 ts = bpf_ktime_get_ns(); |
| 65 | start.update(&req, &ts); |
| 66 | return 0; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 67 | } |
| 68 | |
| 69 | // output |
| 70 | int trace_req_completion(struct pt_regs *ctx, struct request *req) |
| 71 | { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 72 | u64 *tsp, delta; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 73 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 74 | // fetch timestamp and calculate delta |
| 75 | tsp = start.lookup(&req); |
| 76 | if (tsp == 0) { |
| 77 | return 0; // missed issue |
| 78 | } |
| 79 | delta = bpf_ktime_get_ns() - *tsp; |
| 80 | FACTOR |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 81 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 82 | // store as histogram |
| 83 | STORE |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 84 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 85 | start.delete(&req); |
| 86 | return 0; |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 87 | } |
| 88 | """ |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 89 | |
| 90 | # code substitutions |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 91 | if args.milliseconds: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 92 | bpf_text = bpf_text.replace('FACTOR', 'delta /= 1000000;') |
| 93 | label = "msecs" |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 94 | else: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 95 | bpf_text = bpf_text.replace('FACTOR', 'delta /= 1000;') |
| 96 | label = "usecs" |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 97 | if args.disks: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 98 | bpf_text = bpf_text.replace('STORAGE', |
| 99 | 'BPF_HISTOGRAM(dist, disk_key_t);') |
| 100 | bpf_text = bpf_text.replace('STORE', |
| 101 | 'disk_key_t key = {.slot = bpf_log2l(delta)}; ' + |
| 102 | 'bpf_probe_read(&key.disk, sizeof(key.disk), ' + |
| 103 | 'req->rq_disk->disk_name); dist.increment(key);') |
Brendan Gregg | 44e6877 | 2015-09-25 13:20:16 -0700 | [diff] [blame] | 104 | else: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 105 | bpf_text = bpf_text.replace('STORAGE', 'BPF_HISTOGRAM(dist);') |
| 106 | bpf_text = bpf_text.replace('STORE', |
| 107 | 'dist.increment(bpf_log2l(delta));') |
Nathan Scott | ca4ba55 | 2018-01-16 11:02:58 +1100 | [diff] [blame] | 108 | if debug or args.ebpf: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 109 | print(bpf_text) |
Nathan Scott | ca4ba55 | 2018-01-16 11:02:58 +1100 | [diff] [blame] | 110 | if args.ebpf: |
| 111 | exit() |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 112 | |
| 113 | # load BPF program |
| 114 | b = BPF(text=bpf_text) |
| 115 | if args.queued: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 116 | 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] | 117 | else: |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 118 | b.attach_kprobe(event="blk_start_request", fn_name="trace_req_start") |
| 119 | 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] | 120 | b.attach_kprobe(event="blk_account_io_completion", |
| 121 | fn_name="trace_req_completion") |
| 122 | |
| 123 | print("Tracing block device I/O... Hit Ctrl-C to end.") |
| 124 | |
| 125 | # output |
| 126 | exiting = 0 if args.interval else 1 |
| 127 | dist = b.get_table("dist") |
| 128 | while (1): |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 129 | try: |
| 130 | sleep(int(args.interval)) |
| 131 | except KeyboardInterrupt: |
| 132 | exiting = 1 |
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 | print() |
| 135 | if args.timestamp: |
| 136 | print("%-8s\n" % strftime("%H:%M:%S"), end="") |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 137 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 138 | dist.print_log2_hist(label, "disk") |
| 139 | dist.clear() |
Brendan Gregg | 9fa1562 | 2015-09-21 15:51:11 -0700 | [diff] [blame] | 140 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 141 | countdown -= 1 |
| 142 | if exiting or countdown == 0: |
| 143 | exit() |