User:Gszorc/Build System Experimentation
The Mozilla build system, specifically all the makefiles and the things they do, is scary. I have a personal project (which will inevitably bleed into bugs and patches) to improve it any way I can.
Contents
Impetus
User:ally and I were opining how developing mozilla-central on Windows isn't very Windows-y. Specifically, there is no official Visual Studio story. Windows developers love Visual Studio and it is really unfortunate we can't give them what they love (no, scanning existing directories for source or simply using the debugger does not count). So, all the work on this page started as a way to explore generating Visual Studio project files automatically with the goal of eventually bundling them in the source tree (or at least providing a way for them to be generated automatically on checkout).
PyMake Hacking
I'm working on a number of features to PyMake to make it more useful and faster. My work can be found at https://github.com/indygreg/pymake (typically inside a branch). This Github repository is an unofficial import of the Mercurial repository hosted by Mozilla. I make no promises that Mercurial changes are pushed to Github.
Tracing
I've implemented tracing to PyMake. When you load a *Makefile* instance in PyMake, you have the option of passing an object which will receive notifications during certain build events, such as:
- Start/end of new Makefile processing
- Start/end of target processing
- Start/end of command execution
These callbacks all pass information about the object they are operating on.
Using this callback API, I've implemented a basic tracing logger and integrated it with the PyMake make.py driver. It takes the callback data, converts it to JSON, and writes it to a file. This stream contains very detailed records, including dependencies and variables. From that stream, we should be able to perform magic not previously conceivable.
Tracing is available in the *tracing* branch of the aforementioned Git repository.
Tracing Your Builds
WARNING: tracing is still in early development. File formats and the APIs WILL change. Use at your own risk.
To trace builds with PyMake, you simply invoke pymake.py with the --trace-log argument.
$ cd mozilla-central/objdir $ /path/to/pymake/make.py --trace-log=/home/gps/pymake-trace00.log -f ./Makefile # wait for make to finish - this takes a while
As PyMake is running, the file specified by --trace-log will be appended with events as they happen. Parallel builds should work fine, as PyMake obtain an exclusive lock on a lock file before writing to it.
Be sure to specify a full path to the --trace-log file. If you don't, you may be bitten by relative paths and current working directories.
Analyzing Your Traces
There are 3 options for analyzing traces:
- Write your own parser/analyzer
- Use the CLI script in my tree
- Code Python against the parser class in PyMake
I would hold off on #1 right now because data formats will likely change and your custom code will break.
My Git repository contains a CLI script in build/pymake/pymaketrace.py. To see how to use it:
$ ./build/pymake/pymaketrace.py --help # or $ python ./build/pymake/pymaketrace.py --help
There is also a Python module for analyzing the trace files, pymake.traceparser. This modules contains a class, TraceParser. This class has a number of convenient methods for analyzing the trace file. All this is in build/pymake/pymake/traceparser.
By far the easiest is the supplied CLI script. For example, to analyze the command counts during a trace run:
$ ./build/pymake/pymaketrace.py --print-command-counts ~/trace00.log
Native Python Execution
Creating a new Python interpreter to run Python code from an existing Python interpreter (PyMake) is silly.
During the course of a normal build, PyMake calls out to numerous Python scripts (see observations below). For each command executed this way, we spin off a new process, fire up a new Python interpreter, and execute the script. This is slow, especially on Windows, where new processes aren't as cheap as they are on NIX platforms. It is grossly inefficient when you take into account the simplicity of the scripts being executed (e.g. *nsinstall.py*). The execution time is most often dominated by the Python interpreter process creation overhead.
To make matters even more ridiculous, *PyMake already has support for native Python command execution*! By simply prefixing a recipe line with *%*, PyMake can call out into Python modules!
I plan to rewrite things so some of the most abused Python scripts are called natively from PyMake. This is a 2 step process:
- Rewrite existing scripts so they can be called as routines in a module
- Rewrite Makefiles to use the native syntax when running under PyMake
Observations
Fresh Builds
Linux
On Linux, I performed a trace on a fresh obj directory following a make configure. First, my .mozconfig:
mk_add_options MOZ_OBJDIR=@TOPSRCDIR@/obj-ff-debug mk_add_options MOZ_MAKE_FLAGS="-j8" ac_add_options --enable-application=browser ac_add_options --enable-tests ac_add_options --with-ccache=/usr/bin/ccache ac_add_options --enable-optimize=-O2
Using pymaketrace.py --print-target-counts, we see a number of targets evaluated more than 10 times:
12 /build/automation-build.mk 12 /obj-ff-debug/gfx/qcms/Makefile 12 /obj-ff-debug/widget/src/gtkxtbin/Makefile 12 /xpcom/glue/objs.mk 16 /nsprpub/config/prdepend.h 19 /js/src/config/config.mk 19 /js/src/config/rules.mk 19 /js/src/config/static-checking-config.mk 19 /js/src/config/version.mk 19 /js/src/@MOZ_BUILD_APP@/app-config.mk 19 /js/src/@MOZ_BUILD_APP@/app-rules.mk 19 /obj-ff-debug/js/src/config/myconfig.mk 19 /obj-ff-debug/js/src/config/myrules.mk 21 /obj-ff-debug/js/src/config/autoconf.mk 25 /obj-ff-debug/dist/lib/libxpcomglue_s.a.desc 36 /browser/build.mk 36 /config/js/build.mk 36 /config/nspr/build.mk 36 /obj-ff-debug/Makefile.in 36 /testing/testsuite-targets.mk 36 /toolkit/toolkit-tiers.mk 37 /obj-ff-debug/Makefile 39 /toolkit/mozapps/installer/package-name.mk 45 /nsprpub/config/config.mk 45 /nsprpub/config/rules.mk 45 /obj-ff-debug/nsprpub/config/autoconf.mk 48 /build/binary-location.mk 147 /obj-ff-debug/dist/idl 147 /obj-ff-debug/dist/include 155 /ipc/chromium/chromium-config.mk 294 /xpcom/idl-parser/typelib.py 295 /xpcom/idl-parser/header.py 295 /xpcom/idl-parser/xpidl.py 886 /obj-ff-debug/dist/bin/chrome 2613 /browser/app-config.mk 2613 /browser/app-rules.mk 2613 /config/config.mk 2613 /config/rules.mk 2613 /config/static-checking-config.mk 2613 /config/version.mk 2613 /obj-ff-debug/config/autoconf.mk 2613 /obj-ff-debug/config/myconfig.mk 2613 /obj-ff-debug/config/myrules.mk
As for commands, here are the ones executed more than 10 times:
14 chmod 18 /home/gps/src/mozilla-central/config/Preprocessor.py 20 ranlib 29 yasm 31 set 61 /home/gps/src/mozilla-central/build/xpccheck.py 72 /home/gps/src/mozilla-central/config/JarMaker.py 84 rm 136 perl 146 /home/gps/src/mozilla-central/obj-ff-debug/dist/sdk/bin/xpt.py 364 /home/gps/src/mozilla-central/config/buildlist.py 381 /home/gps/src/mozilla-central/config/pythonpath.py 693 pymake.builtins 1276 if 1653 nsinstall 2680 /home/gps/src/mozilla-central/build/pymake/make.py 3303 ccache 5598 echo
Windows
On Windows, I performed a trace on a fresh obj directory following a make configure. My .mozconfig:
mk_add_options MOZ_OBJDIR=@TOPSRCDIR@/obj-ff-debug mk_add_options MOZ_MAKE_FLAGS="-j1" ac_add_options --enable-application=browser ac_add_options --enable-tests ac_add_options --disable-angle
For the fresh build, PyMake churned through 26060 targets. The most processed targets were:
11 \dist\lib\mozjs.lib 12 \gfx\qcms\Makefile 12 c:\dev\src\mozilla-central-git\build\automation-build.mk 12 c:\dev\src\mozilla-central-git\xpcom\glue\objs.mk 15 \js\src\config\myconfig.mk 15 \js\src\config\myrules.mk 15 c:\dev\src\mozilla-central-git\js\src\@MOZ_BUILD_APP@\app-config.mk 15 c:\dev\src\mozilla-central-git\js\src\@MOZ_BUILD_APP@\app-rules.mk 15 c:\dev\src\mozilla-central-git\js\src\config\config.mk 15 c:\dev\src\mozilla-central-git\js\src\config\rules.mk 15 c:\dev\src\mozilla-central-git\js\src\config\static-checking-config.mk 15 c:\dev\src\mozilla-central-git\js\src\config\version.mk 16 c:\dev\src\mozilla-central-git\nsprpub\config\prdepend.h 17 \js\src\config\autoconf.mk 20 \dist\lib\xul.lib 24 \dist\lib\xpcomglue_s.lib.desc 26 \dist\lib\xpcom.lib 29 \dist\lib\mozalloc.lib 29 c:\dev\src\mozilla-central-git\config\version_win.pl 33 \dist\lib\nspr4.lib 33 \dist\lib\plc4.lib 33 \dist\lib\plds4.lib 35 \Makefile.in 36 \Makefile 36 c:\dev\src\mozilla-central-git\browser\build.mk 36 c:\dev\src\mozilla-central-git\config\js\build.mk 36 c:\dev\src\mozilla-central-git\config\nspr\build.mk 36 c:\dev\src\mozilla-central-git\testing\testsuite-targets.mk 36 c:\dev\src\mozilla-central-git\toolkit\toolkit-tiers.mk 43 c:\dev\src\mozilla-central-git\toolkit\mozapps\installer\package-name.mk 45 \nsprpub\config\autoconf.mk 45 c:\dev\src\mozilla-central-git\nsprpub\config\config.mk 45 c:\dev\src\mozilla-central-git\nsprpub\config\rules.mk 48 c:\dev\src\mozilla-central-git\build\binary-location.mk 146 \dist\idl 146 \dist\include 158 c:\dev\src\mozilla-central-git\ipc\chromium\chromium-config.mk 292 c:\dev\src\mozilla-central-git\xpcom\idl-parser\typelib.py 293 c:\dev\src\mozilla-central-git\xpcom\idl-parser\header.py 293 c:\dev\src\mozilla-central-git\xpcom\idl-parser\xpidl.py 879 \dist\bin\chrome 2588 \config\autoconf.mk 2588 \config\myconfig.mk 2588 \config\myrules.mk 2588 c:\dev\src\mozilla-central-git\browser\app-config.mk 2588 c:\dev\src\mozilla-central-git\browser\app-rules.mk 2588 c:\dev\src\mozilla-central-git\config\config.mk 2588 c:\dev\src\mozilla-central-git\config\rules.mk 2588 c:\dev\src\mozilla-central-git\config\static-checking-config.mk 2588 c:\dev\src\mozilla-central-git\config\version.mk
For commands, PyMake spun off 30116. The grouping of commands is currently unavailable on Windows due to a bug in the PyMake trace parser.
Previously-Built Trees
While fresh builds are interesting, most developers care about the time to build on existing tree, because that is something we find ourselves doing every day. We typically shy away from rebuilding the whole tree because it takes so long. Instead, we typically make -C in the component we change. There's nothing wrong with that. But, there is always the possibility we could have missed a cascading dependency.
I would argue that in the ideal build system the output of a simple make for an already completely built tree would only consist of the following messages:
Make: Entering directory A Make: Entering directory B Make: Nothing to be done for B Make: Leaving directory B Make: Leaving directory B
Actually, a perfect build system would just say nothing to be done and exit. But, make's little brain can't grok the state of the world like that, since it has to parse Makefiles in other directories (which is what the Entering directory logs signify).
Anyway, when you build mozilla-central on a tree that's already fully built, we see tons of other output. e.g.
make.py[6]: Entering directory '/home/gps/src/mozilla-central/obj-ff-debug/js/src/ctypes/libffi' /home/gps/src/mozilla-central/obj-ff-debug/js/src/ctypes/libffi/Makefile:1035:0$ depbase=`echo src/debug.lo | sed 's|[^/]*$|.deps/&|;s|\.lo$||'`;\ /bin/bash ./libtool --tag=CC --mode=compile gcc -DHAVE_CONFIG_H -I. -I../../../../../js/src/ctypes/libffi -I. -I../../../../../js/src/ctypes/libffi/include -Iinclude -I../../../../../js/src/ctypes/libffi/src -Wall -g -fexceptions -O2 -MT src/debug.lo -MD -MP -MF $depbase.Tpo -c -o src/debug.lo ../../../../../js/src/ctypes/libffi/src/debug.c &&\ mv -f $depbase.Tpo $depbase.Plo libtool: compile: gcc -DHAVE_CONFIG_H -I. -I../../../../../js/src/ctypes/libffi -I. -I../../../../../js/src/ctypes/libffi/include -Iinclude -I../../../../../js/src/ctypes/libffi/src -Wall -g -fexceptions -O2 -MT src/debug.lo -MD -MP -MF src/.deps/debug.Tpo -c ../../../../../js/src/ctypes/libffi/src/debug.c -fPIC -DPIC -o src/debug.o /home/gps/src/mozilla-central/obj-ff-debug/js/src/ctypes/libffi/Makefile:1035:0$ depbase=`echo src/prep_cif.lo | sed 's|[^/]*$|.deps/&|;s|\.lo$||'`;\ /bin/bash ./libtool --tag=CC --mode=compile gcc -DHAVE_CONFIG_H -I. -I../../../../../js/src/ctypes/libffi -I. -I../../../../../js/src/ctypes/libffi/include -Iinclude -I../../../../../js/src/ctypes/libffi/src -Wall -g -fexceptions -O2 -MT src/prep_cif.lo -MD -MP -MF $depbase.Tpo -c -o src/prep_cif.lo ../../../../../js/src/ctypes/libffi/src/prep_cif.c &&\ mv -f $depbase.Tpo $depbase.Plo libtool: compile: gcc -DHAVE_CONFIG_H -I. -I../../../../../js/src/ctypes/libffi -I. -I../../../../../js/src/ctypes/libffi/include -Iinclude -I../../../../../js/src/ctypes/libffi/src -Wall -g -fexceptions -O2 -MT src/prep_cif.lo -MD -MP -MF src/.deps/prep_cif.Tpo -c ../../../../../js/src/ctypes/libffi/src/prep_cif.c -fPIC -DPIC -o src/prep_cif.o /home/gps/src/mozilla-central/obj-ff-debug/js/src/ctypes/libffi/Makefile:1035:0$ depbase=`echo src/types.lo | sed 's|[^/]*$|.deps/&|;s|\.lo$||'`;\ /bin/bash ./libtool --tag=CC --mode=compile gcc -DHAVE_CONFIG_H -I. -I../../../../../js/src/ctypes/libffi -I. -I../../../../../js/src/ctypes/libffi/include -Iinclude -I../../../../../js/src/ctypes/libffi/src -Wall -g -fexceptions -O2 -MT src/types.lo -MD -MP -MF $depbase.Tpo -c -o src/types.lo ../../../../../js/src/ctypes/libffi/src/types.c &&\ mv -f $depbase.Tpo $depbase.Plo
Wha!? I just built the tree! y u repeat compilation?
On Linux, when I trace PyMake, I find 5022 commands executed in total. Keep in mind these are only commands directly spun off from PyMake. The total does not include all fork()s, exec()s, etc. (I could probably find this using DTrace if I really wanted...)
The full breakdown of commands counts is as follows:
2677 /home/gps/src/mozilla-central/build/pymake/make.py 1638 nsinstall 364 /home/gps/src/mozilla-central/config/buildlist.py 72 /home/gps/src/mozilla-central/config/JarMaker.py 68 /home/gps/src/mozilla-central/config/pythonpath.py 61 /home/gps/src/mozilla-central/build/xpccheck.py 30 set 22 echo 18 rm 9 /home/gps/src/mozilla-central/config/Preprocessor.py 8 if 8 depbase=`echo 7 make 5 cp 5 (cd 4 /home/gps/src/mozilla-central/js/src/config/pythonpath.py 4 : 3 mv 2 /home/gps/src/mozilla-central/toolkit/xre/make-platformini.py 2 cd 2 ccache 2 cat 2 bash 1 tar 1 sed 1 ranlib 1 pymake.builtins 1 perl 1 /home/gps/src/mozilla-central/js/src/config/Preprocessor.py 1 /home/gps/src/mozilla-central/config/nsinstall.py 1 fail= 1 chmod
There is some noise in there. I hope to figure that out and clean it up in a future version.
If we look at the targets evaluated during a build on a built tree, I find 26032 unique targets with 5075 evaluated multiple times. Of those with multiple evaluation, the top 50 in terms of invocations are:
2613 /home/gps/src/mozilla-central/config/version.mk 2613 /home/gps/src/mozilla-central/config/static-checking-config.mk 2613 /home/gps/src/mozilla-central/config/rules.mk 2613 /home/gps/src/mozilla-central/config/config.mk 2613 /home/gps/src/mozilla-central/browser/app-rules.mk 2613 /home/gps/src/mozilla-central/browser/app-config.mk 2613 /config/myrules.mk 2613 /config/myconfig.mk 2613 /config/autoconf.mk 886 /dist/bin/chrome 295 /home/gps/src/mozilla-central/xpcom/idl-parser/xpidl.py 295 /home/gps/src/mozilla-central/xpcom/idl-parser/header.py 294 /home/gps/src/mozilla-central/xpcom/idl-parser/typelib.py 155 /home/gps/src/mozilla-central/ipc/chromium/chromium-config.mk 147 /dist/include 147 /dist/idl 48 /home/gps/src/mozilla-central/build/binary-location.mk 45 /nsprpub/config/autoconf.mk 45 /home/gps/src/mozilla-central/nsprpub/config/rules.mk 45 /home/gps/src/mozilla-central/nsprpub/config/config.mk 39 /home/gps/src/mozilla-central/toolkit/mozapps/installer/package-name.mk 36 /Makefile 36 /home/gps/src/mozilla-central/toolkit/toolkit-tiers.mk 36 /home/gps/src/mozilla-central/testing/testsuite-targets.mk 36 /home/gps/src/mozilla-central/config/nspr/build.mk 36 /home/gps/src/mozilla-central/config/js/build.mk 36 /home/gps/src/mozilla-central/browser/build.mk 35 /Makefile.in 25 /dist/lib/libxpcomglue_s.a.desc 20 /js/src/config/autoconf.mk 18 /js/src/config/myrules.mk 18 /js/src/config/myconfig.mk 18 /home/gps/src/mozilla-central/js/src/@MOZ_BUILD_APP@/app-rules.mk 18 /home/gps/src/mozilla-central/js/src/@MOZ_BUILD_APP@/app-config.mk 18 /home/gps/src/mozilla-central/js/src/config/version.mk 18 /home/gps/src/mozilla-central/js/src/config/static-checking-config.mk 18 /home/gps/src/mozilla-central/js/src/config/rules.mk 18 /home/gps/src/mozilla-central/js/src/config/config.mk 16 /home/gps/src/mozilla-central/nsprpub/config/prdepend.h 12 /widget/src/gtkxtbin/Makefile 12 /home/gps/src/mozilla-central/xpcom/glue/objs.mk 12 /home/gps/src/mozilla-central/build/automation-build.mk 12 /gfx/qcms/Makefile 9 /home/gps/src/mozilla-central/rdf/util/src/objs.mk 9 /home/gps/src/mozilla-central/intl/unicharutil/util/objs.mk 9 /dist/lib/libjs_static.a.desc 9 /browser/branding/nightly/Makefile 9 /browser/branding/nightly/locales/Makefile 8 /toolkit/xre/test/Makefile 8 /dist/sdk/lib
What does redundant target evaluation mean? Well, I can't make any hard or fast rules because I believe some redundant evaluation will occur as a result of parallel execution and due to the way Makefile processing works. But, I can say that any time a target is processes more than once, there is some extra work involved.
To boil it down, a build on a fully built tree does a lot of work. This work should be skipped because the tree is fully built. The good news is my tracing feature described above makes it pretty darn easy to isolate exact work performed. So, hopefully we can find the offenders and start fixing them.
