MySQL slow queries caused by filesystem latency

mysql_pid_fslatency_slowlog0.d

#!/usr/sbin/dtrace -s
/*
 * mysqld_pid_fslatency_slowlog0.d  Print slow filesystem I/O events.
 *
 * USAGE: ./mysql_pid_fslatency_slowlog0.d mysqld_PID
 *
 * This traces all mysqld filesystem I/O (including some that may be
 * asynchronous to queries and not causing query latency), and prints
 * those individual I/O taking longer than the MIN_FS_LATENCY_MS tunable.
 *
 * This is a monitoring tool (if Cloud Analytics is not available).
 *
 * TESTED: these pid-provider probes may only work on some mysqld versions.
 *	5.0.51a: ok
 */

#pragma D option quiet

inline int MIN_FS_LATENCY_MS = 1000;

dtrace:::BEGIN
{
	min_ns = MIN_FS_LATENCY_MS * 1000000;
}

pid$1::os_file_read:entry,
pid$1::os_file_write:entry,
pid$1::my_read:entry,
pid$1::my_write:entry
{
	self->start = timestamp;
}

pid$1::os_file_read:return,
pid$1::my_read:return
/self->start && (timestamp - self->start) > min_ns/
{
	this->ms = (timestamp - self->start) / 1000000;
	printf("%Y filesystem read > %d ms: %d ms\n", walltimestamp,
	    MIN_FS_LATENCY_MS, this->ms);
}

pid$1::os_file_write:return,
pid$1::my_write:return
/self->start && (timestamp - self->start) > min_ns/
{
	this->ms = (timestamp - self->start) / 1000000;
	printf("%Y filesystem write > %d ms: %d ms\n", walltimestamp,
	    MIN_FS_LATENCY_MS, this->ms);
}

pid$1::os_file_read:return,
pid$1::os_file_write:return,
pid$1::my_read:return,
pid$1::my_write:return
{
	self->start = 0;
}