Alexey Ivanov | 777e802 | 2019-01-03 13:46:38 -0800 | [diff] [blame] | 1 | #!/usr/bin/env python |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 2 | # @lint-avoid-python-3-compatibility-imports |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 3 | # |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 4 | # biosnoop Trace block device I/O and print details including issuing PID. |
| 5 | # For Linux, uses BCC, eBPF. |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 6 | # |
| 7 | # This uses in-kernel eBPF maps to cache process details (PID and comm) by I/O |
| 8 | # request, as well as a starting timestamp for calculating I/O latency. |
| 9 | # |
| 10 | # Copyright (c) 2015 Brendan Gregg. |
| 11 | # Licensed under the Apache License, Version 2.0 (the "License") |
| 12 | # |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 13 | # 16-Sep-2015 Brendan Gregg Created this. |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 14 | # 11-Feb-2016 Allan McAleavy updated for BPF_PERF_OUTPUT |
| 15 | |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 16 | from __future__ import print_function |
| 17 | from bcc import BPF |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 18 | import ctypes as ct |
| 19 | import re |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 20 | |
| 21 | # load BPF program |
| 22 | b = BPF(text=""" |
| 23 | #include <uapi/linux/ptrace.h> |
| 24 | #include <linux/blkdev.h> |
| 25 | |
| 26 | struct val_t { |
Brendan Gregg | baebe80 | 2016-02-06 16:45:29 -0800 | [diff] [blame] | 27 | u32 pid; |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 28 | char name[TASK_COMM_LEN]; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 29 | }; |
| 30 | |
mcaleavya | 79f3c34 | 2016-02-12 23:19:11 +0000 | [diff] [blame] | 31 | struct data_t { |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 32 | u32 pid; |
| 33 | u64 rwflag; |
| 34 | u64 delta; |
| 35 | u64 sector; |
| 36 | u64 len; |
| 37 | u64 ts; |
| 38 | char disk_name[DISK_NAME_LEN]; |
| 39 | char name[TASK_COMM_LEN]; |
| 40 | }; |
| 41 | |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 42 | BPF_HASH(start, struct request *); |
Brendan Gregg | baebe80 | 2016-02-06 16:45:29 -0800 | [diff] [blame] | 43 | BPF_HASH(infobyreq, struct request *, struct val_t); |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 44 | BPF_PERF_OUTPUT(events); |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 45 | |
| 46 | // cache PID and comm by-req |
| 47 | int trace_pid_start(struct pt_regs *ctx, struct request *req) |
| 48 | { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 49 | struct val_t val = {}; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 50 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 51 | if (bpf_get_current_comm(&val.name, sizeof(val.name)) == 0) { |
Brendan Gregg | 31cd104 | 2016-02-06 17:19:59 -0800 | [diff] [blame] | 52 | val.pid = bpf_get_current_pid_tgid(); |
Brendan Gregg | baebe80 | 2016-02-06 16:45:29 -0800 | [diff] [blame] | 53 | infobyreq.update(&req, &val); |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 54 | } |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 55 | return 0; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 56 | } |
| 57 | |
| 58 | // time block I/O |
| 59 | int trace_req_start(struct pt_regs *ctx, struct request *req) |
| 60 | { |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 61 | u64 ts; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 62 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 63 | ts = bpf_ktime_get_ns(); |
| 64 | start.update(&req, &ts); |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 65 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 66 | return 0; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -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; |
| 73 | u32 *pidp = 0; |
| 74 | struct val_t *valp; |
Brendan Gregg | af3302d | 2016-08-03 15:15:41 -0700 | [diff] [blame] | 75 | struct data_t data = {}; |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 76 | u64 ts; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 77 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 78 | // fetch timestamp and calculate delta |
| 79 | tsp = start.lookup(&req); |
| 80 | if (tsp == 0) { |
| 81 | // missed tracing issue |
| 82 | return 0; |
| 83 | } |
Brendan Gregg | af3302d | 2016-08-03 15:15:41 -0700 | [diff] [blame] | 84 | ts = bpf_ktime_get_ns(); |
mcaleavya | 79f3c34 | 2016-02-12 23:19:11 +0000 | [diff] [blame] | 85 | data.delta = ts - *tsp; |
| 86 | data.ts = ts / 1000; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 87 | |
Brendan Gregg | baebe80 | 2016-02-06 16:45:29 -0800 | [diff] [blame] | 88 | valp = infobyreq.lookup(&req); |
| 89 | if (valp == 0) { |
mcaleavya | 79f3c34 | 2016-02-12 23:19:11 +0000 | [diff] [blame] | 90 | data.len = req->__data_len; |
Brendan Gregg | af3302d | 2016-08-03 15:15:41 -0700 | [diff] [blame] | 91 | strcpy(data.name, "?"); |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 92 | } else { |
mcaleavya | 79f3c34 | 2016-02-12 23:19:11 +0000 | [diff] [blame] | 93 | data.pid = valp->pid; |
| 94 | data.len = req->__data_len; |
| 95 | data.sector = req->__sector; |
| 96 | bpf_probe_read(&data.name, sizeof(data.name), valp->name); |
Paul Chaignon | f86f7e8 | 2018-06-14 02:20:03 +0200 | [diff] [blame] | 97 | struct gendisk *rq_disk = req->rq_disk; |
mcaleavya | 79f3c34 | 2016-02-12 23:19:11 +0000 | [diff] [blame] | 98 | bpf_probe_read(&data.disk_name, sizeof(data.disk_name), |
Paul Chaignon | f86f7e8 | 2018-06-14 02:20:03 +0200 | [diff] [blame] | 99 | rq_disk->disk_name); |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 100 | } |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 101 | |
Brendan Gregg | 0d4d0bf | 2016-08-24 15:10:05 -0700 | [diff] [blame] | 102 | /* |
| 103 | * The following deals with a kernel version change (in mainline 4.7, although |
| 104 | * it may be backported to earlier kernels) with how block request write flags |
| 105 | * are tested. We handle both pre- and post-change versions here. Please avoid |
| 106 | * kernel version tests like this as much as possible: they inflate the code, |
| 107 | * test, and maintenance burden. |
| 108 | */ |
| 109 | #ifdef REQ_WRITE |
Ryan Leary | bc43a29 | 2017-01-07 15:34:31 -0500 | [diff] [blame] | 110 | data.rwflag = !!(req->cmd_flags & REQ_WRITE); |
| 111 | #elif defined(REQ_OP_SHIFT) |
| 112 | data.rwflag = !!((req->cmd_flags >> REQ_OP_SHIFT) == REQ_OP_WRITE); |
Brendan Gregg | 0d4d0bf | 2016-08-24 15:10:05 -0700 | [diff] [blame] | 113 | #else |
Ryan Leary | bc43a29 | 2017-01-07 15:34:31 -0500 | [diff] [blame] | 114 | data.rwflag = !!((req->cmd_flags & REQ_OP_MASK) == REQ_OP_WRITE); |
Brendan Gregg | 0d4d0bf | 2016-08-24 15:10:05 -0700 | [diff] [blame] | 115 | #endif |
Brendan Gregg | 0d4d0bf | 2016-08-24 15:10:05 -0700 | [diff] [blame] | 116 | |
Brendan Gregg | af3302d | 2016-08-03 15:15:41 -0700 | [diff] [blame] | 117 | events.perf_submit(ctx, &data, sizeof(data)); |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 118 | start.delete(&req); |
Brendan Gregg | baebe80 | 2016-02-06 16:45:29 -0800 | [diff] [blame] | 119 | infobyreq.delete(&req); |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 120 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 121 | return 0; |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 122 | } |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 123 | """, debug=0) |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 124 | b.attach_kprobe(event="blk_account_io_start", fn_name="trace_pid_start") |
Jerome Marchand | 74e25ed | 2018-12-10 08:54:50 +0100 | [diff] [blame] | 125 | if BPF.get_kprobe_functions(b'blk_start_request'): |
| 126 | b.attach_kprobe(event="blk_start_request", fn_name="trace_req_start") |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 127 | b.attach_kprobe(event="blk_mq_start_request", fn_name="trace_req_start") |
| 128 | b.attach_kprobe(event="blk_account_io_completion", |
| 129 | fn_name="trace_req_completion") |
| 130 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 131 | TASK_COMM_LEN = 16 # linux/sched.h |
| 132 | DISK_NAME_LEN = 32 # linux/genhd.h |
| 133 | |
| 134 | class Data(ct.Structure): |
| 135 | _fields_ = [ |
| 136 | ("pid", ct.c_ulonglong), |
| 137 | ("rwflag", ct.c_ulonglong), |
| 138 | ("delta", ct.c_ulonglong), |
| 139 | ("sector", ct.c_ulonglong), |
| 140 | ("len", ct.c_ulonglong), |
| 141 | ("ts", ct.c_ulonglong), |
| 142 | ("disk_name", ct.c_char * DISK_NAME_LEN), |
| 143 | ("name", ct.c_char * TASK_COMM_LEN) |
| 144 | ] |
Brendan Gregg | af3302d | 2016-08-03 15:15:41 -0700 | [diff] [blame] | 145 | |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 146 | # header |
| 147 | print("%-14s %-14s %-6s %-7s %-2s %-9s %-7s %7s" % ("TIME(s)", "COMM", "PID", |
| 148 | "DISK", "T", "SECTOR", "BYTES", "LAT(ms)")) |
| 149 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 150 | rwflg = "" |
Brendan Gregg | 5be5194 | 2015-09-16 15:09:04 -0700 | [diff] [blame] | 151 | start_ts = 0 |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 152 | prev_ts = 0 |
| 153 | delta = 0 |
mcaleavya | 62c6152 | 2016-02-12 23:43:14 +0000 | [diff] [blame] | 154 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 155 | # process event |
| 156 | def print_event(cpu, data, size): |
| 157 | event = ct.cast(data, ct.POINTER(Data)).contents |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 158 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 159 | val = -1 |
| 160 | global start_ts |
| 161 | global prev_ts |
| 162 | global delta |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 163 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 164 | if event.rwflag == 1: |
| 165 | rwflg = "W" |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 166 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 167 | if event.rwflag == 0: |
| 168 | rwflg = "R" |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 169 | |
Brenden Blanco | aa85f33 | 2016-03-08 10:07:51 -0800 | [diff] [blame] | 170 | if not re.match(b'\?', event.name): |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 171 | val = event.sector |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 172 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 173 | if start_ts == 0: |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 174 | prev_ts = start_ts |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 175 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 176 | if start_ts == 1: |
| 177 | delta = float(delta) + (event.ts - prev_ts) |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 178 | |
Alexei Starovoitov | a79da0a | 2016-01-09 12:06:40 -0800 | [diff] [blame] | 179 | print("%-14.9f %-14.14s %-6s %-7s %-2s %-9s %-7s %7.2f" % ( |
jeromemarchand | b96ebcd | 2018-10-10 01:58:15 +0200 | [diff] [blame] | 180 | delta / 1000000, event.name.decode('utf-8', 'replace'), event.pid, |
| 181 | event.disk_name.decode('utf-8', 'replace'), rwflg, val, |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 182 | event.len, float(event.delta) / 1000000)) |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 183 | |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 184 | prev_ts = event.ts |
| 185 | start_ts = 1 |
mcaleavya | 6e789ab | 2016-02-12 23:06:53 +0000 | [diff] [blame] | 186 | |
mcaleavya | 62c6152 | 2016-02-12 23:43:14 +0000 | [diff] [blame] | 187 | # loop with callback to print_event |
Mark Drayton | 5f5687e | 2017-02-20 18:13:03 +0000 | [diff] [blame] | 188 | b["events"].open_perf_buffer(print_event, page_cnt=64) |
mcaleavya | ee5f823 | 2016-02-12 20:06:38 +0000 | [diff] [blame] | 189 | while 1: |
Jerome Marchand | 5167127 | 2018-12-19 01:57:24 +0100 | [diff] [blame] | 190 | try: |
| 191 | b.perf_buffer_poll() |
| 192 | except KeyboardInterrupt: |
| 193 | exit() |