On Mon, Jun 22 2009, Richard Kennedy wrote:
> I been running a hopefully simple fio test, but I don't understand the
> results.
>
> the test :-
>
> fio --name=f1 --directory=/sda --rw=rw --size=400m
> --name=f2 --directory=/sdb --rw=write --size=1g --startdelay=10
>
> on linux 2.6.30-git
>
> running this takes quite while, 'time fio ...' gives
> real 3m49.174s
> user 0m0.838s
> sys 0m7.990s
That does looke very odd.
> (edited highlights of the fio output)
> f1: (groupid=0, jobs=1): err= 0: pid=5181
> read : io=200MiB, bw=23,480KiB/s, iops=5,870, runt= 8722msec
> write: io=200MiB, bw=23,499KiB/s, iops=5,874, runt= 8715msec
> f2: (groupid=0, jobs=1): err= 0: pid=5182
> write: io=1,024MiB, bw=77,231KiB/s, iops=19,307, runt= 13577msec
>
> The jobs seem to finish reasonable quickly, but then fio seem to be
> stuck waiting for something. CPU usage is 100% but the CPU frequency
> stays at the lowest level and the system is really sluggish in its
> response. It does recover in time but this test does seem to torture my
> system.
>
> strace shows fio repeating this :-
> open and read several disk stats, such as
>
> open("/sys/block/sdb/stat", O_RDONLY) = 10
> fstat(10, {st_mode=S_IFREG|0444, st_size=4096, ...}) = 0
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7ff9ef70c000
> read(10, " 45168 22897 2239004 1505"..., 4096) = 99
> close(10) = 0
> munmap(0x7ff9ef70c000, 4096) = 0
>
> then...
>
> gettimeofday({1245665343, 22984}, NULL) = 0
> gettimeofday({1245665343, 23015}, NULL) = 0
> ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
> gettimeofday({1245665343, 23086}, NULL) = 0
> gettimeofday({1245665343, 23115}, NULL) = 0
> gettimeofday({1245665343, 23150}, NULL) = 0
> setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 250000}}, NULL) = 0
> rt_sigreturn(0) = -1 EINTR (Interrupted system call)
> wait4(5321, 0x7fffcfed49d4, WNOHANG, NULL) = 0
> nanosleep({0, 10000000}, NULL) = 0
> wait4(5321, 0x7fffcfed49d4, WNOHANG, NULL) = 0
> nanosleep({0, 10000000}, NULL) = 0
> ...
> wait4(5321, 0x7fffcfed49d4, WNOHANG, NULL) = 0
> nanosleep({0, 10000000}, NULL) = 0
>
> then back to the open & reads..
This is normal, since it looks like you are stracing the parent process.
You'll want to inspect the two processes that are actually performing
the IO.
> The machine is a AMD X2 64bit with 3G memory & fio is 1.26.
Did you pull changes into that fio repo and not do a make clean before
compiling it? The build system is a bit broken, so it wont always
rebuild everything if eg fio.h had changes to structures. And that'll
cause weird behaviour sometimes.
In any case, please try and download a new fresh version and see if that
makes it any better.
There was also a recent linux kernel futex problem that fio triggered,
so it could also be a kernel issue. Again, knowing what the two other
jobs are doing would help.
--
Jens Axboe
--
To unsubscribe from this list: send the line "unsubscribe fio" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
