zvol_io_time_histograms.d

zvol_io_time_histograms.d

#!/usr/sbin/dtrace -s

#pragma D option quiet

/*
 * Times (in microseconds) of all zvol I/O functions:
 *  net_lundman_zfs_zvol_device::doAsyncReadWrite
 *  net_lundman_zfs_zvol_device::doUnmap
 *  net_lundman_zfs_zvol_device::doDiscard
 *  zvol_read_iokit
 *  zvol_write_iokit
 *  zvol_unmap
 *
 * (Note: The upstream functions zvol_read() and zvol_write()
 *  are not used by the IOKit implementation)
 */

dtrace:::BEGIN
{
	printf("Tracing for 10 seconds... Hit Ctrl-C to end.\n");
}

tick-10000msec {
	exit(0);
}

fbt::_ZN27net_lundman_zfs_zvol_device16doAsyncReadWriteEP18IOMemoryDescriptoryyP19IOStorageAttributesP19IOStorageCompletion:entry
{
	self->rw_start = vtimestamp;
}

fbt::_ZN27net_lundman_zfs_zvol_device16doAsyncReadWriteEP18IOMemoryDescriptoryyP19IOStorageAttributesP19IOStorageCompletion:return
/(self->rw_start)/
{
	/* Get elapsed time */
	@rw_times = quantize((vtimestamp - self->rw_start)/1000);
}

fbt::zvol_read_iokit:entry
{
	self->read_start = vtimestamp;
}

fbt::zvol_read_iokit:return
/(self->read_start)/
{
	/* Get elapsed time */
	@read_times = quantize((vtimestamp - self->read_start)/1000);
}

fbt::zvol_write_iokit:entry
{
	self->write_start = vtimestamp;
}

fbt::zvol_write_iokit:return
/(self->write_start)/
{
	/* Get elapsed time */
	@write_times = quantize((vtimestamp - self->write_start)/1000);
}

fbt::_ZN27net_lundman_zfs_zvol_device7doUnmapEP26IOBlockStorageDeviceExtentjj:entry
{
	self->dounmap_start = vtimestamp;
}

fbt::_ZN27net_lundman_zfs_zvol_device7doUnmapEP26IOBlockStorageDeviceExtentjj:return
/(self->dounmap_start)/
{
	/* Get elapsed time */
	@dounmap_times = quantize((vtimestamp - self->dounmap_start)/1000);
}

fbt::_ZN27net_lundman_zfs_zvol_device9doDiscardEyy:entry
{
	self->discard_start = vtimestamp;
}

fbt::_ZN27net_lundman_zfs_zvol_device9doDiscardEyy:return
/(self->discard_start)/
{
	/* Get elapsed time */
	@discard_times = quantize((vtimestamp - self->discard_start)/1000);
}

fbt::zvol_unmap:entry
{
	self->unmap_start = vtimestamp;
}

fbt::zvol_unmap:return
/(self->unmap_start)/
{
	/* Get elapsed time */
	@unmap_times = quantize((vtimestamp - self->unmap_start)/1000);
}

dtrace:::END
{
	printf("==============================================================\n");
	printf("\n%s\n", "zvol::doAsyncReadWrite time delta");
	printa("%@d\n", @rw_times);
	printf("==============================================================\n");
	printf("\n%s\n", "zvol_read_iokit time delta");
	printa("%@d\n", @read_times);
	printf("==============================================================\n");
	printf("\n%s\n", "zvol_write_iokit time delta");
	printa("%@d\n", @write_times);
	printf("==============================================================\n");
	printf("\n%s\n", "zvol::doUnmap time delta");
	printa("%@d\n", @dounmap_times);
	printf("==============================================================\n");
	printf("\n%s\n", "zvol::doDiscard time delta");
	printa("%@d\n", @discard_times);
	printf("==============================================================\n");
	printf("\n%s\n", "zvol_unmap time delta");
	printa("%@d\n", @unmap_times);
	printf("==============================================================\n");
}