Is there a tool like Microsoft's "SQL Server Profiler" for MySQL?

MySQL has never come up with Query Profiling. Now that MySQL is being grandfathered by Oracle, I know this will continue to be the case.

Yet, all hope is not lost.

Since 2007, Percona has come up with some absolutely marvelous tools for everything a Developer and DBA would want, including Query Profiling.

Percona's first set of tools, known as MAATKIT, created a realm for the serious user of MySQL. It features many things, such as:

Query Profiling
Replication Heartbeat
Replication Slave Management
Table Checksum and Synchronization

Percona has recently forked MAATKIT into a more up-to-date set of tools, known today as Percona Toolkit. These tools picked up where MAATKIT left off by expanding the realm of activity for the serious MySQL user to include things such:

Foreign Key Error Checking
Online Schema Changing
Visual Explain Plans
and more ...

Getting back to the original question, the tools out there for query profiling are

pt-query-advisor
pt-query-digest
mk-query-profiler (for MAATKIT users)
mk-query-digest (for MAATKIT users)

Here is an example of the kind of rich information that can come from using one of these tools:

I helped a client implement mk-query-digest to report the 20 worst-performing queries every 20 minutes. I got the idea from this YouTube video. The client would move any bad query's output to memcached thus lowering the incidence of the query's taking a toll on the the database.

Here is the script I made to call mk-query-digest (examing the processlist only)

#!/bin/sh

RUNFILE=/tmp/QueriesAreBeingDigested.txt
if [ -f ${RUNFILE} ] ; then exit ; fi

MKDQ=/usr/local/sbin/mk-query-digest
RUNTIME=${1}
COPIES_TO_KEEP=${2}
DBVIP=${3}

WHICH=/usr/bin/which
DATE=`${WHICH} date`
ECHO=`${WHICH} echo`
HEAD=`${WHICH} head`
TAIL=`${WHICH} tail`
AWK=`${WHICH} awk`
SED=`${WHICH} sed`
CAT=`${WHICH} cat`
WC=`${WHICH} wc`
RM=`${WHICH} rm | ${TAIL} -1 | ${AWK} '{print $1}'`
LS=`${WHICH} ls | ${TAIL} -1 | ${AWK} '{print $1}'`

HAS_THE_DBVIP=`/sbin/ip addr show | grep "scope global secondary" | grep -c "${DBVIP}"`
if [ ${HAS_THE_DBVIP} -eq 1 ] ; then exit ; fi

DT=`${DATE} +"%Y%m%d_%H%M%S"`
UNIQUETAG=`${ECHO} ${SSH_CLIENT}_${SSH_CONNECTION}_${DT} | ${SED} 's/\./ /g' | ${SED} 's/ //g'`

cd /root/QueryDigest
OUTFILE=QP_${DT}.txt
HOSTADDR=${DBVIP}
${MKDQ} --processlist h=${HOSTADDR},u=queryprofiler,p=queryprofiler --run-time=${RUNTIME} > ${OUTFILE}

#
# Rotate out Old Copies
#

QPFILES=QPFiles.txt
QPFILES2ZAP=QPFiles2Zap.txt
${LS} QP_[0-9][0-9][0-9][0-9][0-9][0-9][0-9][0-9]_[0-9][0-9][0-9][0-9][0-9][0-9].txt > ${QPFILES}

LINECOUNT=`${WC} -l < ${QPFILES}`
if [ ${LINECOUNT} -gt ${COPIES_TO_KEEP} ]
then
        (( DIFF = LINECOUNT - COPIES_TO_KEEP ))
        ${HEAD} -${DIFF} < ${QPFILES} > ${QPFILES2ZAP}
        for QPFILETOZAP in `${CAT} ${QPFILES2ZAP}`
        do
                ${RM} ${QPFILETOZAP}
        done
fi

rm -f ${QPFILES2ZAP}
rm -f ${QPFILES}
rm -f ${RUNFILE}

Here is the user I made to connect to mysql using mk-query-digest

GRANT PROCESS ON *.* TO 'queryprofiler'@'%' IDENTIFIED BY 'queryprofiler';

Here is the crontab I ran every 20 minutes (less 10 seconds) keeping the last 144 copies (which is 48 hours of profiling)

*/20 * * * * /root/QueryDigest/ExecQueryDigest.sh 1190s 144 10.1.1.8

The incredible part: The output of mk-query-digest

Here is a profile that ran 2011-12-28 11:20:00 for 1190 sec (20 min less 10 sec)

The last 22 lines

# Rank Query ID           Response time    Calls   R/Call     Item
# ==== ================== ================ ======= ========== ====
#    1 0x5E994008E9543B29    40.3255 11.2%     101   0.399263 SELECT schedule_occurrence schedule_eventschedule schedule_event schedule_eventtype schedule_event schedule_eventtype schedule_occurrence.start
#    2 0x392F6DA628C7FEBD    33.9181  9.4%      17   1.995184 SELECT mt_entry mt_objecttag
#    3 0x6C6318E56E149036    26.4695  7.3%     102   0.259505 SELECT schedule_occurrence schedule_eventschedule schedule_event schedule_eventtype schedule_event schedule_eventtype schedule_occurrence.start
#    4 0x00F66961DAE6FFB2    25.5472  7.1%      55   0.464495 SELECT mt_entry mt_placement mt_category
#    5 0x99E13015BFF1E75E    22.3618  6.2%     199   0.112371 SELECT mt_entry mt_objecttag
#    6 0x84DD09F0FC444677    22.3516  6.2%      39   0.573118 SELECT mt_entry
#    7 0x440EBDBCEDB88725    21.1817  5.9%      36   0.588380 SELECT mt_entry
#    8 0x8D258C584B858811    17.2402  4.8%      37   0.465951 SELECT mt_entry mt_placement mt_category
#    9 0x4E2CB0F4CAFD1400    16.9768  4.7%      40   0.424419 SELECT mt_entry mt_placement mt_category
#   10 0x377E0D0898266FDD    16.6979  4.6%     150   0.111319 SELECT polls_pollquestion mt_category
#   11 0x3B9686D98BB8E054    16.2089  4.5%      32   0.506529 SELECT mt_entry mt_objecttag mt_tag
#   12 0x97F670B604A85608    15.6158  4.3%      34   0.459287 SELECT mt_entry mt_placement mt_category
#   13 0x3F5557DA231225EB    14.4309  4.0%      36   0.400859 SELECT mt_entry mt_placement mt_category
#   14 0x191D660A10738896    13.1220  3.6%      31   0.423290 SELECT mt_entry mt_placement mt_category
#   15 0xF88F7421DD88036D    12.1261  3.4%      61   0.198788 SELECT mt_entry mt_blog mt_objecttag mt_tag mt_author
#   16 0xA909BF76E7051792    10.3971  2.9%      53   0.196172 SELECT mt_entry mt_objecttag mt_tag
#   17 0x3D42D07A335ED983     9.1424  2.5%      20   0.457121 SELECT mt_entry mt_placement mt_category
#   18 0x59F43B57DD43F2BD     9.0533  2.5%      21   0.431111 SELECT mt_entry mt_placement mt_category
#   19 0x7961BD4C76277EB7     8.5564  2.4%      47   0.182052 INSERT UNION UPDATE UNION mt_session
#   20 0x173EB4903F3B6DAC     8.5394  2.4%      22   0.388153 SELECT mt_entry mt_placement mt_category

Notice that this the list of the 20 worst-performing queries based on Query Response Time divided by the Number of Times the query was called.

Looking at Query ID #1, which is 0x5E994008E9543B29, we locate that Query ID in the output file and here is the report for that particular query:

# Query 1: 0.09 QPS, 0.03x concurrency, ID 0x5E994008E9543B29 at byte 0 __
# This item is included in the report because it matches --limit.
#              pct   total     min     max     avg     95%  stddev  median
# Count          4     101
# Exec time      7     40s   303ms      1s   399ms   992ms   198ms   293ms
# Lock time      0       0       0       0       0       0       0       0
# Users                  1      mt
# Hosts                101 10.64.95.73:33750 (1), 10.64.95.73:34452 (1), 10.64.95.73:38440 (1)... 97 more
# Databases              1     mt1
# Time range 1325089201 to 1325090385
# bytes          0 273.60k   2.71k   2.71k   2.71k   2.62k       0   2.62k
# id             4 765.11M   7.57M   7.58M   7.58M   7.29M    0.12   7.29M
# Query_time distribution
#   1us
#  10us
# 100us
#   1ms
#  10ms
# 100ms  ################################################################
#    1s  ######
#  10s+
# Tables
#    SHOW TABLE STATUS FROM `mt1` LIKE 'schedule_occurrence'\G
#    SHOW CREATE TABLE `mt1`.`schedule_occurrence`\G
#    SHOW TABLE STATUS FROM `mt1` LIKE 'schedule_eventschedule'\G
#    SHOW CREATE TABLE `mt1`.`schedule_eventschedule`\G
#    SHOW TABLE STATUS FROM `mt1` LIKE 'schedule_event'\G
#    SHOW CREATE TABLE `mt1`.`schedule_event`\G
#    SHOW TABLE STATUS FROM `mt1` LIKE 'schedule_eventtype'\G
#    SHOW CREATE TABLE `mt1`.`schedule_eventtype`\G
#    SHOW TABLE STATUS FROM `schedule_occurrence` LIKE 'start'\G
#    SHOW CREATE TABLE `schedule_occurrence`.`start`\G
# EXPLAIN
SELECT `schedule_occurrence`.`id`, `schedule_occurrence`.`schedule_id`, `schedule_occurrence`.`event_id`, `schedule_occurrence`.`start`, `schedule_occurrence`.`end`, `schedule_occurrence`.`cancelled`, `schedule_occurrence`.`original_start`, `schedule_occurrence`.`original_end`, `schedule_occurrence`.`all_day`, `schedule_occurrence`.`ongoing`, `schedule_occurrence`.`featured`, `schedule_eventschedule`.`id`, `schedule_eventschedule`.`event_id`, `schedule_eventschedule`.`start`, `schedule_eventschedule`.`end`, `schedule_eventschedule`.`all_day`, `schedule_eventschedule`.`ongoing`, `schedule_eventschedule`.`min_date_calculated`, `schedule_eventschedule`.`max_date_calculated`, `schedule_eventschedule`.`rule`, `schedule_eventschedule`.`end_recurring_period`, `schedule_eventschedule`.`textual_description`, `schedule_event`.`id`, `schedule_event`.`title`, `schedule_event`.`slug`, `schedule_event`.`description`, `schedule_event`.`host_id`, `schedule_event`.`cost`, `schedule_event`.`age_restrictions`, `schedule_event`.`more_info`, `schedule_event`.`photo_id`, `schedule_event`.`contact_email`, `schedule_event`.`event_type_id`, `schedule_event`.`featured`, `schedule_event`.`staff_pick`, `schedule_event`.`futuremost`, `schedule_event`.`creator_id`, `schedule_event`.`created_on`, `schedule_event`.`allow_comments`, `schedule_event`.`mt_entry`, `schedule_eventtype`.`id`, `schedule_eventtype`.`parent_id`, `schedule_eventtype`.`name`, `schedule_eventtype`.`slug`, `schedule_eventtype`.`lft`, `schedule_eventtype`.`rght`, `schedule_eventtype`.`tree_id`, `schedule_eventtype`.`level`, T5.`id`, T5.`title`, T5.`slug`, T5.`description`, T5.`host_id`, T5.`cost`, T5.`age_restrictions`, T5.`more_info`, T5.`photo_id`, T5.`contact_email`, T5.`event_type_id`, T5.`featured`, T5.`staff_pick`, T5.`futuremost`, T5.`creator_id`, T5.`created_on`, T5.`allow_comments`, T5.`mt_entry`, T6.`id`, T6.`parent_id`, T6.`name`, T6.`slug`, T6.`lft`, T6.`rght`, T6.`tree_id`, T6.`level` FROM `schedule_occurrence` INNER JOIN `schedule_eventschedule` ON (`schedule_occurrence`.`schedule_id` = `schedule_eventschedule`.`id`) INNER JOIN `schedule_event` ON (`schedule_eventschedule`.`event_id` = `schedule_event`.`id`) INNER JOIN `schedule_eventtype` ON (`schedule_event`.`event_type_id` = `schedule_eventtype`.`id`) INNER JOIN `schedule_event` T5 ON (`schedule_occurrence`.`event_id` = T5.`id`) INNER JOIN `schedule_eventtype` T6 ON (T5.`event_type_id` = T6.`id`) WHERE (EXTRACT(MONTH FROM `schedule_occurrence`.`start`) = 8 AND EXTRACT(DAY FROM `schedule_occurrence`.`start`) = 6 AND `schedule_occurrence`.`start` BETWEEN '2011-01-01 00:00:00' and '2011-12-31 23:59:59.99') ORDER BY `schedule_occurrence`.`ongoing` ASC, `schedule_occurrence`.`all_day` DESC, `schedule_occurrence`.`start` ASC\G

Although the histogram is text-based, it gives an accurate picture of the query's overall performance, sometimes running over 1 sec, and most of the time between 0.01 and 0.1 seconds. From here, one can proceed to do performance tuning by refactoring the query, placing query results in memcached, adding missing or covering indexes, etc.

CONCLUSION

IMHO If Percona ever placed the profiler tools into a Windows GUI, it would easily rival Microsoft's SQL Server Profiler.

Defense Rests !!!

See also this answer about Jet Profiler for MySQL

No, there is no such tool.

Is there a tool like Microsoft's "SQL Server Profiler" for MySQL?

The incredible part: The output of mk-query-digest

CONCLUSION

Tags:

Mysql

Profiler

Tools

Related

Recent Posts