1#!/usr/bin/env 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 18from __future__ import print_function 19from bcc import BPF, USDT 20import sys 21 22# arguments 23def usage(): 24 print("USAGE: mysqld_qslower PID [min_ms]") 25 exit() 26if len(sys.argv) < 2: 27 usage() 28if sys.argv[1][0:1] == "-": 29 usage() 30pid = int(sys.argv[1]) 31min_ns = 1 * 1000000 32min_ms_text = 1 33if len(sys.argv) == 3: 34 min_ns = float(sys.argv[2]) * 1000000 35 min_ms_text = sys.argv[2] 36debug = 0 37QUERY_MAX = 128 38 39# load BPF program 40bpf_text = """ 41#include <uapi/linux/ptrace.h> 42 43#define QUERY_MAX """ + str(QUERY_MAX) + """ 44 45struct start_t { 46 u64 ts; 47 char *query; 48}; 49 50struct data_t { 51 u32 pid; 52 u64 ts; 53 u64 delta; 54 char query[QUERY_MAX]; 55}; 56 57BPF_HASH(start_tmp, u32, struct start_t); 58BPF_PERF_OUTPUT(events); 59 60int do_start(struct pt_regs *ctx) { 61 u32 tid = bpf_get_current_pid_tgid(); 62 struct start_t start = {}; 63 start.ts = bpf_ktime_get_ns(); 64 bpf_usdt_readarg(1, ctx, &start.query); 65 start_tmp.update(&tid, &start); 66 return 0; 67}; 68 69int do_done(struct pt_regs *ctx) { 70 u64 pid_tgid = bpf_get_current_pid_tgid(); 71 u32 pid = pid_tgid >> 32; 72 u32 tid = (u32)pid_tgid; 73 struct start_t *sp; 74 75 sp = start_tmp.lookup(&tid); 76 if (sp == 0) { 77 // missed tracing start 78 return 0; 79 } 80 81 // check if query exceeded our threshold 82 u64 delta = bpf_ktime_get_ns() - sp->ts; 83 if (delta >= """ + str(min_ns) + """) { 84 // populate and emit data struct 85 struct data_t data = {.pid = pid, .ts = sp->ts, .delta = delta}; 86 bpf_probe_read_user(&data.query, sizeof(data.query), (void *)sp->query); 87 events.perf_submit(ctx, &data, sizeof(data)); 88 } 89 90 start_tmp.delete(&tid); 91 92 return 0; 93}; 94 95""" 96 97# enable USDT probe from given PID 98u = USDT(pid=pid) 99u.enable_probe(probe="query__start", fn_name="do_start") 100u.enable_probe(probe="query__done", fn_name="do_done") 101if debug: 102 print(u.get_text()) 103 print(bpf_text) 104 105# initialize BPF 106b = BPF(text=bpf_text, usdt_contexts=[u]) 107 108# header 109print("Tracing MySQL server queries for PID %d slower than %s ms..." % (pid, 110 min_ms_text)) 111print("%-14s %-7s %8s %s" % ("TIME(s)", "PID", "MS", "QUERY")) 112 113# process event 114start = 0 115def print_event(cpu, data, size): 116 global start 117 event = b["events"].event(data) 118 if start == 0: 119 start = event.ts 120 print("%-14.6f %-7d %8.3f %s" % (float(event.ts - start) / 1000000000, 121 event.pid, float(event.delta) / 1000000, event.query)) 122 123# loop with callback to print_event 124b["events"].open_perf_buffer(print_event, page_cnt=64) 125while 1: 126 try: 127 b.perf_buffer_poll() 128 except KeyboardInterrupt: 129 exit() 130