Problem solve Get help with specific problems with your technologies, process and projects.

Examining MySQL in real time using DTrace

Analyzing your applications from the outside can be inefficient and cumbersome. DTrace helps you understand and debug programs like MySQL by giving a clear internal view of them.

DTrace, the Dynamic Tracing facility currently available on OSes including Mac OS X, FreeBSD, and of course Solaris, provides a unique way to peer into the inner workings of MySQL even when under the most brutal of production workloads.

Contrary to popular belief, MySQL does not need to be modified for DTrace to be effective. One of DTrace's most powerful "providers" (a grouping of observable probes) is the Functional Boundary Tracing (FBT) provider. FBT can see the entry or return of any C function. We combine this with the PID provider to peer into userland processes. We can exploit these capabilities with a basic understanding of the MySQL code.

How do we get to know the MySQL code? There are two ways. The first is to buy a good book such as MySQL Internals. If you're serious about MySQL, you must have a copy of this book. The second is DTrace itself. One of DTrace's greatest features is a pragma option called "flowindent". This function shows entry and return properly indented, forming a logic tree so that you can see what is calling what. In this way we can actually see MySQL's inner monologue, if you will. Every function streams by in real time.

Here is the code itself (mysqlflow.d):


#!/usr/sbin/dtrace -s

#pragma D option flowindent




Put this in a file and make it executable. Here we're using the PID provider to look into the 'mysqld' process. Because we're not specifying a "function" (remember, probe form is PROVIDER:MODULE:FUNCTION:NAME) it is interpreted as a wildcard. Thus we will see all functions. The initial probe names are for entry and return of each function.

When we run this we need to use the DTrace -p flag to specify the process id (PID) of the mysql daemon itself, which we can get conveniently on Solaris via the "pgrep" command:


# ./mysqlflow.d -p `pgrep -x mysqld`
 0  -> sync_array_get_nth_cell       
 0  <- sync_array_get_nth_cell       
 0 <- sync_array_print_long_waits      
 0 -> os_thread_sleep            
 2 <- os_thread_sleep            
 2 -> sync_arr_wake_threads_if_sema_free  
 2  -> sync_array_enter          
 2   -> os_mutex_enter          
 2    -> os_fast_mutex_lock       
 2    <- os_fast_mutex_lock       
 2   <- os_mutex_enter          
 2  <- sync_array_enter          
 2  -> sync_array_exit           
 2   -> os_mutex_exit           
 2    -> os_fast_mutex_unlock      
 2    <- os_fast_mutex_unlock      
 2   <- os_mutex_exit           
 2  <- sync_array_exit           
 2 <- sync_arr_wake_threads_if_sema_free 


Use ^C to end the trace. Just this alone can provide hours of entertainment and enlightenment.

The first thing you'll notice is that InnoDB is very chatty even when the database is idle. A seemingly constant flow of 'sync_array_get_nth_cell()' functions are the result of InnoDB checkpoints.

The example above demonstrates DTrace's ability to watch MySQL functions coming and going in real time, but to be of any use we need to know what's being passed into these functions. We need to look at certain functions and their arguments. We all like to spy, right? What if I told you that without logging into the database or looking at any logs I can see every query that MySQL processes? By tracing an argument of "dispatch_command()" I can do just that.

Here is the script (query_watch.d):


#!/usr/sbin/dtrace -s

#pragma D option quiet

 printf("Query: %s\n", copyinstr(arg2));


Again, save that to a text file and make executable and execute with '-p PID'. Use ^c to stop tracing.


# query_watch.d -p `pgrep -x mysqld`
Query: show tables
Query: select * from Country LIMIT 10
Query: explain user


Because we're able to see queries entering the MySQL dispatcher in real time just watching the queries fly by, we can easily identify patterns and trends. Were you aware that your CRM was executing hundreds of identical queries every second?

For those of you reading this who have just realized the security implications of what I'm teaching you to do, you'll be happy to know that only root (or an explicitly authorized user in Solaris) can run DTrace. If your knee-jerk reaction is to be scared of MySQL on a DTrace capable system, remember that we can use DTrace like this for - Oracle, PostgreSQL, Mozilla or any other application. DTrace sees all. If you've never understood the full power of DTrace, I hope it's sinking in.

Now, lets take this example a little further. Duplicate queries can be a big problem, commonly suggesting poor client-side caching or application logic. Let's use a DTrace aggregation to count up all those queries and report on how many times each query is getting hammered during a given period.

Here is the script (querycounts.d):


#!/usr/sbin/dtrace -s

#pragma D option quiet

    printf("Tracing... Hit Ctrl-C to end.\n");

    @query[copyinstr(arg2)] = count();


When this script is run, it will begin collecting data and won't actually output its report until it completes. The aggregation function count() is filling up @query with the results of arg2 passed to the "dispatch_command" function.


# querycounts.d -p `pgrep -x mysqld`
Tracing... Hit Ctrl-C to end.

 select * from CountryLanguage LIMIT 5  1
 show tables     4
 select * from City    10


Obviously, this example output isn't from a real production system. When using in production, you may expect far more output.

The examples we've covered here are only the tip of an iceburg of possibility. When you combine a good MySQL internals reference book with the ability to watch the flow of functions within MySQL, you'll quickly start to understand it in a way you never imagined possible. With this newfound knowledge you'll be able to leverage DTrace to quickly pierce into parts of the code of production workloads. Then, you'll be able to comprehend behavior that you couldn't do so in any other way.

I hope this puts you on solid footing to go forward. Use it to learn, impress your coworkers or save the day. Happy tracing.

Special thanks to Derek Crudgington.

ABOUT THE AUTHOR: Ben Rockwood is the Director of Systems at the cloud computing. infrastructure company Joyent, Inc. A Solaris expert and Sun evangelist, he lives just outside of the Silicon Valley with his smokin' hot wife, Tamarah, and their 3 children. Read his blog at

Dig Deeper on Linux servers

Start the conversation

Send me notifications when other members comment.

Please create a username to comment.