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