glibc build timings

[DJ Delorie]

Some time ago Carlos asked me to look into how long it took to build
and test glibc, partly from frustration from developers at how much
time the test-in-container setup added. What follows is the results of
this task, and some insights into what might be changed in the
future.  This email is a copy of

  http://people.redhat.com/dj/glibc/build-times/

which contains the full raw data and reports.

Setup

The system used was a dual 6-core w/HT Xeon X5690 @ 3.47GHz, for a
total of 24 threads, with 64 Gb of RAM. Note that the absolute times
are not relevent, as the runs were being traced with strace. It's the
relative times that are relevent. "strace -e %process" was used to
trace all process activity, and scripts anaylzed these traces. Note
that .NOTPARALLEL: was added to the top-level Makefile to help keep
subdir stats separate.

Parallelzation

The first set of reports, with -j24, analyze the parallelization of
each subdir. The report lists each subdir and what percent of the time
it had N jobs running in parallel. Ideally, all the time would be
spent at the "24 jobs" level. Subdirs which spend more of their time
at lower parallelization levels are candidates for optimization. One
example would be the posix subdir (excerpt from "Full Build, -J24"
report):

 Subdir  Sec   %time at -jN
  posix:  17   14  5  3  2  1  -  -  -  -  -  1  -  -  -  -  -  -  -  -  1  4  9 17 29 

Note that 29% of the time, there are 24 posix jobs running, but 14% of
the time, there's only one. Rearranging the targets in posix/Makefile
might mean more efficient parallelization. In general, jobs that take
the longest, should be scehduled the earliest.

The incremental -j24 build is much less interesting, since there
aren't any jobs to run in parallel. However, a spot check of what
syscalls were happening during an incremental build indicated that
stat/lstat are nearly all of the syscalls, and a breakdown of which
file extensions are being stat'd is:

  90874 *.d
  72788 *.dt
  32524 *.h
  21329 *.list
   8460 *.ac
   6343 *.os
   4844 *.c
   3511 *.o
   1660 *.oS
   1298 *.awk

Note that the *.dt files are pretty much guaranteed to never exist,
due to this Makerules rule:

# This is a funny rule in that it removes its input file.
%.d: %.dt
	@sed $(sed-remove-objpfx) $< > $(@:.d=.T) && \
	 mv -f $(@:.d=.T) $@ && \
	 rm -f $<

Hiding the *.dt files inside the compiler rules might reduce the time
spent stat'ing non-existing files.

For the full check/test run, There are many directories with fewer
than 24 jobs, but a top-level paralellization should handle
those. However, the nptl subdir is explicitly not parallelized, as
some of the tests need to be run in isolation. One idea to remediate
this is to have the support infrastructure read-lock a file in the
build directory, and tests (any tests) that need to run by themselves
(without other tests running at the same time) could be configured to
take a write-lock on that file instead. That would allow most of the
nptl tests to run in parallel, while isolating the ones that can't.

For the incremental check/test run, no actual tests are run. However,
the summaries are still generated in full. Most of this time is spent
running /bin/head in merge-test-results.sh since it is called a
lot. Optimizing this script - either with builtins or by rewriting in
python or C - should quicken incremental testing.

Overhead

The second set of reports deals with the overhead of running the
builds. These are run without parallelization just to make analyzing
the reports simpler. For each report, the trace files were scanned and
run time allocated to each PID. The reports list accumulated runtime
for each program (like gcc or mv), each subdir, and combinations of
the above. Key notes from the full build - cc1 itself accounts for 80%
of the runtime, and adding as/ld brings that up to 87%.

Looking at an incremental build, we see that of the 107 seconds of
runtime, 56% is inside make itself! This includes parsing Makefiles as
well as stat'ing all the dependencies. Also, rm takes up 20% of the
runtime, despite not building anything.

The full check has no surprises; most of the time is spent either
compiling or in ld-linux-*.so.2, plus 7% in python. Keep in mind that
we do an incremental build as well as a "make install" as part of this
full check.

An incremental "make check" shows 68% of the time spent in make, and
19% in head. Head plus the merge-test-results script account for 30%
of the time, or 15 of the 52 seconds. Optimizing this script should
give significant speedups.