913880 - "ac_add_options --disable-debug-symbols" breaks build with "Memory Error"

Status: RESOLVED WORKSFORME

(Firefox Build System :: General, defect)

Description

[Avi Halachmi (:avih)]

Using m-c from yesterday (cset 146034:3697f962bb7b), and probably a day or two before as well, if .mozconfig contains "add_ac_options --disable-debug-symbols", then the |./mach build| aborts towards the end with "Memory error", and without creating firefox.exe.

This was consistent in several .mozconfig configurations which I tried (with/out webrtc etc), including a .mozconfig file which contains a single line to disables debug symbols (failed with memory error) and without a .mozconfig file (build succeeded).

My system is Windows 7 x64 home premium. i7-3630qm (8 logical cores, 4 phys), 16G ram, very stable in general, and had no issue compiling Firefox until today (been using it for about a year).

This happens with MozillaBuild 1.8 (python 2.7.5) but also when I went back to 1.7 with python 2.7.4 (though the actual narrowing down process was with 1.8).

The compiler is:
Microsoft Visual Studio 2010
Version 10.0.40219.1 SP1Rel
Microsoft .NET Framework
Version 4.0.30319 SP1Rel

These are the last log lines:
---------------------------
entral/obj-i686-pc-mingw32/dist/include/xpcom-config.h:']
32:19.98 No rule to make target 'e:/dev/moz/src/central/xpcom/ds/nsCRT.h:' needed by ['<command-line>', 'e:/dev/moz/src/central/xpcom/ds/nsCRT.h:']
32:19.98 No rule to make target 'e:/dev/moz/src/central/obj-i686-pc-mingw32/dist/include/string-template-undef.h:' needed by ['<command-line>', 'e:/dev/moz/src/central/obj-i686-pc-mingw32/dist/include/string-template-undef.h:']
32:24.38 jsdombase_s.lib.desc
32:25.16 No rule to make target 'e:/dev/moz/src/central/obj-i686-pc-mingw32/dist/include/xrecore.h:' needed by ['<command-line>', 'e:/dev/moz/src/central/obj-i686-pc-mingw32/dist/include/xrecore.h:']
32:25.25 dom_activities_s.lib.desc
34:26.90 Traceback (most recent call last):
34:26.90   File "e:/dev/moz/src/central/build/pymake/make.py", line 28, in <module>
34:26.90     pymake.process.ParallelContext.spin()
34:26.90 MemoryError
Single process terminated successfully
34:29.10 971 compiler warnings present.
---------------------------

When observing the processes tree just before it aborts, it looks like this:

env.exe              "c:\mozilla-build\msys\bin\env.exe"
- python.exe          c:\mozilla-build\python\python.exe ./mach build
  - sh.exe            c:/mozilla-build/msys/bin/sh.exe -c "c:/mozilla-build/python/python.exe e:/dev/moz/src/central/build/pymake/make.py -f client.mk -s"
    - python.exe  **  c:\mozilla-build\python\python.exe e:/dev/moz/src/central/build/pymake/make.py -f client.mk -s
      - python.exe   "c:\mozilla-build\python\python.exe" "-c" "from multiprocessing.forking inport main; main" "--multiprocessing-fork" "588"
      - python.exe   "c:\mozilla-build\python\python.exe" "-c" "from multiprocessing.forking inport main; main" "--multiprocessing-fork" "656"
      - python.exe   "c:\mozilla-build\python\python.exe" "-c" "from multiprocessing.forking inport main; main" "--multiprocessing-fork" "648"
      - ... (5 more python processes here for 8 overall)

Where the ** python process is very close to using 2G ram (1.99). This process tree doesn't change during the last 10s or so, except for the ** process going up in RAM usage from about 100M to 2G, and few seconds later the build fails with the memory error.

Comment 1

[Avi Halachmi (:avih)]

Nit: the last level processes look like this (the last 'main' has '()'):

python.exe   "c:\mozilla-build\python\python.exe" "-c" "from multiprocessing.forking inport main; main()" "--multiprocessing-fork" "588"

Comment 2

[Gregory Szorc [:gps]]

This quacks like a pymake bug. Only bug 912846 (c265760f8b9b) and bug 912971 (ef653664ef98) touched pymake recently. Can you try backing those out to see if the problem goes away? Of those, I'd start with c265760f8b9b.

Comment 3

[Gregory Szorc [:gps]]

Also, are you absolutely sure this is isolated to --disable-debug-symbols. I find it hard to believe the pymake process's memory usage varies because of that.

Comment 4

[Avi Halachmi (:avih)]

I'll try to backout the patches.

Can't be sure that it's not some weird combination of configs, but my bisection points towards --disable-debug-symbols. These are the .mozconfig which I tried, with their build results:

-------------------------------------------------------------------

Good (40 mins):

[no mozconfig]

-------------------------------------------------------------------

Memory Error (32 mins):

########ac_add_options --disable-update-packaging
########ac_add_options --enable-jemalloc
########ac_add_options --enable-signmar
########ac_add_options --enable-profiling
########ac_add_options --enable-js-diagnostics
########export MOZILLA_OFFICIAL=1
########export MOZ_TELEMETRY_REPORTING=1
export MOZ_PACKAGE_JSSHELL=0
ac_add_options --disable-webrtc
ac_add_options --disable-crashreporter
#ac_add_options --enable-debug-symbols
ac_add_options --disable-debug-symbols
#ac_add_options --disable-optimize
ac_add_options --enable-optimize
ac_add_options --enable-tests
mk_add_options AUTOCLOBBER=1

-------------------------------------------------------------------

memory error (34 mins):

ac_add_options --disable-update-packaging
ac_add_options --enable-jemalloc
ac_add_options --enable-signmar
ac_add_options --enable-profiling
ac_add_options --enable-js-diagnostics
export MOZILLA_OFFICIAL=1
export MOZ_TELEMETRY_REPORTING=1
export MOZ_PACKAGE_JSSHELL=0
########ac_add_options --disable-webrtc
########ac_add_options --disable-crashreporter
ac_add_options --disable-debug-symbols
#ac_add_options --disable-optimize
ac_add_options --enable-optimize
#avih - disable tests for faster build, but needs rebuild if want tests
#ac_add_options --disable-tests
ac_add_options --enable-tests
mk_add_options AUTOCLOBBER=1

-------------------------------------------------------------------

Good (39 mins):

ac_add_options --disable-update-packaging
ac_add_options --enable-jemalloc
ac_add_options --enable-signmar
ac_add_options --enable-profiling
ac_add_options --enable-js-diagnostics
export MOZILLA_OFFICIAL=1
export MOZ_TELEMETRY_REPORTING=1
export MOZ_PACKAGE_JSSHELL=0
########ac_add_options --disable-webrtc
########ac_add_options --disable-crashreporter
########ac_add_options --disable-debug-symbols
########ac_add_options --enable-optimize
ac_add_options --enable-tests
mk_add_options AUTOCLOBBER=1

-------------------------------------------------------------------

Memory error (32 mins):

ac_add_options --disable-update-packaging
ac_add_options --enable-jemalloc
ac_add_options --enable-signmar
ac_add_options --enable-profiling
ac_add_options --enable-js-diagnostics
export MOZILLA_OFFICIAL=1
export MOZ_TELEMETRY_REPORTING=1
export MOZ_PACKAGE_JSSHELL=0
ac_add_options --disable-webrtc
ac_add_options --disable-crashreporter
ac_add_options --disable-debug-symbols
#ac_add_options --disable-optimize
########ac_add_options --enable-optimize
ac_add_options --enable-tests
mk_add_options AUTOCLOBBER=1

-------------------------------------------------------------------

Memory error (34 mins):

ac_add_options --disable-update-packaging
ac_add_options --enable-jemalloc
ac_add_options --enable-signmar
ac_add_options --enable-profiling
ac_add_options --enable-js-diagnostics
export MOZILLA_OFFICIAL=1
export MOZ_TELEMETRY_REPORTING=1
export MOZ_PACKAGE_JSSHELL=0
########ac_add_options --disable-webrtc
ac_add_options --disable-crashreporter
ac_add_options --disable-debug-symbols
ac_add_options --enable-optimize
ac_add_options --enable-tests
mk_add_options AUTOCLOBBER=1

--------------------------------------

Good (37 mins):

ac_add_options --disable-update-packaging
ac_add_options --enable-jemalloc
ac_add_options --enable-signmar
ac_add_options --enable-profiling
ac_add_options --enable-js-diagnostics
export MOZILLA_OFFICIAL=1
export MOZ_TELEMETRY_REPORTING=1
export MOZ_PACKAGE_JSSHELL=0
ac_add_options --disable-webrtc
ac_add_options --disable-crashreporter
########ac_add_options --disable-debug-symbols
ac_add_options --enable-optimize
ac_add_options --enable-tests
mk_add_options AUTOCLOBBER=1

-------------------------------------------------------------------

Memory error (34 mins):

ac_add_options --disable-debug-symbols

--------------------------------------

Comment 5

[Mike Hommey [:glandium]]

ISTR pymake has some memory leaking issues. Bug 912846 could have made the situation worse.

Comment 6

[Avi Halachmi (:avih)]

I'd appreciate if someone could try to reproduce this.

So far I've reverted the MRU cache from 50 back to 15, and with --disable-debug-symbols it had the same memory error.

Now retrying after also reverting the stripdotslash thingy. Will update once it finishes.

Comment 7

[Avi Halachmi (:avih)]

Same symptoms and memory error with both patches reverted.

I guess I could go to a week old m-c revision and retry. Though if someone else can reproduce this, then at least I'll be less worried that it's a system issue on my side...

Comment 8

[Mike Hommey [:glandium]]

Could be bug 912832, then. But there are subsequent patches that depend on it.

Comment 9

[Gregory Szorc [:gps]]

I'm knee deep into the compile-platform tier and the main pymake process is holding steady around 63 MB. Although I am running on OS X. Being Python, it shouldn't make a difference. Although, multiprocessing could be doing something wonky...

Comment 10

[Gregory Szorc [:gps]]

Just built on Windows and I'm not seeing this :/

Comment 11

[Avi Halachmi (:avih)]

So far bisected to:

BAD (34 mins)
changeset:   145810:8b4a47eb1217
user:        Jonathan Griffin <[e-mail]>
date:        Thu Sep 05 17:36:16 2013 -0700
summary:     Bug 908356 - In-tree reuqirements files for marionette and mozbase, r=aki


Good (31 mins)
changeset:   145794:cd2e84ff64dd
user:        David Dahl <[e-mail]>
date:        Thu Sep 05 18:18:04 2013 -0500
summary:     Bug 882467 - Mixed Content Telemetry - How many times do users click Disable Protection r=dolske

Still bisecting.

Comment 12

[Avi Halachmi (:avih)]

Attachment: process mem usage graph

So it's bug 912856 and this push:
https://hg.mozilla.org/mozilla-central/rev/2375fae8e78f

The bisection was consistent and I also tested this revision and the one just before it. This revision and all the following ones which I tested (a lot) fail with the memory error, and all the prior ones (also tested a lot) succeed, all with --disable-debug-symbols.

At the attached image (of the same ** python process from comment 0) you'll see that the relatively high mem usage with big spikes lasts about 4 mins, and it's while doing the *.lib.desc items, and it always fail while the console shows dom_activities_s.lib.desc .

I'm not sure what else I can test or what more info I could provide or otherwise debug this issue... any suggestion for what's next would be appreciated.

Comment 13

[Avi Halachmi (:avih)]

And it's happening at the end of the build, but before firefox.exe is created. The previous revisions take about 32 mins to build succesfully, and the memory error on this revision onwards happens after about 33-34 mins.

Comment 14

[Mike Hommey [:glandium]]

I can reproduce some memory suckage in a limited way, while building the .desc files. Memory usage was steadily around 50MB during compilation, and jumped in 3 or 4 steps up to 200MB while doing make libs.

Comment 15

[Mike Hommey [:glandium]]

As discussed on irc with Avi, the patch from bug 914935 makes things at least go until the end of the build. Avi is going to check how memory usage evolved.

Comment 16

[Avi Halachmi (:avih)]

(In reply to Mike Hommey [:glandium] from comment #15)
> As discussed on irc with Avi, the patch from bug 914935 makes things at
> least go until the end of the build. Avi is going to check how memory usage
> evolved.

I tested with the first bad revision.

With this patch, the same ** python process is quite flat at 35M +- 5M for most of the build. At some stage when processing the .desc files towards the end - it went up once to 105M, settled back to 50m after 10s, and after another 40s got back to around 40M and stayed that way until the build finished successfully.

A bit off topic, but this revision is about a minute slower to finish the build with my .mozconfig file, which is about 3% slower.

Comment 17

[Mike Hommey [:glandium]]

(In reply to Avi Halachmi (:avih) from comment #16)
> A bit off topic, but this revision is about a minute slower to finish the
> build with my .mozconfig file, which is about 3% slower.

Do you mean changeset 2375fae8e78f is 1 minute slower than changeset 0c3e37bb0973? If so, that's expected. That's a minute bug 911902 should have reclaimed. (And bug 912846, landed before bug 912856, should have made it 3 to 5 minutes faster)

Comment 18

[Avi Halachmi (:avih)]

Bug 914935 fixed this.

Comment 19

[Nathan Froyd [:froydnj]]

No reason for secrecy.

Comment 20

[Avi Halachmi (:avih)]

Yeah, was just about to fix this. Don't know how it got checked, as I wasn't anywhere near it.. oh well..