Home | History | Annotate | Download | only in tools 
      1 #!/usr/bin/python
      2 #
      3 # mysqld_qslower    MySQL server queries slower than a threshold.
      4 #                   For Linux, uses BCC, BPF. Embedded C.
      5 #
      6 # USAGE: mysqld_qslower PID [min_ms]
      7 #
      8 # By default, a threshold of 1.0 ms is used. Set this to 0 ms to trace all
      9 # queries (verbose).
     10 #
     11 # This uses USDT probes, and needs a MySQL server with -DENABLE_DTRACE=1.
     12 #
     13 # Copyright 2016 Netflix, Inc.
     14 # Licensed under the Apache License, Version 2.0 (the "License")
     15 #
     16 # 30-Jul-2016   Brendan Gregg   Created this.
     17 
     18 from __future__ import print_function
     19 from bcc import BPF, USDT
     20 import sys
     21 import ctypes as ct
     22 
     23 # arguments
     24 def usage():
     25     print("USAGE: mysqld_latency PID [min_ms]")
     26     exit()
     27 if len(sys.argv) < 2:
     28     usage()
     29 if sys.argv[1][0:1] == "-":
     30     usage()
     31 pid = int(sys.argv[1])
     32 min_ns = 1 * 1000000
     33 min_ms_text = 1
     34 if len(sys.argv) == 3:
     35     min_ns = float(sys.argv[2]) * 1000000
     36     min_ms_text = sys.argv[2]
     37 debug = 0
     38 QUERY_MAX = 128
     39 
     40 # load BPF program
     41 bpf_text = """
     42 #include <uapi/linux/ptrace.h>
     43 
     44 #define QUERY_MAX	""" + str(QUERY_MAX) + """
     45 
     46 struct start_t {
     47     u64 ts;
     48     char *query;
     49 };
     50 
     51 struct data_t {
     52     u64 pid;
     53     u64 ts;
     54     u64 delta;
     55     char query[QUERY_MAX];
     56 };
     57 
     58 BPF_HASH(start_tmp, u32, struct start_t);
     59 BPF_PERF_OUTPUT(events);
     60 
     61 int do_start(struct pt_regs *ctx) {
     62     u32 pid = bpf_get_current_pid_tgid();
     63     struct start_t start = {};
     64     start.ts = bpf_ktime_get_ns();
     65     bpf_usdt_readarg(1, ctx, &start.query);
     66     start_tmp.update(&pid, &start);
     67     return 0;
     68 };
     69 
     70 int do_done(struct pt_regs *ctx) {
     71     u32 pid = bpf_get_current_pid_tgid();
     72     struct start_t *sp;
     73 
     74     sp = start_tmp.lookup(&pid);
     75     if (sp == 0) {
     76         // missed tracing start
     77         return 0;
     78     }
     79 
     80     // check if query exceeded our threshold
     81     u64 delta = bpf_ktime_get_ns() - sp->ts;
     82     if (delta >= """ + str(min_ns) + """) {
     83         // populate and emit data struct
     84         struct data_t data = {.pid = pid, .ts = sp->ts, .delta = delta};
     85         bpf_probe_read(&data.query, sizeof(data.query), (void *)sp->query);
     86         events.perf_submit(ctx, &data, sizeof(data));
     87     }
     88 
     89     start_tmp.delete(&pid);
     90 
     91     return 0;
     92 };
     93 
     94 """
     95 
     96 # enable USDT probe from given PID
     97 u = USDT(pid=pid)
     98 u.enable_probe(probe="query__start", fn_name="do_start")
     99 u.enable_probe(probe="query__done", fn_name="do_done")
    100 if debug:
    101     print(u.get_text())
    102     print(bpf_text)
    103 
    104 # initialize BPF
    105 b = BPF(text=bpf_text, usdt_contexts=[u])
    106 
    107 # header
    108 print("Tracing MySQL server queries for PID %d slower than %s ms..." % (pid,
    109     min_ms_text))
    110 print("%-14s %-6s %8s %s" % ("TIME(s)", "PID", "MS", "QUERY"))
    111 
    112 class Data(ct.Structure):
    113     _fields_ = [
    114         ("pid", ct.c_ulonglong),
    115         ("ts", ct.c_ulonglong),
    116         ("delta", ct.c_ulonglong),
    117         ("query", ct.c_char * QUERY_MAX)
    118     ]
    119 
    120 # process event
    121 start = 0
    122 def print_event(cpu, data, size):
    123     global start
    124     event = ct.cast(data, ct.POINTER(Data)).contents
    125     if start == 0:
    126         start = event.ts
    127     print("%-14.6f %-6d %8.3f %s" % (float(event.ts - start) / 1000000000,
    128         event.pid, float(event.delta) / 1000000, event.query))
    129 
    130 # loop with callback to print_event
    131 b["events"].open_perf_buffer(print_event, page_cnt=64)
    132 while 1:
    133     b.perf_buffer_poll()
    134