Alexey Ivanov | cc01a9c | 2019-01-16 09:50:46 -0800 | [diff] [blame] | 1 | #!/usr/bin/python |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 2 | # |
| 3 | # dbslower Trace MySQL and PostgreSQL queries slower than a threshold. |
| 4 | # |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 5 | # USAGE: dbslower [-v] [-p PID [PID ...]] [-b PATH_TO_BINARY] [-m THRESHOLD] |
| 6 | # {mysql,postgres} |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 7 | # |
| 8 | # By default, a threshold of 1ms is used. Set the threshold to 0 to trace all |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 9 | # queries (verbose). |
| 10 | # |
| 11 | # Script works in two different modes: |
| 12 | # 1) USDT probes, which means it needs MySQL and PostgreSQL built with |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 13 | # USDT (DTrace) support. |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 14 | # 2) uprobe and uretprobe on exported function of binary specified by |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 15 | # PATH_TO_BINARY parameter. (At the moment only MySQL support) |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 16 | # |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 17 | # If no PID or PATH_TO_BINARY is provided, the script attempts to discover |
| 18 | # all MySQL or PostgreSQL database processes and uses USDT probes. |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 19 | # |
| 20 | # Strongly inspired by Brendan Gregg's work on the mysqld_qslower script. |
| 21 | # |
Paul Chaignon | 956ca1c | 2017-03-04 20:07:56 +0100 | [diff] [blame] | 22 | # Copyright 2017, Sasha Goldshtein |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 23 | # Licensed under the Apache License, Version 2.0 |
| 24 | # |
| 25 | # 15-Feb-2017 Sasha Goldshtein Created this. |
| 26 | |
| 27 | from bcc import BPF, USDT |
| 28 | import argparse |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 29 | import re |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 30 | import subprocess |
| 31 | |
| 32 | examples = """examples: |
| 33 | dbslower postgres # trace PostgreSQL queries slower than 1ms |
| 34 | dbslower postgres -p 188 322 # trace specific PostgreSQL processes |
| 35 | dbslower mysql -p 480 -m 30 # trace MySQL queries slower than 30ms |
Paul Chaignon | 956ca1c | 2017-03-04 20:07:56 +0100 | [diff] [blame] | 36 | dbslower mysql -p 480 -v # trace MySQL queries & print the BPF program |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 37 | dbslower mysql -x $(which mysqld) # trace MySQL queries with uprobes |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 38 | """ |
| 39 | parser = argparse.ArgumentParser( |
| 40 | description="", |
| 41 | formatter_class=argparse.RawDescriptionHelpFormatter, |
| 42 | epilog=examples) |
| 43 | parser.add_argument("-v", "--verbose", action="store_true", |
| 44 | help="print the BPF program") |
| 45 | parser.add_argument("db", choices=["mysql", "postgres"], |
| 46 | help="the database engine to use") |
| 47 | parser.add_argument("-p", "--pid", type=int, nargs='*', |
| 48 | dest="pids", metavar="PID", help="the pid(s) to trace") |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 49 | parser.add_argument("-x", "--exe", type=str, |
| 50 | dest="path", metavar="PATH", help="path to binary") |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 51 | parser.add_argument("-m", "--threshold", type=int, default=1, |
| 52 | help="trace queries slower than this threshold (ms)") |
Nathan Scott | cf0792f | 2018-02-02 16:56:50 +1100 | [diff] [blame] | 53 | parser.add_argument("--ebpf", action="store_true", |
| 54 | help=argparse.SUPPRESS) |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 55 | args = parser.parse_args() |
| 56 | |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 57 | threshold_ns = args.threshold * 1000000 |
| 58 | |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 59 | mode = "USDT" |
| 60 | if args.path and not args.pids: |
| 61 | if args.db == "mysql": |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 62 | regex = "\\w+dispatch_command\\w+" |
| 63 | symbols = BPF.get_user_functions_and_addresses(args.path, regex) |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 64 | |
| 65 | if len(symbols) == 0: |
| 66 | print("Can't find function 'dispatch_command' in %s" % (args.path)) |
| 67 | exit(1) |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 68 | |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 69 | (mysql_func_name, addr) = symbols[0] |
| 70 | |
Jerome Marchand | bffd94f | 2018-12-17 17:04:07 +0100 | [diff] [blame] | 71 | if mysql_func_name.find(b'COM_DATA') >= 0: |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 72 | mode = "MYSQL57" |
| 73 | else: |
| 74 | mode = "MYSQL56" |
| 75 | else: |
| 76 | # Placeholder for PostrgeSQL |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 77 | # Look on functions initStringInfo, pgstat_report_activity, EndCommand, |
| 78 | # NullCommand |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 79 | print("Sorry at the moment PostgreSQL supports only USDT") |
| 80 | exit(1) |
| 81 | |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 82 | program = """ |
Sasha Goldshtein | aa124dd | 2017-03-31 17:16:45 -0400 | [diff] [blame] | 83 | #include <uapi/linux/ptrace.h> |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 84 | |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 85 | DEFINE_THRESHOLD |
| 86 | DEFINE_USDT |
| 87 | DEFINE_MYSQL56 |
| 88 | DEFINE_MYSQL57 |
| 89 | |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 90 | struct temp_t { |
| 91 | u64 timestamp; |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 92 | #ifdef USDT |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 93 | char *query; |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 94 | #else |
| 95 | /* |
| 96 | MySQL clears query packet before uretprobe call - so copy query in advance |
| 97 | */ |
| 98 | char query[256]; |
| 99 | #endif //USDT |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 100 | }; |
| 101 | |
| 102 | struct data_t { |
| 103 | u64 pid; |
| 104 | u64 timestamp; |
| 105 | u64 duration; |
| 106 | char query[256]; |
| 107 | }; |
| 108 | |
| 109 | BPF_HASH(temp, u64, struct temp_t); |
| 110 | BPF_PERF_OUTPUT(events); |
| 111 | |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 112 | int query_start(struct pt_regs *ctx) { |
| 113 | |
| 114 | #if defined(MYSQL56) || defined(MYSQL57) |
| 115 | /* |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 116 | Trace only packets with enum_server_command == COM_QUERY |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 117 | */ |
| 118 | #ifdef MYSQL56 |
| 119 | u64 command = (u64) PT_REGS_PARM1(ctx); |
| 120 | #else //MYSQL57 |
| 121 | u64 command = (u64) PT_REGS_PARM3(ctx); |
| 122 | #endif |
| 123 | if (command != 3) return 0; |
| 124 | #endif |
| 125 | |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 126 | struct temp_t tmp = {}; |
| 127 | tmp.timestamp = bpf_ktime_get_ns(); |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 128 | |
| 129 | #if defined(MYSQL56) |
Sumanth Korikkar | 023154c | 2020-04-20 05:54:57 -0500 | [diff] [blame] | 130 | bpf_probe_read_user(&tmp.query, sizeof(tmp.query), (void*) PT_REGS_PARM3(ctx)); |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 131 | #elif defined(MYSQL57) |
| 132 | void* st = (void*) PT_REGS_PARM2(ctx); |
| 133 | char* query; |
Sumanth Korikkar | 023154c | 2020-04-20 05:54:57 -0500 | [diff] [blame] | 134 | bpf_probe_read_user(&query, sizeof(query), st); |
| 135 | bpf_probe_read_user(&tmp.query, sizeof(tmp.query), query); |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 136 | #else //USDT |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 137 | bpf_usdt_readarg(1, ctx, &tmp.query); |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 138 | #endif |
| 139 | |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 140 | u64 pid = bpf_get_current_pid_tgid(); |
| 141 | temp.update(&pid, &tmp); |
| 142 | return 0; |
| 143 | } |
| 144 | |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 145 | int query_end(struct pt_regs *ctx) { |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 146 | struct temp_t *tempp; |
| 147 | u64 pid = bpf_get_current_pid_tgid(); |
| 148 | tempp = temp.lookup(&pid); |
| 149 | if (!tempp) |
| 150 | return 0; |
| 151 | |
| 152 | u64 delta = bpf_ktime_get_ns() - tempp->timestamp; |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 153 | #ifdef THRESHOLD |
| 154 | if (delta >= THRESHOLD) { |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 155 | #endif //THRESHOLD |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 156 | struct data_t data = {}; |
| 157 | data.pid = pid >> 32; // only process id |
| 158 | data.timestamp = tempp->timestamp; |
| 159 | data.duration = delta; |
Sumanth Korikkar | 023154c | 2020-04-20 05:54:57 -0500 | [diff] [blame] | 160 | #if defined(MYSQL56) || defined(MYSQL57) |
Sumanth Korikkar | 7f6066d | 2020-05-20 10:49:56 -0500 | [diff] [blame] | 161 | // We already copied string to the bpf stack. Hence use bpf_probe_read_kernel() |
| 162 | bpf_probe_read_kernel(&data.query, sizeof(data.query), tempp->query); |
Sumanth Korikkar | 023154c | 2020-04-20 05:54:57 -0500 | [diff] [blame] | 163 | #else |
| 164 | // USDT - we didnt copy string to the bpf stack before. |
| 165 | bpf_probe_read_user(&data.query, sizeof(data.query), tempp->query); |
| 166 | #endif |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 167 | events.perf_submit(ctx, &data, sizeof(data)); |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 168 | #ifdef THRESHOLD |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 169 | } |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 170 | #endif //THRESHOLD |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 171 | temp.delete(&pid); |
| 172 | return 0; |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 173 | }; |
| 174 | """.replace("DEFINE_USDT", "#define USDT" if mode == "USDT" else "") \ |
| 175 | .replace("DEFINE_MYSQL56", "#define MYSQL56" if mode == "MYSQL56" else "") \ |
| 176 | .replace("DEFINE_MYSQL57", "#define MYSQL57" if mode == "MYSQL57" else "") \ |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 177 | .replace("DEFINE_THRESHOLD", |
| 178 | "#define THRESHOLD %d" % threshold_ns if threshold_ns > 0 else "") |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 179 | |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 180 | if mode.startswith("MYSQL"): |
| 181 | # Uprobes mode |
| 182 | bpf = BPF(text=program) |
Paul Chaignon | 4601792 | 2017-10-07 11:06:28 +0200 | [diff] [blame] | 183 | bpf.attach_uprobe(name=args.path, sym=mysql_func_name, |
| 184 | fn_name="query_start") |
| 185 | bpf.attach_uretprobe(name=args.path, sym=mysql_func_name, |
| 186 | fn_name="query_end") |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 187 | else: |
| 188 | # USDT mode |
| 189 | if not args.pids or len(args.pids) == 0: |
| 190 | if args.db == "mysql": |
| 191 | args.pids = map(int, subprocess.check_output( |
| 192 | "pidof mysqld".split()).split()) |
| 193 | elif args.db == "postgres": |
| 194 | args.pids = map(int, subprocess.check_output( |
| 195 | "pidof postgres".split()).split()) |
| 196 | |
Jerome Marchand | c9805f4 | 2020-06-10 18:29:11 +0200 | [diff] [blame] | 197 | usdts = list(map(lambda pid: USDT(pid=pid), args.pids)) |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 198 | for usdt in usdts: |
| 199 | usdt.enable_probe("query__start", "query_start") |
| 200 | usdt.enable_probe("query__done", "query_end") |
| 201 | if args.verbose: |
| 202 | print('\n'.join(map(lambda u: u.get_text(), usdts))) |
| 203 | |
| 204 | bpf = BPF(text=program, usdt_contexts=usdts) |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 205 | |
Nathan Scott | cf0792f | 2018-02-02 16:56:50 +1100 | [diff] [blame] | 206 | if args.verbose or args.ebpf: |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 207 | print(program) |
Nathan Scott | cf0792f | 2018-02-02 16:56:50 +1100 | [diff] [blame] | 208 | if args.ebpf: |
| 209 | exit() |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 210 | |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 211 | start = BPF.monotonic_time() |
| 212 | |
| 213 | def print_event(cpu, data, size): |
Xiaozhou Liu | 51d62d3 | 2019-02-15 13:03:05 +0800 | [diff] [blame] | 214 | event = bpf["events"].event(data) |
xingfeng2510 | 03e4948 | 2022-03-17 13:07:16 +0800 | [diff] [blame] | 215 | print("%-14.6f %-7d %8.3f %s" % ( |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 216 | float(event.timestamp - start) / 1000000000, |
swj | 21f2463 | 2019-04-30 20:34:45 +0800 | [diff] [blame] | 217 | event.pid, float(event.duration) / 1000000, event.query)) |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 218 | |
Igor Mazur | 5f7035e | 2017-07-18 10:06:34 +0300 | [diff] [blame] | 219 | if mode.startswith("MYSQL"): |
| 220 | print("Tracing database queries for application %s slower than %d ms..." % |
| 221 | (args.path, args.threshold)) |
| 222 | else: |
| 223 | print("Tracing database queries for pids %s slower than %d ms..." % |
| 224 | (', '.join(map(str, args.pids)), args.threshold)) |
| 225 | |
xingfeng2510 | 03e4948 | 2022-03-17 13:07:16 +0800 | [diff] [blame] | 226 | print("%-14s %-7s %8s %s" % ("TIME(s)", "PID", "MS", "QUERY")) |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 227 | |
Mark Drayton | 5f5687e | 2017-02-20 18:13:03 +0000 | [diff] [blame] | 228 | bpf["events"].open_perf_buffer(print_event, page_cnt=64) |
Sasha Goldshtein | dd37d63 | 2017-02-09 05:44:43 -0500 | [diff] [blame] | 229 | while True: |
Jerome Marchand | 5167127 | 2018-12-19 01:57:24 +0100 | [diff] [blame] | 230 | try: |
| 231 | bpf.perf_buffer_poll() |
| 232 | except KeyboardInterrupt: |
| 233 | exit() |