Re: [RFC] Un-staticise the toolchain

On Tuesday, May 01, 2012 6:46:04 pm Erik Cederstrand wrote:
> Den 01/05/2012 kl. 15.55 skrev Gary Palmer:
> > 
> > If you want a high-level view of what goes on run
> > 
> > ldd `which ls`
> > 
> > check that it has libraries to load and doesn't say "not a dynamic ELF
> > executable", and then run: 
> > 
> > ktrace ls
> > kdump | more
> > 
> > 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=no' 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

Keep in mind that the first time each system call is invoked, the runtime
linker has to resolve the symbol.  You can force the linker to do all
that when the object is loaded instead by setting LD_BIND_NOW=yes in the
environment of dynamicmake.  If that makes the sysarch() call take 0.01
ms, then you know that the extra 0.10 ms is because of rtld doing the
lookup of sysarch() on the first sysarch() call.

-- 
John Baldwin