linux-kernel - Higher than expected disk write(2) latency

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [thread-next>] [day] [month] [year] [list]

Message-ID: <20080628121131.GA14181@nodbug.moloch.sk>
Date:	Sat, 28 Jun 2008 14:11:32 +0200
From:	Martin Lucina <mato@...elna.sk>
To:	linux-kernel@...r.kernel.org
Cc:	Martin Sustrik <sustrik@...tmq.com>
Subject: Higher than expected disk write(2) latency

Hi,

we're getting some rather high figures for write(2) latency when testing
synchronous writing to disk.  The test I'm running writes 2000 blocks of
contiguous data to a raw device, using O_DIRECT and various block sizes
down to a minimum of 512 bytes.  

The disk is a Seagate ST380817AS SATA connected to an Intel ICH7
using ata_piix.  Write caching has been explicitly disabled on the
drive, and there is no other activity that should affect the test
results (all system filesystems are on a separate drive).  The system is
running Debian etch, with a 2.6.24 kernel.

Observed results:

size=1024, N=2000, took=4.450788 s, thput=3 mb/s seekc=1
write: avg=8.388851 max=24.998846 min=8.335624 ms
8 ms: 1992 cases
9 ms: 2 cases
10 ms: 1 cases
14 ms: 1 cases
16 ms: 3 cases
24 ms: 1 cases

size=512, N=2000, took=4.401289 s, thput=1 mb/s seekc=1
write: avg=8.364283 max=16.692206 min=2.010072 ms
2 ms: 1 cases
7 ms: 1 cases
8 ms: 1995 cases
16 ms: 3 cases

Measurement of the write(2) time is performed using the TSC, so any
latency there is negligible.

The datasheet for the drive being used gives the following figures:

Average latency (msec): 4.16
Track-to-track seek time (msec typical): <1.2 (write)
Average seek, write (msec typical): 9.5

If these figures are to be believed, then why are we seeing latencies of
8.3 msec?  Is this normal?  Or are we just being overly optimistic in
our performance expectations?

What we find suspicious is that the latency we see is so close to the
Average seek latency specified for the drive, almost as if the drive was
performing a seek on every write.

For comparison, here are the results of the same test with the disk
write cache *enabled*:

size=1024, N=2000, took=0.296284 s, thput=55 mb/s seekc=1
write: avg=0.147745 max=0.606990 min=0.117246 ms
0 ms: 2000 cases

size=512, N=2000, took=0.304614 s, thput=26 mb/s seekc=1
write: avg=0.152089 max=0.533234 min=0.125370 ms
0 ms: 2000 cases

We also ran the same test on a different system with recent SAS disks
connected via a HP/Compaq CCISS controller.  I don't have the exact
details of the drives used, since I don't know how to get them out of
the cciss driver, but the latencies we got were around 4 msec.  Whilst
this is better than the "commodity" hardware used in the tests above, it
still seems excessive.

Any advice would be appreciated.

Thanks,

-mato
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/