Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 2 May 2012 00:46:04 +0200
From:      Erik Cederstrand <erik@cederstrand.dk>
To:        Gary Palmer <gpalmer@freebsd.org>
Cc:        freebsd-current FreeBSD <freebsd-current@freebsd.org>
Subject:   Re: [RFC] Un-staticise the toolchain
Message-ID:  <13119BE4-531E-4681-89F0-876DC272B18F@cederstrand.dk>
In-Reply-To: <20120501135530.GA50127@in-addr.com>
References:  <20120426093548.GR2358@deviant.kiev.zoral.com.ua> <20120426134140.GF14350@lo0.su> <CADLo838sdUT2e%2B7j8vCyOmDithLsh3kwDd_z04dWaPoiMphPDQ@mail.gmail.com> <4F99ACF9.2050609@infracaninophile.co.uk> <CADLo83_sr=13H=9nnrdge0jJaOh5Bk2N_gg=Gf-uYhwM8jm7Xg@mail.gmail.com> <42D8809D-0E99-47A5-802F-71991B5B0B8D@cederstrand.dk> <A79EE48D-A2AC-4D35-B156-1F58D17F77DD@kientzle.com> <AF37B4BF-69D5-41D3-819A-0252911CBC89@cederstrand.dk> <20120501135530.GA50127@in-addr.com>

next in thread | previous in thread | raw e-mail | index | archive | help
Den 01/05/2012 kl. 15.55 skrev Gary Palmer:
>=20
> If you want a high-level view of what goes on run
>=20
> ldd `which ls`
>=20
> check that it has libraries to load and doesn't say "not a dynamic ELF
> executable", and then run:=20
>=20
> ktrace ls
> kdump | more
>=20
> All the system calls related to resolving and loading shared libraries
> take time.  I realise "ls" is not "make", but it should give you an
> idea.

Just for fun, I did some measurements with ktrace and a static vs =
dynamic make. I did 'ktrace make' and 'trace dynamicmake' ('dynamicmake' =
produced by running 'make NO_SHARED=3Dno' in /usr/src/usr.bin/make), =
just to see where time is spent when loading and running make in the =
static and dynamic cases. I did this 100 times for each version =
(discarding the first run) and ran through ministat (numbers in msecs):

x static.dat
=
+-------------------------------------------------------------------------=
-------+
|               x             x                                          =
        |
|               x x x       x x x            x                           =
        |
|               x x x       x x x            x     x                     =
        |
|            x  x x x x   x x x x     x      x     x     x               =
        |
|  x         x  x x x x   x x x x   x x      x x   x   x x               =
        |
|  x       x x  x x x x x x x x x x x x  x x x x x x   x x               =
        |
|x x       x x  x x x x x x x x x x x x  x x x x x x   x x x   x x  x x  =
       x|
|               |_____________M__A_______________|                       =
        |
=
+-------------------------------------------------------------------------=
-------+
    N           Min           Max        Median           Avg        =
Stddev
x 100         2.228         2.266         2.242       2.24333       =
0.00794

x dynamic.dat
=
+-------------------------------------------------------------------------=
-------+
|                            x                                           =
        |
|                            xx                                          =
        |
|               x            xx   x x   x                                =
        |
|               x            xx   x x   xx     x                         =
        |
|               x          x xx   x x   xx   x x x                       =
        |
|               x x    x x x xx   x x   xx   x x x               x       =
        |
|x          x   x xx   x x x xx x x x x xx x x x x  x            x       =
        |
|x     xx   x x x xx   x x x xx x x x x xx x x x x xx x x x x xx x       =
   x x x|
|                   |_____________M_A_______________|                    =
        |
=
+-------------------------------------------------------------------------=
-------+
    N           Min           Max        Median           Avg        =
Stddev
x 100         2.648         2.691         2.666        2.6669       =
0.00873


So the dynamic version is ca. 0.42 ms, or 16%, slower on my system.

I then compared a trace from a static and a dynamic 'make'. Both =
selected traces had a running time matching the median of that run. I =
cut away all common system calls etc., which resulted in just the steps =
involved in loading 'make' to a state where it can start executing.

In the static case, this took 0.26 ms. In the dynamic case, this took =
0.57 ms, or 0.31 ms (119%) more. The remaining ca. 0.11 ms (0.42 - 0.31) =
are mainly due to the dynamic version having slightly slower IO (read() =
and stat()). I have no idea why. The following are the notable steps in =
each version:

Static version:
 * 0.09 ms spent execve'ing /usr/bin/make
 * The rest is mostly sysctl calls

Dynamic version:
 * 0.09 ms spent execve'ing ./dynamicmake and /libexec/ld-elf.so.1
 * 0.18 ms spent loading libc.so.7 (incl. reading /etc/libmap.conf and =
/var/run/ld-elf.so.hints)
 * 0.11 ms spent calling sysarch(0x81,0x7fffffffXXXX) (static version =
also does this but only uses 0.01 ms. No idea why)
 * The rest is mostly sysctl and sigprocmask calls


Loading of libc.so.7 does indeed seem to be the main culprit.


Thanks,
Erik=



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?13119BE4-531E-4681-89F0-876DC272B18F>