Re: 40% slowdown with dynamic /bin/sh

At 6:27 PM +1100 11/27/03, Bruce Evans wrote:
>On Wed, 26 Nov 2003, Garance A Drosihn wrote:
>  >
>  > I have reformatted the numbers that Michael reported,
>>  into the following table:
>>
>>  >Static /bin/sh:         Dynamic /bin/sh:
>>  >   real    385m29.977s     real    455m44.852s   => 18.22%
>>  >   user    111m58.508s     user    113m17.807s   =>  1.18%
>>  >   sys      93m14.450s     sys     103m16.509s   => 10.76%
>>  >                           user+sys              =>  5.53%
>
>What are people doing to make buildworld so slow?

Well, I'm not *trying* to make it slow...  :-)

>  > Here are some buildworld numbers of my own, from my system.
>>  In my case, I am running on a single Athlon MP2000, with a
>>  gig of memory.  It does a buildworld without paging to disk.
>
>I have a similar configuration, except with a single Athlon
>XP1600 overclocked by 146/133 and I always benchmark full
>makeworlds.  I was unhappy when the gcc pessimizations between
>gcc-2.95 and gcc-3.0 increased the makeworld time from about
>24 minutes to about 33 minutes.  The time has since increased
>to about 38 minutes.  The latter is cheating slightly -- I
>leave out the DYNAMICROOT and RESCUE mistakes and the KERBEROS
>non-mistake.

I keep DYNAMICROOT, RESCUE, and KERBEROS.  I'm tempted to
drop RESCUE just to see how much of a difference it would
make.

>This also shows why -j should not be used on non-SMP machines.
>...so it can only possibly help on systems where unbalanced
>resources (mainly slow disks) give too much idle time.

I got in the habit if using -j3 back on a system where my
disks were running ATA/33, even though they should have
been faster.  (eventually I figured out that the IDE cable
had been hooked up backwards)

>  > Buildworld, static, with no '-j',
>>                    executed /bin/sh  32,308 times.
>>
>>  Buildworld, static, with '-j2',
>>                    executed /bin/sh  32,802 times.
>
>Turning on accounting must have pessimized things a bit.

I did not turn on accounting.  I added a simple kludge
to /bin/sh so I would keep track of how often it was
called.  I had a benchmark of how much that slowed down
buildworld, but I've deleted that now.  iirc, It wasn't
too much, and it would have been the same amount for all
the builds that I gave numbers on.

>I think you are also using a pessimized kernel (with
>INVARIANTS and WITNESS).  makeworld times should be
>dominated by the gcc hog, but your sys times are almost
>as large as your user times.

Ugh.  I forgot to check those.

Yeah, I have:  INVARIANTS, INVARIANT_SUPPORT, and WITNESS.
I used to have them off, but when I bought the newer Althon
I turned them back on.  I also have them off on my sparc.
(I do keep WITNESS_SKIPSPIN, because dropping that gives me
more of a penalty than I want).


>  > On all attempts, I started out by doing:
>>       rm -Rf /usr/obj/usr/src/*
>>       sync ; sleep 1 ; sync ; sleep 1 ; sync
>>
>  > before doing the 'make' command.
>
>I use:
          [...skipping]
>	# Sometimes: export __MAKE_CONF=/etc/nonesuch
>	cd /wherever/src || exit 1
>	DESTDIR=/c/z/root \
>	MAKEOBJDIRPREFIX=/c/z/obj \
>	time -l make -s world > /tmp/world.out 2>&1

I also had some benchmarks of doing 'buildworld' over an
ssh connection vs doing it at the console.  Oddly enough,
the ssh connection was faster in some ways and slower in
others.  I wonder if there is a speed-up by writing to a
file instead of the console?

>Rebooting doesn't affect the times much in relative terms
>(...), but it reduces the variance to less than a second
>provided the system is mostly idle.

I had done a few buildworlds before starting any of the
buildworlds that I reported, and they seemed to be fairly
consistent after the first one.  Not "less than a second"
though, I think it was a few seconds difference.  Mainly I
just wanted to avoid the reboots.  These tests had chewed
up enough of my day as it was...

>  > Aside: building 5.1-"security" on this same hardware took
>>  the following times:
>  >    real    54m10.092s   [  71.03% ]
>>     user    41m39.121s   [  24.40% ]
>>     sys     10m20.325s   [ 210.69% ]
>>
>>  And those times *are* with 'script' running, as well as a
>>  perl-script which I use to summarize "interesting" data from
>>  the output of a buildworld.  So, those times include extra
>>  overhead which is not included in the above buildworlds.
>>  That's from a 'make -j3', and obviously has a static /bin/sh.
>
>Why so much faster?  Now the times are only 20% larger than mine,

>Building rescue only accounts for about 2 minutes of the
>86-54 difference.

Hmm.  Dunno.  I had assumed it was /rescue, but I did mean
to go back and get a better idea.  It did seem a bit large.

It might very well be that the 5.1-"secure" build was done
on a 5.1-release GENERIC kernel.  Ie, without INVARIANTS,
INVARIANT_SUPPORT, and WITNESS.  Those numbers are from a
left-over log of the build that I just happened to have
around, so it was done not in as controlled a setup as the
other builds.

>  > For those who think I'm spoiled by fast hardware, ...
>  > ... on my sparc64 box.  So I certainly am interested in
>  > how freebsd runs on "slower HW"!
>
>Single Athlon 1600-2000's are slow hardware :-).

I bet they beat a 300 MHz UltraSparc-IIi Processor!

-- 
Garance Alistair Drosehn            =   gad_at_gilead.netel.rpi.edu
Senior Systems Programmer           or  gad_at_freebsd.org
Rensselaer Polytechnic Institute    or  drosih_at_rpi.edu