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