Brendan Gregg | d602d6b | 2016-08-01 16:18:40 -0700 | [diff] [blame] | 1 | Demonstrations of mysqld_qslower, the Linux eBPF/bcc version. |
| 2 | |
| 3 | |
| 4 | mysqld_qslower traces queries served by a MySQL server, and prints those that |
| 5 | exceed a latency (query time) threshold. By default a threshold of 1 ms is |
| 6 | used. For example: |
| 7 | |
| 8 | # ./mysqld_qslower.py `pgrep -n mysqld` |
| 9 | Tracing MySQL server queries for PID 14371 slower than 1 ms... |
| 10 | TIME(s) PID MS QUERY |
| 11 | 0.000000 18608 130.751 SELECT * FROM words WHERE word REGEXP '^bre.*n$' |
| 12 | 2.921535 18608 130.590 SELECT * FROM words WHERE word REGEXP '^alex.*$' |
| 13 | 4.603549 18608 24.164 SELECT COUNT(*) FROM words |
| 14 | 9.733847 18608 130.936 SELECT count(*) AS count FROM words WHERE word REGEXP '^bre.*n$' |
| 15 | 17.864776 18608 130.298 SELECT * FROM words WHERE word REGEXP '^bre.*n$' ORDER BY word |
| 16 | |
| 17 | This traced 5 queries, 4 of which took about 130 milliseconds. |
| 18 | |
| 19 | A pgrep command was used to specify the PID of mysqld. |
| 20 | |
| 21 | |
| 22 | In this example, a lower threshold is used of 0.1 ms: |
| 23 | |
| 24 | # ./mysqld_qslower.py `pgrep -n mysqld` 0.1 |
| 25 | Tracing MySQL server queries for PID 14371 slower than 0.1 ms... |
| 26 | TIME(s) PID MS QUERY |
| 27 | 0.000000 18608 24.201 SELECT COUNT(*) FROM words |
| 28 | 13.242390 18608 130.378 SELECT * FROM words WHERE word REGEXP '^bre.*n$' |
| 29 | 23.601751 18608 119.198 SELECT * FROM words WHERE word REGEXP '^zzzzzzzz$' |
| 30 | |
| 31 | It worked, but I'm not catching any faster queries in this example. Notice I |
| 32 | added a query that searched for "zzzzzzzz": it returned an empty set, and ran |
| 33 | 11 ms faster. |
| 34 | |
| 35 | |
| 36 | A 0 ms threshold can be specified to trace all queries: |
| 37 | |
| 38 | # ./mysqld_qslower.py `pgrep -n mysqld` 0 |
| 39 | Tracing MySQL server queries for PID 14371 slower than 0 ms... |
| 40 | TIME(s) PID MS QUERY |
| 41 | 0.000000 18608 0.105 select @@version_comment limit 1 |
| 42 | 2.049312 18608 0.099 SELECT DATABASE() |
| 43 | 2.050666 18608 0.274 show databases |
| 44 | 2.051040 18608 0.176 show tables |
| 45 | 5.730044 18608 130.365 SELECT count(*) AS count FROM words WHERE word REGEXP '^bre.*n$' |
| 46 | 9.273837 18608 0.096 select 1 |
| 47 | 9.553742 18608 0.059 select 1 |
| 48 | 9.986087 18608 0.080 select 1 |
| 49 | |
| 50 | This includes an initialization of a mysql client command, and selecting the |
| 51 | database. I also added some "select 1;" queries, which do no work and return |
| 52 | quickly. |
| 53 | |
| 54 | |
| 55 | USAGE: |
| 56 | |
| 57 | # ./mysqld_qslower.py -h |
| 58 | USAGE: mysqld_latency PID [min_ms] |