Collecting data with DTraceTools
DTrace is a sophisticated framework for developing scripts that aid in troubleshooting performance issues on production systems in real-time. You can also use DTrace directly on systems you provision in the MNX Public Cloud through dtracetools.
About the dtracetools package
The dtracetools package is available through the pkgsrc repository and includes several pre-defined DTrace scripts specifically tailored towards common use cases in the MNX Public Cloud. The package is installed by default on all available images in the MNX Public Cloud. All DTrace scripts this package installs are located in /opt/local/bin/
and are prefixed with dtrace-*
.
The initial version of dtracetools first appeared in the 2011Q4 pkgsrc branch. You can install dtracetools from pkgsrc by running this:
pkgin in dtracetools
Helpful DTrace commands
Here are a few helpful DTrace commands you can use to uncover latency issues with MySQL, MongoDB, and PHP.
Viewing MongoDB commands per second
Use dtrace-mongocmd.d
:
# dtrace-mongocmd.d -p `pgrep -x mongod`
dtrace: script '/opt/local/bin/dtrace-mongocmd.d' matched 2 probes
CPU ID FUNCTION:NAME
6 71046 :tick-1s
6 71046 :tick-1s
6 71046 :tick-1s mongo cmds/s: 18
6 71046 :tick-1s mongo cmds/s: 0
6 71046 :tick-1s mongo cmds/s: 0
6 71046 :tick-1s mongo cmds/s: 0
6 71046 :tick-1s mongo cmds/s: 0
6 71046 :tick-1s mongo cmds/s: 0
6 71046 :tick-1s mongo cmds/s: 18
6 71046 :tick-1s mongo cmds/s: 0
6 71046 :tick-1s mongo cmds/s: 0
^C
Viewing MySQL queries longer than one millisecond
Use dtrace-mysql_pid_slow.d
:
# dtrace-mysql_pid_slow.d -p `pgrep -x mysqld` 1
Tracing... Min query time: 1000000 ns.
TIME(ms) CPU(ms) QUERY
91 3 show databases\0
27 0 select * from mysql.user\0
^C
Viewing MySQL query latency in a distribution
Use dtrace-mysql_pid_latency.d
:
# dtrace-mysql_pid_latency.d -p `pgrep -x mysqld`
Tracing PID 10630... Hit Ctrl-C to end.
MySQL queries/second: 1; query latency (ns):
value ------------- Distribution ------------- count
131072 | 0
262144 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
524288 | 0
^C
MySQL queries/second: 1; query latency (ns):
value ------------- Distribution ------------- count
65536 | 0
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
262144 | 0
Viewing MySQL query average execution time
Use dtrace-mysql_pid_avg.d
:
# dtrace-mysql_pid_avg.d -p `pgrep -x mysqld`
Tracing PID 10630...
TIME QUERIES 1+sec_Qs AVG(ms) MAX(ms)
2012 Oct 19 15:23:07 1 0 0 0
2012 Oct 19 15:23:08 1 0 0 0
2012 Oct 19 15:23:09 0 0 0 0
^C
Viewing PHP function call counts
Use dtrace-php_funccalls.d
:
# dtrace-php_funccalls.d
Tracing... Hit Ctrl-C to end.
^C
FILE FUNC CALLS
blah.php blastoff 4
blah.php launch 4
blah.php one 4
blah.php sleep 4
blah.php three 4
blah.php two 4
Viewing PHP function flow
Use dtrace-php_flow.d
:
# dtrace-php_flow.d
TIME(us) -- FUNC
20578568252193 <- sleep
20578568252218 -> launch
20578568252229 -> three
20578568252269 -> two
20578568252282 -> one
20578568252296 -> blastoff
20578568252314 <- blastoff
20578568252320 <- one
20578568252324 <- two
20578568252329 <- three
20578568252333 <- launch
20578568252341 -> sleep