I was recently helping some colleagues check what was happening with their MySQL queries, and wrote a DTrace script to do it. Time to share that script.

First of all, a look at some output from the script:

mashie[bash]# ./querystat.d -p `pgrep mysqld`
Tracing started at 2009 Sep 17 16:28:35
2009 Sep 17 16:28:38   throughput 3 queries/sec
2009 Sep 17 16:28:41   throughput 4 queries/sec
2009 Sep 17 16:28:44   throughput 528 queries/sec
2009 Sep 17 16:28:47   throughput 1603 queries/sec
2009 Sep 17 16:28:50   throughput 1676 queries/sec
\^C
Tracing ended   at 2009 Sep 17 16:28:51
Average latency, all queries: 107 us
Latency distribution, all queries (us): 
           value  ------------- Distribution ------------- count    
              16 |                                         0        
              32 |@@                                       170      
              64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ …

I recently presented DTrace at Sun's CommunityONE event. My presentation was focused on observing drupal using DTrace. You can see a replay of the presentation here. You can get the presentation here as well.

If you are an AMP (Apache MySQL PHP) stack user on Solaris/OpenSolaris you can benefit from DTrace. Here is a D-Script that will print the load distribution on your system. Think of it as "AMP-top" if you may! This was tested on OpenSolaris 2009.06

#!/usr/sbin/dtrace -qs

BEGIN
{ …

I wrote a small DTrace script to understand InnoDB IO statistics. This script shows statistics about different kinds of Innodb IO requests and how many of them result in actual IO. Sample output is shown below

#./inniostat -h
Usage: inniostat [-h] [-d] [-p pid] [interval]
                 -h : Print this message
                 -p : MySQL PID
                 -d : Dump dtrace script being used

# ./inniostat
 __physical__  ___Innodb___ ____read____     ______write______
   r/s    w/s    r/s    w/s   data    pre    log dblbuf dflush     Time
    24    121     24     50     24      0     50      0      0 16:00:57
    26    130     26     51     26      0     51      0      0 16:00:58
    18    134     18     54     18      0     54      0      0 16:00:59
    25    129     25     51     25      0     51      0      0 16:01:00
    29    116     46     47     17     29     47      0      0 16:01:01
    10    140     10    132     10      0     52      0     80 …

I wrote a small DTrace script to understand InnoDB IO statistics. This script shows statistics about different kinds of Innodb IO requests and how many of them result in actual IO. Sample output is shown below

#./inniostat -h
Usage: inniostat [-h] [-d] [-p pid] [interval]
                 -h : Print this message
                 -p : MySQL PID
                 -d : Dump dtrace script being used

# ./inniostat
 __physical__  ___Innodb___ ____read____     ______write______
   r/s    w/s    r/s    w/s   data    pre    log dblbuf dflush     Time
    24    121     24     50     24      0     50      0      0 16:00:57
    26    130     26     51     26      0     51      0      0 16:00:58
    18    134     18     54     18      0     54      0      0 16:00:59
    25    129     25     51     25      0     51      0      0 16:01:00
    29    116     46     47     17     29     47      0      0 16:01:01
    10    140     10    132     10      0     52      0     80 …

I wrote a small DTrace script to understand InnoDB IO statistics. This script shows statistics about different kinds of Innodb IO requests and how many of them result in actual IO. Sample output is shown below

#./inniostat -h
Usage: inniostat [-h] [-d] [-p pid] [interval]
                 -h : Print this message
                 -p : MySQL PID
                 -d : Dump dtrace script being used

# ./inniostat
 __physical__  ___Innodb___ ____read____     ______write______
   r/s    w/s    r/s    w/s   data    pre    log dblbuf dflush     Time
    24    121     24     50     24      0     50      0      0 16:00:57
    26    130     26     51     26      0     51      0      0 16:00:58
    18    134     18     54     18      0     54      0      0 16:00:59
    25    129     25     51     25      0     51      0      0 16:01:00
    29    116     46     47     17     29     47      0      0 16:01:01
    10    140     10    132     10      0     52      0     80 …

For some reason my presentation slides have not been posted to on MySQL Users Conference site. Here it is, a pdf format of "Introduction to Using DTrace with MySQL".

For some reason my presentation slides have not been posted to on MySQL Users Conference site. Here it is, a pdf format of "Introduction to Using DTrace with MySQL".

For some reason my presentation slides have not been posted to on MySQL Users Conference site. Here it is, a pdf format of "Introduction to Using DTrace with MySQL".

Over the last year there has been alot of work done to instrument MySQL with static dtrace probes. The mysql provider first became available in MySQL 6.0.8 but required a build with the --enable-dtrace flag to enable it. Starting with MySQL 5.4 the mysql provider and it's static probes are now enabled by default and ready to be used on Solaris 10, OpenSolaris and Mac OS X.

The static probes in MySQL 5.4 have been designed to follow the execution path of a query

with the level getting deeper as the query execution proceeds. However the probes are implemented so that you don't have to traverse the entire hierarchy to get the information you want.

They are also implemented in sets. The -start probe exposes pertinent information such as the query text. The -done probe returns the status of the probe operation. With probe sets time spent within an operation can be captured.

Check out MC Brown's …