Closed Bug 730196 Opened 14 years ago Closed 14 years ago

Frequent Windows build timeouts during make_pkg or make package pretty buildstep, often with a "--- Press `Q' to quit, or any other key to continue ---" prompt

Categories

(Core :: General, defect)

Product:
Core
Component:
General
Platform:
x86
Windows Server 2003
Type:
defect
Priority:
Not set
Severity:
critical

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla14
Tracking Flags:
Tracking Status
firefox13 --- fixed

People

(Reporter: philor, Assigned: froydnj)

References

Details

(Keywords: intermittent-failure, Whiteboard: [qa-])

Attachments

(1 file)

patch
1.19 KB, patch
ted
: review+
johnath
: approval-mozilla-aurora+
Details | Diff | Splinter Review
Six of one whether this is releng, or packaging. Personally, I'm betting on some Windows zip limitation. https://tbpl.mozilla.org/php/getParsedLog.php?id=9584873&tree=Firefox WINNT 5.2 mozilla-central pgo-build on 2012-02-23 18:00:09 PST for push 6fe899b9b372 Compressing... cd ../../dist && (cd firefox && rm -f omni.ja components/binary.manifest && grep -h '^binary-component' components/*.manifest > binary.manifest ; for m in components/*.manifest; do sed -e 's/^binary-component/#binary-component/' $m > tmp.manifest && mv tmp.manifest $m; done; zip -r9m omni.ja chrome chrome.manifest components/*.js components/*.xpt components/*.manifest modules res defaults greprefs.js jsloader hyphenation update.locale -x chrome/icons/\* defaults/pref/channel-prefs.js res/cursors/\* res/MainMenu.nib/\* && e:/builds/moz2_slave/m-cen-w32-pgo/build/obj-firefox/dist/bin/xpcshell.exe -g "$PWD" -a "$PWD" -f /e/builds/moz2_slave/m-cen-w32-pgo/build/toolkit/mozapps/installer/precompile_cache.js -e "populate_startupcache('GreD', 'omni.ja', 'startupCache.zip');" && rm -rf jsloader && unzip startupCache.zip && rm startupCache.zip && zip -r9m omni.ja jsloader/resource/gre && d:/mozilla-build/python25/python2.5.exe /e/builds/moz2_slave/m-cen-w32-pgo/build/config/optimizejars.py --optimize /e/builds/moz2_slave/m-cen-w32-pgo/build/obj-firefox/browser/installer/../../jarlog//en-US ./ ./ && mv binary.manifest components && printf "manifest components/binary.manifest\n" > chrome.manifest) && (cd firefox && d:/mozilla-build/python25/python2.5.exe /e/builds/moz2_slave/m-cen-w32-pgo/build/config/createprecomplete.py) && zip -r9D win32/en-US/nightly-13.0a1.zip firefox ... adding: update.locale (188 bytes security) (stored 0%) <-- where most of them die ... Archive: startupCache.zip �\Q --- Press `Q' to quit, or any other key to continue --- command timed out: 1200 seconds without output, attempting to kill We had six or eight of them on inbound yesterday, so I hounded a probably-guiltless patch out of the tree, then we had two more overnight, and now this one (first PGO I remember, the previous ones were split among Win32 opt and debug and Win64 opt). Unfortunately, we're going to have a Mexican standoff between releng and build over who should figure out what is happening, because nobody's going to want to sit watching a slave make package over and over until it happens.
That was w32-ix-slave27 (and possibly the only one that was in make package pretty rather than make_pkg, or possibly make package pretty is a PGO thing). https://tbpl.mozilla.org/php/getParsedLog.php?id=9584748&tree=Mozilla-Inbound - w32-ix-slave30 https://tbpl.mozilla.org/php/getParsedLog.php?id=9560154&tree=Mozilla-Inbound - w32-ix-slave26 https://tbpl.mozilla.org/php/getParsedLog.php?id=9549136&tree=Mozilla-Inbound - w64-ix-slave15 https://tbpl.mozilla.org/php/getParsedLog.php?id=9542348&tree=Mozilla-Inbound - w32-ix-slave40 https://tbpl.mozilla.org/php/getParsedLog.php?id=9541533&tree=Mozilla-Inbound - w32-ix-slave25 https://tbpl.mozilla.org/php/getParsedLog.php?id=9538661&tree=Mozilla-Inbound - w32-ix-slave44 so it doesn't look at all good for blame-the-slave.
Summary: Frequent Windows build timeouts during make package pretty buildstep, often with a "--- Press `Q' to quit, or any other key to continue ---" prompt → Frequent Windows build timeouts during make_pkg or make package pretty buildstep, often with a "--- Press `Q' to quit, or any other key to continue ---" prompt
At first, even though I wanted to blame optimizejars.py, I believed mak that the timing didn't work. However, bug 726656 landed on m-c on the 17th, so m-i then or maybe the 18th, either way I took last weekend off, and it's purple: we ignore purple. It could easily have happened ten or twenty times between last Friday/Saturday and yesterday's explosion without anyone ever paying it any real mind. With any "luck" whatever broke during the time it wasn't working is also broken on m-a and m-b, and we'll get confirmation by them starting to fail too, though something only intermittent on our most-coalesced builds may take time to show up on branches like those that don't do many builds. First shot fired :) <nthomas>: I feel a slave loan coming on
Blocks: 726656
https://tbpl.mozilla.org/php/getParsedLog.php?id=9618613&tree=Mozilla-Inbound went a bit longer - the usual is stopping at the "adding: update.locale (188 bytes security) (stored 0%)" point, at the end of zipping up apparently, since this one continued on to WARNING: CheckLinkStatus called on main thread! No check performed. Assuming link is up, status is unknown.: file e:/builds/moz2_slave/m-in-w32-dbg/build/netwerk/system/win32/nsNotifyAddrListener.cpp, line 414 resource:///components/txEXSLTRegExFunctions.js ... resource:///modules/CSPUtils.jsm WARNING: nsExceptionService ignoring thread destruction after shutdown: file e:/builds/moz2_slave/m-in-w32-dbg/build/xpcom/base/nsExceptionService.cpp, line 199 WARNING: NS_ENSURE_TRUE(mMainThread) failed: file e:/builds/moz2_slave/m-in-w32-dbg/build/xpcom/threads/nsThreadManager.cpp, line 292 WARNING: NS_ENSURE_TRUE(thread) failed: file e:/builds/moz2_slave/m-in-w32-dbg/build/obj-firefox/xpcom/build/nsThreadUtils.cpp, line 181 WARNING: NS_ENSURE_TRUE(thread) failed: file e:/builds/moz2_slave/m-in-w32-dbg/build/obj-firefox/xpcom/build/nsThreadUtils.cpp, line 181 WARNING: NS_ENSURE_TRUE(mMainThread) failed: file e:/builds/moz2_slave/m-in-w32-dbg/build/xpcom/threads/nsThreadManager.cpp, line 283 WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file e:/builds/moz2_slave/m-in-w32-dbg/build/obj-firefox/xpcom/build/nsThreadUtils.cpp, line 168 nsStringStats => mAllocCount: 17261 => mReallocCount: 1595 => mFreeCount: 17261 => mShareCount: 17419 => mAdoptCount: 2410 => mAdoptFreeCount: 2410 Archive: startupCache.zip Pú --- Press `Q' to quit, or any other key to continue --- command timed out: 1200 seconds without output, attempting to kill so one zip file later.
And, oddly enough, the build I started locally at about that time, on OS X, stopped at exactly that point too. I couldn't think of anything useful to do to diagnose it (other than to note that the terminal tab said I was running unzip), so I pressed the any key, and it happily continued packaging.
https://tbpl.mozilla.org/php/getParsedLog.php?id=9637948&tree=Firefox If you cause the mozilla-central nightly to fail, your severity is something other than "normal."
Severity: normal → blocker
https://hg.mozilla.org/integration/mozilla-inbound/rev/8937b91b8435 shows up as suspect after a bunch of bisecting
Severity: major → trivial
https://tbpl.mozilla.org/php/getParsedLog.php?id=9813395&tree=Mozilla-Inbound That's a pretty crazy thing to be sending unzip into spewing bits to the terminal.
Severity: trivial → normal
I can reproduce it here: https://tbpl.mozilla.org/?tree=Try&rev=80230f9c3fc8 (based on 8937b91b8435) but not here: https://tbpl.mozilla.org/?tree=Try&rev=1ba37a8e8b98 (based on 8ca3fd79d50c)
Severity: critical → trivial
stupid bugzilla
Severity: trivial → critical
after more retrying, looks like 8ca3fd79d50c also fails...which shifts the blame onto https://hg.mozilla.org/integration/mozilla-inbound/rev/8ca3fd79d50c
CC' gavin as assignee of bug 729767.
(In reply to Chris AtLee [:catlee] from comment #74) > after more retrying, looks like 8ca3fd79d50c also fails...which shifts the > blame onto > https://hg.mozilla.org/integration/mozilla-inbound/rev/8ca3fd79d50c That would surprise me. I think we should try backing out the omnijar ordering thing and seeing if that fixes the problem.
* All the errors occur in the 'make installer' step, ending with Archive: startupCache.zip <some binary data> --- Press `Q' to quit, or any other key to continue --- command timed out: 1200 seconds without output, attempting to kill * the relevant code is http://mxr.mozilla.org/mozilla-central/source/toolkit/mozapps/installer/packager.mk#486 (CC mhommey) * it affects both win32 and win64 compile jobs; pgo, non-pgo and debug Possible regressors: * bug 726656 started optimizing jars again at https://hg.mozilla.org/mozilla-central/rev/f88a05e00f47. This was broken by renaming omni.jar to omni.ja (bug 701875) at https://hg.mozilla.org/mozilla-central/rev/3f0b94325b80, some two months earlier * there were a five landings in startupCache/ on Feb. 22nd from bug 711297 The latter fits pretty well and is going to be much simpler to investigate, so throwing this over to froydnj to do that. If RelEng can help out with access to a windows machine you have only to ask.
Assignee: nobody → nfroyd
Blocks: 711297
(In reply to Nick Thomas [:nthomas] from comment #102) > * All the errors occur in the 'make installer' step, ending with > Archive: startupCache.zip > <some binary data> > --- Press `Q' to quit, or any other key to continue --- > command timed out: 1200 seconds without output, attempting to kill > > * there were a five landings in startupCache/ on Feb. 22nd from bug 711297 This looks like unzip is attempting to print out the binary data we stash in the zipfile comment, which is not going to end well. Fixing that is easy enough.
Attached patch patch — — Splinter Review
Add -q when unzipping the startupCache.zip file so we don't print the binary data in the comment field.
Attachment #604967 - Flags: review?(ted.mielczarek)
Whiteboard: [orange] → [orange][autoland-try:-b do -p all -u none -t none]
Whiteboard: [orange][autoland-try:-b do -p all -u none -t none] → [orange][autoland-in-queue]
Comment on attachment 604967 [details] [diff] [review] patch Review of attachment 604967 [details] [diff] [review]: ----------------------------------------------------------------- Is there a reason this only happens intermittently? Does the data we jam into the comment field change, so it only causes failures sometimes? ::: toolkit/mozapps/installer/packager.mk @@ +479,5 @@ > PRECOMPILE_RESOURCE=gre > PRECOMPILE_GRE=$$PWD > endif > > +# Silence the unzip step so we don't print any binary data from the comment field. This comment would probably fit better right above the unzip line itself.
Attachment #604967 - Flags: review?(ted.mielczarek) → review+
Autoland Patchset: Patches: 604967 Branch: mozilla-central => try Destination: http://hg.mozilla.org/try/pushloghtml?changeset=be056fdb0132 Try run started, revision be056fdb0132. To cancel or monitor the job, see: https://tbpl.mozilla.org/?tree=Try&rev=be056fdb0132
(In reply to Ted Mielczarek [:ted] from comment #108) > Is there a reason this only happens intermittently? Does the data we jam > into the comment field change, so it only causes failures sometimes? We're stuffing an 8-byte timestamp in there; presumably the bytes in the timestamp every so often cause heartache for the Windows shell (cmd.exe?) when it's trying to decode them. > > +# Silence the unzip step so we don't print any binary data from the comment field. > > This comment would probably fit better right above the unzip line itself. Duly noted. I wasn't sure that'd work, but I guess that's what try is for!
(In reply to Nathan Froyd (:froydnj) from comment #110) > We're stuffing an 8-byte timestamp in there; presumably the bytes in the > timestamp every so often cause heartache for the Windows shell (cmd.exe?) > when it's trying to decode them. Ah, that makes sense. > > This comment would probably fit better right above the unzip line itself. > > Duly noted. I wasn't sure that'd work, but I guess that's what try is for! The pedantically-correct way to do this is to put the # at the left margin, so it gets parsed as a Makefile comment, but I'm not 100% sure how that works inside a continuation. You might need to just have <tab># blah \ to get it to parse properly. Or it's possible that that just won't parse and you have to live with what you have.
(In reply to Ted Mielczarek [:ted] from comment #111) > The pedantically-correct way to do this is to put the # at the left margin, > so it gets parsed as a Makefile comment, but I'm not 100% sure how that > works inside a continuation. You might need to just have <tab># blah \ to > get it to parse properly. Or it's possible that that just won't parse and > you have to live with what you have. Try (windows only) seems to indicate this doesn't work: https://tbpl.mozilla.org/?tree=Try&rev=dbeb08eb7573 I'm just going to call the current comment-not-quite-close-to-code version good enough.
Try looks good (green builds for almost all major platforms), so marking checkin-needed.
Keywords: checkin-needed
I needed to rebuild the windows builds on try 6 or 7 times to make sure it wasn't still happening. Can you do that?
(In reply to Chris AtLee [:catlee] from comment #114) > I needed to rebuild the windows builds on try 6 or 7 times to make sure it > wasn't still happening. Can you do that? Pushed a 3rd attempt to try: https://tbpl.mozilla.org/?tree=Try&rev=cdab92f07ac7 which along with an earlier windows-only run: https://tbpl.mozilla.org/?tree=Try&rev=b58312ae711d and the autoland run is three runs, at least. I'm pretty confident this will fix things, though.
(In reply to Nathan Froyd (:froydnj) from comment #116) > (In reply to Chris AtLee [:catlee] from comment #114) > > I needed to rebuild the windows builds on try 6 or 7 times to make sure it > > wasn't still happening. Can you do that? > > Pushed a 3rd attempt to try: > > https://tbpl.mozilla.org/?tree=Try&rev=cdab92f07ac7 You know you can trigger rebuilds via tbpl, right? Click on the win32 opt/debug build, and on the bottom left pane there will be a blue plus icon. Click that to re-trigger it.
(In reply to Chris AtLee [:catlee] from comment #117) > You know you can trigger rebuilds via tbpl, right? Click on the win32 > opt/debug build, and on the bottom left pane there will be a blue plus icon. > Click that to re-trigger it. I am enlightened. Thanks!
Try run for be056fdb0132 is complete. Detailed breakdown of the results available here: https://tbpl.mozilla.org/?tree=Try&rev=be056fdb0132 Results (out of 16 total builds): success: 16 Builds (or logs if builds failed) available at: http://ftp.mozilla.org/pub/mozilla.org/firefox/try-builds/autolanduser@mozilla.com-be056fdb0132
Whiteboard: [orange][autoland-in-queue] → [orange]
(In reply to Chris AtLee [:catlee] from comment #114) > I needed to rebuild the windows builds on try 6 or 7 times to make sure it > wasn't still happening. Can you do that? https://tbpl.mozilla.org/?tree=Try&rev=b58312ae711d says that we've been green for about that many builds with the patch. WDYT?
LGTM
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/c7d9848ffff5
Status: NEW → RESOLVED
Closed: 14 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla14
Attachment #604967 - Flags: approval-mozilla-aurora?
Attachment #604967 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Whiteboard: [orange] → [orange][qa-]
Whiteboard: [orange][qa-] → [qa-]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: