From owner-freebsd-current@FreeBSD.ORG Tue May 1 22:46:17 2012 Return-Path: Delivered-To: freebsd-current@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:4f8:fff6::34]) by hub.freebsd.org (Postfix) with ESMTP id 9D419106566B; Tue, 1 May 2012 22:46:17 +0000 (UTC) (envelope-from erik@cederstrand.dk) Received: from csmtp3.one.com (csmtp3.one.com [91.198.169.23]) by mx1.freebsd.org (Postfix) with ESMTP id 26FD08FC0C; Tue, 1 May 2012 22:46:17 +0000 (UTC) Received: from [192.168.1.15] (unknown [217.157.7.221]) by csmtp3.one.com (Postfix) with ESMTPA id 8C8B42427E3A; Tue, 1 May 2012 22:46:06 +0000 (UTC) Mime-Version: 1.0 (Apple Message framework v1257) Content-Type: text/plain; charset=us-ascii From: Erik Cederstrand In-Reply-To: <20120501135530.GA50127@in-addr.com> Date: Wed, 2 May 2012 00:46:04 +0200 Content-Transfer-Encoding: quoted-printable Message-Id: <13119BE4-531E-4681-89F0-876DC272B18F@cederstrand.dk> References: <20120426093548.GR2358@deviant.kiev.zoral.com.ua> <20120426134140.GF14350@lo0.su> <4F99ACF9.2050609@infracaninophile.co.uk> <42D8809D-0E99-47A5-802F-71991B5B0B8D@cederstrand.dk> <20120501135530.GA50127@in-addr.com> To: Gary Palmer X-Mailer: Apple Mail (2.1257) Cc: freebsd-current FreeBSD Subject: Re: [RFC] Un-staticise the toolchain X-BeenThere: freebsd-current@freebsd.org X-Mailman-Version: 2.1.5 Precedence: list List-Id: Discussions about the use of FreeBSD-current List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 01 May 2012 22:46:17 -0000 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=