Re: ext3 IO latency measurements (was: Linux 2.6.29)

Jens Axboe
2009-03-26T11:08:28Z

On Thu, Mar 26 2009, Ingo Molnar wrote:
> And it's not just sys_fsync(). The script i wrote tests file read
> latencies. I have created 1000 files with the same size (all copies
> of kernel/sched.c ;-), and tested their cache-cold plain-cat
> performance via:
>
> for ((i=0;i<1000;i++)); do
> printf "file #%4d, plain reading it took: " $i
> /usr/bin/time -f "%e seconds." cat $i >/dev/null
> done
>
> I.e. plain, supposedly high-prio reads. The result is very common
> hickups in read latencies:
>
> file # 579 (253560 bytes), reading it took: 0.08 seconds.
> file # 580 (253560 bytes), reading it took: 0.05 seconds.
> file # 581 (253560 bytes), reading it took: 0.01 seconds.
> file # 582 (253560 bytes), reading it took: 0.01 seconds.
> file # 583 (253560 bytes), reading it took: 4.61 seconds.
> file # 584 (253560 bytes), reading it took: 1.29 seconds.
> file # 585 (253560 bytes), reading it took: 3.01 seconds.
> file # 586 (253560 bytes), reading it took: 7.74 seconds.
> file # 587 (253560 bytes), reading it took: 3.22 seconds.
> file # 588 (253560 bytes), reading it took: 0.05 seconds.
> file # 589 (253560 bytes), reading it took: 0.36 seconds.
> file # 590 (253560 bytes), reading it took: 7.39 seconds.
> file # 591 (253560 bytes), reading it took: 7.58 seconds.
> file # 592 (253560 bytes), reading it took: 7.90 seconds.
> file # 593 (253560 bytes), reading it took: 8.78 seconds.
> file # 594 (253560 bytes), reading it took: 8.01 seconds.
> file # 595 (253560 bytes), reading it took: 7.47 seconds.
> file # 596 (253560 bytes), reading it took: 11.52 seconds.
> file # 597 (253560 bytes), reading it took: 10.33 seconds.
> file # 598 (253560 bytes), reading it took: 8.56 seconds.
> file # 599 (253560 bytes), reading it took: 7.58 seconds.

Did you capture the trace of the long delays in the read test case? It
can be two things, at least. One is that each little read takes much
longer than it should, the other is that we get stuck waiting on a dirty
page and hence that slows down the reads a lot.

--
Jens Axboe