DragonFlyBSD

Okay, joerg and me could speed pkgsrc building up a bit by telling pkgsrc to use the builtin for test and [.

However, look at this:

avg fork parent: 0.000148
avg fork child: 0.004091

(rough rough numbers, will be off if there are multiple processes running concurrently)

5ms seems to be a good estimate for fork performance. but mind you, that's the child which is taking longer. This means the parent returns first, then starts wait4'ing (usually, or blocks on a read or so), then some time passes and then later the child returns from fork. Seems wrong to me.

so much statistics for now, cheers
simon

Okay, less rough numbers:

122991 104/s fork

avg fork parent: 0.000157
avg fork child: 0.002563

so if we assume that the parent always waits for the child, it'll take 0.267 seconds per second (in average) to fork? That means 1/4 of the time is just spent until the child start running.

the above numbers include vfork, these are without:

avg fork parent: 0.000144
avg fork child: 0.002556

same, basically. Maybe teaching sh(1) to use vfork could give some performance improvement?

cheers
simon

:Okay, less rough numbers:
:
:122991 104/s fork
:
:avg fork parent: 0.000157
:avg fork child: 0.002563
:
:so if we assume that the parent always waits for the child, it'll take 0.267 seconds per second (in average) to fork? That means 1/4 of the time is just spent until the child start running.
:
:the above numbers include vfork, these are without:
:
:avg fork parent: 0.000144
:avg fork child: 0.002556
:
:same, basically. Maybe teaching sh(1) to use vfork could give some performance improvement?
:
:cheers
: simon

There is always something running somewhere when you fork.  Either the
    child is running or the parent is running.  Either way both have to run
    to their completion before the next program can be execed when running
    a shell script since the script serializes everything.

It tends to be more efficient to allow the parent to continue to run
    (that is, to return from the fork) because there are fewer context
    switches.

parent        child
    ----------        -----------
    fork()        -
    wait        -
    -            run
    -            run
    -            run
    -            run
    -            exit
    waitreturn

parent        child
    ----------        -----------
    fork()        -
    -            run
    -            run
    -            run
    wait        -        <<< 2 extra context switches
    -            run
    -            run
    -            exit
    waitreturn

I would rather not try to optimize programs to use vfork().  There
    just isn't a whole lot of difference between fork and vfork.

Most of the time spent by the child is not waiting for the parent
    to switch it in, but instead is being spent in execl().  It may be
    possible to speed up execution by making certain dynamic binaries 
    resident (with the 'resident' command).  Everything in /bin is
    statically linked alredy, though, and already execs as fast as it is
    possible to exec a program.  But perhaps pkgsrc is using certain
    binaries internally that are dynamically linked.  I suggest taking
    a good look at what pkgsrc runs.

There is a fork test program in /usr/src/test/sysperf/fork1.c.
    (make /tmp/fork1 from /usr/src/test/sysperf).  I get around 
    154 uS for a complete fork/exit/wait sequence on my test box.
    A time of 2 mS indicates that something else is going on.. either
    other processes are running or whatever you are execing is taking
    a long time to initialize (which would not be surprising if we are
    talking about /bin/sh here).

The GNU configure script crap is just that... crap.  In a typical
    pkgsrc build that script will probably be run thousands of times,
    doing the same tests with slow shell scripts over and over and over
    and over and over and over again.  It's really the stupidest gnu thing
    I've ever seen in my life.  It was stupid a decade ago, and its still
    stupid today.

-Matt

No, my point was that the child takes some time to even return from the fork, despite the parent already wait()ing. There is some gap involved where the system seemingly just schedules somebody else instead or so.

Ah, I see the point. This however does not explain why the child takes some time to be scheduled.

I think our vfork is not completely optimized. We could for instance make vfork not COW the vmspace, because the user is only allowed to call _exit and exec(). I don't think we are doing this right now.

That's actually not true:

Total runtime 1171.642231 sec

122991 104/s 0.002616 321.756458 fork_child
122991 104/s 0.000148 18.181783 fork_parent
112576 96/s 0.000235 26.489667 execve
239985 204/s 0.000080 19.174908 open
(etc)

total exec time is not very high.

I'm not talking about fork/exec performance. This is from a build kdump, taking the CALL and RET times and calculating the duration of the syscall.

cheers
simon

Those numbers don't make any sense. What program are you using to
try to measure the child fork return time ?

-Matt

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>

cheers
simon

: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>
:
:cheers
: simon

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
fork)
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?

-Matt

heh. well, the absolute ones help me process the time automatically.

Yah, quite possible. However, why'd that only happen for for fork and not for other possibly blocking syscalls (or vfork)? I think we need some better, performance-counter based tracing tools, rather than plain kdump output.

I don't remember anymore, probably there was a build going on in parallel. But again, I'm not trying to benchmark, I'm trying to find a cause for the slow build speed.

cheers
simon

:Yah, quite possible. However, why'd that only happen for for fork and not for other possibly blocking syscalls (or vfork)? I think we need some better, performance-counter based tracing tools, rather than plain kdump output.

There really isn't a whole lot of difference between fork and vfork,
    but I noticed at the end of your dump that both fork and vfork had
    much shorter delays then what I saw at the beginning of your dump.

:> Are you running anything in parallel during this test or running
:> a parallel build of some sort?
:
:I don't remember anymore, probably there was a build going on in parallel. But again, I'm not trying to benchmark, I'm trying to find a cause for the slow build speed.
:
:cheers
: simon

Its called a script titled 'gnu configure'.  Do a systat -vm 1 and look
    at the name cache hit stats.  Everything bmake, gcc, and especially the
    gnu configure script do is extremely filesystem intensive.  And in the
    case of gnu configure, also mostly redundant.

-Matt

When NetBSD implemented a real vfork back around NetBSD 1.4 or so, it
made difference in the percent range for a full buildworld. Basically,
you can avoid the duplication of the VM space and the COW faulting,
which sums up.

While a lot of bad things can be said about autoconf, it was the only
usable, semi-generic solution for over a decade. There is still only
one good alternative (and that is using C++...). The biggest complain
most maintainers on non-default (from the upstream POV) platform had in
all that time was that it is hard to use correctly. E.g. many tests can
be done a lot more intelligently than most configure scripts do. Given
that autoconf follows the "stand-alone" paradigm (as opposed to imake
for some parts of the problem domain), it actually implements it quite
well.

Joerg