How long does your IO take?

Rajan Shanmugavelu illustrates how to analyze disk IO latency using DTrace at a more granular level than sar or iostat.

Dynamic Tracing (DTrace) allows one to measure latency at a more granular level like measuring elapsed time at adapter driver layer. With this we can find out where in the whole driver stack more cycles are spent. This can be done on the running Linux kernel without having to install an instrumented driver or requiring a reboot of the system.

Below is an example of DTrace measuring latency in the QLogic FC qla2xxx driver from the time the SCSI command is queued until it is completed from the target. This would measure every IO that is sent down the FC channel. We can also filter for commands that are taking abnormally longer time to complete. We would be interested in SCSI commands that have taken more than 25 milliseconds. Anything less than 15 milliseconds is normal per the SCSI specification standard for a spindle Disk.