the evil interrupt stats monster is still around!
dillon at apollo.backplane.com
Sat Jul 28 16:59:33 PDT 2007
:ktrace. These are real numbers, not a microbenchmark. There might be a little bit of load interfering, dunno. You can grab the dump from <http://chlamydia.fs.ei.tum.de/~corecode/unsorted/kdump.out.bz2>
Use kdump -R !!!
In anycase, it does look odd. But I can't reproduce the effect
when I ktrace a similar bmake from pkgsrc and there are cases
in your dump where you don't get large timeouts:
66255 sh 1185522939.738309 CALL fork
66255 sh 1185522939.738419 RET fork 66264/0x102d8
66255 sh 1185522939.738665 CALL getpgrp
66255 sh 1185522939.738676 RET getpgrp 5268/0x1494
66255 sh 1185522939.738730 CALL wait4(0xffffffff,0xbfbff318,0x2,0)
66264 sh 1185522939.738745 RET fork 0
<----------- 15 uS (326 uS from original
66264 sh 1185522939.739292 CALL open(0x280de1c8,0x601,0x1b6)
66264 sh 1185522939.739306 NAMI "/dev/null"
66264 sh 1185522939.739346 RET open 5
What it looks like is happening is that there are other processes
running that get the cpu after the fork/wait4, before the child
gets the cpu. Insofar as I can tell it looks like there is a cpu-bound
program running that is simply not making any system calls to be traced,
or is not being traced.
Are you running anything in parallel during this test or running
a parallel build of some sort?
More information about the Bugs