ioping 0.7 does microseconds!?

[Damian]

Needed to download ioping for a new install and noticed that there was an 0.7 version out and about. 

Apparently it does microseconds now, instead of calling it 0.1 milliseconds:

4.0 kb from /vz (ext4 /dev/sda5): request=1 time=48 us

4.0 kb from /vz (ext4 /dev/sda5): request=2 time=76 us

4.0 kb from /vz (ext4 /dev/sda5): request=3 time=72 us

4.0 kb from /vz (ext4 /dev/sda5): request=4 time=60 us

4.0 kb from /vz (ext4 /dev/sda5): request=5 time=64 us

4.0 kb from /vz (ext4 /dev/sda5): request=6 time=71 us

4.0 kb from /vz (ext4 /dev/sda5): request=7 time=78 us

4.0 kb from /vz (ext4 /dev/sda5): request=8 time=71 us

4.0 kb from /vz (ext4 /dev/sda5): request=9 time=69 us

4.0 kb from /vz (ext4 /dev/sda5): request=10 time=68 us

 

--- /vz (ext4 /dev/sda5) ioping statistics ---

10 requests completed in 9.0 s, 14.8 k iops, 57.7 mb/s

min/avg/max/mdev = 48 us / 67 us / 78 us / 8 us

Crazy! Looks like it was released in July, so I might just be a bit late to the party otherwise.

 

[Deleted]

One of the 'cavets' to doing latency calculations on Linux with I/O is that, for example, ioping has the following section of code. (Linux has a shared ELF page at the top of the stack that caches lookups for time and a few other syscalls so you'll never be able to know the true amount>. Only way to really measure it is to use rdtsc() in a loop and measure CPU ticks, otherwise you'll get 'low' results. Find it interesting that you're seeing 60uS, on my drives without any crazy caching or time stuff I'm seeing triple that.)

long long now(void)
{
struct timeval tv;
 
if (gettimeofday(&tv, NULL))
err(3, "gettimeofday failed");
 
return tv.tv_sec * 1000000ll + tv.tv_usec;
}

 

[Damian]

 Find it interesting that you're seeing 60uS, on my drives without any crazy caching or time stuff I'm seeing triple that.)

Some random other servers. Here's our last RAID 5 server:

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=1 time=134 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=2 time=180 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=3 time=170 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=4 time=169 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=5 time=167 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=6 time=168 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=7 time=170 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=8 time=175 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=9 time=171 us

4.0 kb from /vz (ext4 /dev/mapper/vg_sapphire-home): request=10 time=168 us

 

--- /vz (ext4 /dev/mapper/vg_sapphire-home) ioping statistics ---

10 requests completed in 9.0 s, 6.0 k iops, 23.4 mb/s

min/avg/max/mdev = 134 us / 167 us / 180 us / 11 us

Here's SSD cached:

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=1 time=52 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=2 time=64 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=3 time=77 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=4 time=68 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=5 time=68 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=6 time=82 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=7 time=60 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=8 time=66 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=9 time=61 us

4.0 kb from / (ext4 /dev/mapper/vg_ipx8-root): request=10 time=58 us

 

--- / (ext4 /dev/mapper/vg_ipx8-root) ioping statistics ---

10 requests completed in 9.0 s, 15.2 k iops, 59.5 mb/s

min/avg/max/mdev = 52 us / 65 us / 82 us / 8 us

And the server I posted initially isn't SSD cached but has a heavy-duty RAID card in it. So it seems to be pretty random.

 

[drmike]

Really nice to see ioping supporting these actual lower that millisecond times (finally).

Great info from @Monkburger.