A specific example of a disk i/o problem

[Richard Mahlerwein]

>From: Dieter <freebsd at sopwith.solgatos.com>
>Subject: Re: A specific example of a disk i/o problem
>To: freebsd-performance at freebsd.org
>Date: Friday, October 2, 2009, 1:07 AM
>
>Updated demo, just to make sure:
>
># big_file is larger than main memory, on same disk as man (/usr)
>time man de        
>cat big_file > /dev/null   
>cat big_file > /dev/null & 
>time man de

Trying it on something that surely will have i/o issues:
PIII 500 w/ 60 GB PATA drive and 256 MB RAM.  Blank
minimal install + man pages right now.  I'm trying with
a "file /etc/" command instead of trying to reliably time
man... It seems the file command always hits the disk. 
This should also make any sort of "flushing" unecessary,
shouldn't it?  Anyway, I tried it with the man command but couldn't discern any difference at all with it, so I'm repeating with "file" which at least gives SOME variance.
 
liebnitz# uname -a
FreeBSD xyz 7.2-RELEASE FreeBSD 7.2-RELEASE #0: Fri May  1 08:49:13 UTC 2009     root at walker.cse.buffalo.edu:/usr/obj/usr/src/sys/GENERIC 
i386

liebnitz# time dd if=/dev/zero of=/usr/bigfile count=4096 bs=1M
4096+0 records in
4096+0 records out
4294967296 bytes transferred in 363.700967 secs (11809062 bytes/sec)
0.055u 83.971s 6:03.78 23.0%    25+1071k 128+34391io 0pf+0w

liebnitz# time file /etc/ [run 5 times]
4.052u 0.047s 0:04.14 98.7%    15+1085k 0+0io 0pf+0w
4.068u 0.031s 0:04.13 99.0%    16+1095k 0+0io 0pf+0w
4.052u 0.046s 0:04.13 99.0%    16+1101k 0+0io 0pf+0w
4.044u 0.054s 0:04.13 99.0%    16+1092k 0+0io 0pf+0w
4.052u 0.046s 0:04.13 99.0%    15+1091k 0+0io 0pf+0w

Ok, so that looks pretty repeatable.  Now...

liebnitz# cat /usr/bigfile > /dev/null &
[1] 37923
liebnitz# time file /etc/* [again run 5 times]
4.146u 0.038s 0:06.80 61.3%    15+1103k 87+0io 8pf+0w
4.128u 0.054s 0:06.73 61.9%    15+1095k 93+0io 6pf+0w
4.127u 0.056s 0:06.65 62.7%    14+1058k 88+0io 4pf+0w
4.111u 0.072s 0:06.84 61.1%    15+1049k 91+0io 6pf+0w
4.115u 0.066s 0:06.86 60.7%    15+1022k 91+0io 6pf+0w

BTW, after the cat is done...
liebnitz# time file /etc/*
4.051u 0.047s 0:04.13 99.0%     15+1078k 0+0io 0pf+0w

I see no unexpected issues, only a minor slowdown, and that could be processer contention, IMO.  

(Sorry for duplicate, I was rewriting with the change to "file" instead of "man" and the two year old decided to press some keys and sent the message.)