tools/dbslower.py

   1 #!/usr/bin/python
   2 #
   3 # dbslower      Trace MySQL and PostgreSQL queries slower than a threshold.
   4 #
   5 # USAGE: dbslower [-v] [-p PID [PID ...]] [-m THRESHOLD] {mysql,postgres}
   6 #
   7 # By default, a threshold of 1ms is used. Set the threshold to 0 to trace all
   8 # queries (verbose). If no PID is provided, the script attempts to discover
   9 # all MySQL or PostgreSQL database processes.
  10 #
  11 # This tool uses USDT probes, which means it needs MySQL and PostgreSQL built
  12 # with USDT (DTrace) support.
  13 #
  14 # Strongly inspired by Brendan Gregg's work on the mysqld_qslower script.
  15 #
  16 # Copyright 2017, Sasha Goldshtein
  17 # Licensed under the Apache License, Version 2.0
  18 #
  19 # 15-Feb-2017   Sasha Goldshtein   Created this.
  20
  21 from bcc import BPF, USDT
  22 import argparse
  23 import ctypes as ct
  24 import subprocess
  25
  26 examples = """examples:
  27     dbslower postgres            # trace PostgreSQL queries slower than 1ms
  28     dbslower postgres -p 188 322 # trace specific PostgreSQL processes
  29     dbslower mysql -p 480 -m 30  # trace MySQL queries slower than 30ms
  30     dbslower mysql -p 480 -v     # trace MySQL queries & print the BPF program
  31 """
  32 parser = argparse.ArgumentParser(
  33     description="",
  34     formatter_class=argparse.RawDescriptionHelpFormatter,
  35     epilog=examples)
  36 parser.add_argument("-v", "--verbose", action="store_true",
  37     help="print the BPF program")
  38 parser.add_argument("db", choices=["mysql", "postgres"],
  39     help="the database engine to use")
  40 parser.add_argument("-p", "--pid", type=int, nargs='*',
  41     dest="pids", metavar="PID", help="the pid(s) to trace")
  42 parser.add_argument("-m", "--threshold", type=int, default=1,
  43     help="trace queries slower than this threshold (ms)")
  44 args = parser.parse_args()
  45
  46 if not args.pids or len(args.pids) == 0:
  47     if args.db == "mysql":
  48         args.pids = map(int, subprocess.check_output(
  49                                         "pidof mysqld".split()).split())
  50     elif args.db == "postgres":
  51         args.pids = map(int, subprocess.check_output(
  52                                         "pidof postgres".split()).split())
  53
  54 threshold_ns = args.threshold * 1000000
  55
  56 program = """
  57 #include <uapi/linux/ptrace.h>
  58
  59 struct temp_t {
  60     u64 timestamp;
  61     char *query;
  62 };
  63
  64 struct data_t {
  65     u64 pid;
  66     u64 timestamp;
  67     u64 duration;
  68     char query[256];
  69 };
  70
  71 BPF_HASH(temp, u64, struct temp_t);
  72 BPF_PERF_OUTPUT(events);
  73
  74 int probe_start(struct pt_regs *ctx) {
  75     struct temp_t tmp = {};
  76     tmp.timestamp = bpf_ktime_get_ns();
  77     bpf_usdt_readarg(1, ctx, &tmp.query);
  78     u64 pid = bpf_get_current_pid_tgid();
  79     temp.update(&pid, &tmp);
  80     return 0;
  81 }
  82
  83 int probe_end(struct pt_regs *ctx) {
  84     struct temp_t *tempp;
  85     u64 pid = bpf_get_current_pid_tgid();
  86     tempp = temp.lookup(&pid);
  87     if (!tempp)
  88         return 0;
  89
  90     u64 delta = bpf_ktime_get_ns() - tempp->timestamp;
  91     if (delta >= """ + str(threshold_ns) + """) {
  92         struct data_t data = {};
  93         data.pid = pid >> 32;   // only process id
  94         data.timestamp = tempp->timestamp;
  95         data.duration = delta;
  96         bpf_probe_read(&data.query, sizeof(data.query), tempp->query);
  97         events.perf_submit(ctx, &data, sizeof(data));
  98     }
  99     temp.delete(&pid);
 100     return 0;
 101 }
 102 """
 103
 104 usdts = map(lambda pid: USDT(pid=pid), args.pids)
 105 for usdt in usdts:
 106     usdt.enable_probe("query__start", "probe_start")
 107     usdt.enable_probe("query__done", "probe_end")
 108
 109 if args.verbose:
 110     print('\n'.join(map(lambda u: u.get_text(), usdts)))
 111     print(program)
 112
 113 bpf = BPF(text=program, usdt_contexts=usdts)
 114
 115 class Data(ct.Structure):
 116     _fields_ = [
 117         ("pid", ct.c_ulonglong),
 118         ("timestamp", ct.c_ulonglong),
 119         ("delta", ct.c_ulonglong),
 120         ("query", ct.c_char * 256)
 121     ]
 122
 123 start = BPF.monotonic_time()
 124
 125 def print_event(cpu, data, size):
 126     event = ct.cast(data, ct.POINTER(Data)).contents
 127     print("%-14.6f %-6d %8.3f %s" % (
 128         float(event.timestamp - start) / 1000000000,
 129         event.pid, float(event.delta) / 1000000, event.query))
 130
 131 print("Tracing database queries for pids %s slower than %d ms..." %
 132       (', '.join(map(str, args.pids)), args.threshold))
 133 print("%-14s %-6s %8s %s" % ("TIME(s)", "PID", "MS", "QUERY"))
 134
 135 bpf["events"].open_perf_buffer(print_event, page_cnt=64)
 136 while True:
 137     bpf.kprobe_poll()