Closed Bug 782633 Opened 12 years ago Closed 12 years ago

Intermittent TEST-UNEXPECTED-FAIL | tab process nnn | automationutils.processLeakLog() | missing output line for total leaks!

Categories

(Testing :: Mochitest, defect)

x86_64
All
defect
Not set
normal

Tracking

(firefox18 wontfix, firefox19 fixed, firefox20 fixed, firefox-esr17 fixed, b2g18 fixed)

RESOLVED FIXED
mozilla21
Tracking Status
firefox18 --- wontfix
firefox19 --- fixed
firefox20 --- fixed
firefox-esr17 --- fixed
b2g18 --- fixed

People

(Reporter: emorley, Assigned: emorley)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Not really sure what to file this one as... Rev4 MacOSX Snow Leopard 10.6 mozilla-inbound debug test mochitests-2/5 on 2012-08-14 03:34:35 PDT for push 59707ed19e48 slave: talos-r4-snow-044 https://tbpl.mozilla.org/php/getParsedLog.php?id=14366225&tree=Mozilla-Inbound { [Parent 529] WARNING: not an nsIRDFRemoteDataSource: 'remote != nullptr', file ../../../../rdf/datasource/src/nsLocalStore.cpp, line 279 --DOMWINDOW == 1 (0x122d38ac0) [serial = 3] [outer = 0x0] [url = chrome://browser/content/hiddenWindow.xul] --DOMWINDOW == 0 (0x122d3b720) [serial = 4] [outer = 0x0] [url = chrome://browser/content/hiddenWindow.xul] [Parent 529] WARNING: not an nsIRDFRemoteDataSource: 'remote != nullptr', file ../../../../rdf/datasource/src/nsLocalStore.cpp, line 279 [Parent 529] WARNING: NS_ENSURE_TRUE(mTextInputHandler) failed: file ../../../widget/cocoa/nsChildView.mm, line 4070 nsStringStats => mAllocCount: 2302636 => mReallocCount: 106561 => mFreeCount: 2302636 => mShareCount: 4690847 => mAdoptCount: 208698 => mAdoptFreeCount: 208698 INFO | automation.py | Application ran for: 0:18:35.995106 INFO | automation.py | Reading PID log: /var/folders/Hs/HsDn6a9SG8idoIya6p9mtE+++TI/-Tmp-/tmpUiWBqXpidlog == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 529 |<----------------Class--------------->|<-----Bytes------>|<----------------Objects---------------->|<--------------References-------------->| Per-Inst Leaked Total Rem Mean StdDev Total Rem Mean StdDev 0 TOTAL 22 0 130053207 0 (37632.00 +/- 71412.98) 297676800 18446744073709551614 (61969108727.09 +/- 0.00) nsTraceRefcntImpl::DumpStatistics: 1299 entries TEST-PASS | automationutils.processLeakLog() | no leaks detected! TEST-UNEXPECTED-FAIL | tab process 555 | automationutils.processLeakLog() | missing output line for total leaks! == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 558 |<----------------Class--------------->|<-----Bytes------>|<----------------Objects---------------->|<--------------References-------------->| Per-Inst Leaked Total Rem Mean StdDev Total Rem Mean StdDev 0 TOTAL 30 0 62013 0 ( 1012.43 +/- 1195.63) 93059 0 ( 1191.63 +/- 2479.43) nsTraceRefcntImpl::DumpStatistics: 540 entries TEST-PASS | tab process 558 | automationutils.processLeakLog() | no leaks detected! == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, tab process 559 |<----------------Class--------------->|<-----Bytes------>|<----------------Objects---------------->|<--------------References-------------->| Per-Inst Leaked Total Rem Mean StdDev Total Rem Mean StdDev 0 TOTAL 19 0 7066748 0 ( 3373.42 +/- 1878.13) 4719591 0 ( 1271.50 +/- 2913.44) nsTraceRefcntImpl::DumpStatistics: 745 entries TEST-PASS | tab process 559 | automationutils.processLeakLog() | no leaks detected! INFO | runtests.py | Running tests: end. program finished with exit code 0 }
Summary: Intermittent TEST-UNEXPECTED-FAIL | tab process 555 | automationutils.processLeakLog() | missing output line for total leaks! → Intermittent TEST-UNEXPECTED-FAIL | tab process nnn | automationutils.processLeakLog() | missing output line for total leaks!
vporof, bbondy, paul: The starrings you made via TBPL above were mis-stars. Whilst this bug gets suggested quite a bit of the time, the case to which it refers will never be able to be picked up by the tbpl parser - it always requires manual starring. Please check when starring on TBPL that the full summary matches (in this case, the "tab process nnn" part is key) - since mis-stars can obscure real failures. Thanks! :-)
Whiteboard: [orange]
https://tbpl.mozilla.org/php/getParsedLog.php?id=17369860&tree=Try The problem here is that we don't "join" all content processes on shutdown, i.e. wait for them to terminate. And, not surprisingly, sometimes they don't shut down before the parent process does.
Can we do that for debug builds only? That's the only place we're doing leak checks anyway.
Oh, golly, yes. I didn't mean to even suggest anything otherwise :).
Chris, I don't suppose you'd be able to try making the change you suggested in comment 160 - this has become pretty frequent on TBPL now (and currently requires manual starring, so is time consuming for sheriffs + confusing for devs using Try etc). Cheers :-)
Flags: needinfo?(jones.chris.g)
Luckily the mechanism we need from this is coming, so hopefully in the near future.
Depends on: 821192
Flags: needinfo?(jones.chris.g)
(In reply to Chris Jones [:cjones] [:warhammer] from comment #255) > Luckily the mechanism we need from this is coming, so hopefully in the near > future. Now that bug 821192 has landed, could I ask a massive favour and get you to finish off the necessary work here? :-)
Flags: needinfo?(jones.chris.g)
Bug 821192 ended up not providing the fix for this, unfortunately :/.
Flags: needinfo?(jones.chris.g)
Depends on: 828239
(Sent via email to auto-tools@, posting here so everyone can see it): On desktop TBPL unit test runs, automationutils.processSingleLeakFile() currently checks for the presence of a leak log, and gives a "TEST-UNEXPECTED-FAIL %s| automationutils.processLeakLog() | missing output line for total leaks!"" if one is not found: http://mxr.mozilla.org/mozilla-central/source/build/automationutils.py#387 As it is currently implemented, this causes several problems: 1) WhilstprocessSingleLeakFile() checks for purposeful crashes (http://mxr.mozilla.org/mozilla-central/source/build/automationutils.py#329), if we have an unexpected crash (eg intermittent crashes seen on TBPL) the TBPL annotated summary output includes both the PROCESS-CRASH line and the "missing output line for total leaks!" line. From my first glance, there doesn't seem to be an easy way for processSingleLeakFile() to tell if there was a PROCESS-CRASH since it won't be present in the leak log (and the callers of processLeakLog() don't have any idea as to crash state either). 2) Content processes are not always fully shutdown before the parent is, causing bug 782633, which is both not-automatically starable (so time consuming for sheriffs) & of late, pretty frequent. My initial though was to adjust the failure string so that it would be TBPL-starable (bug 828239), however this: a) Doesn't resolve #1. b) Still means we have a frequent intermittent failure bug that there doesn't appear to be much platform interest in fixing. As an alternative, would anyone object to me s/TEST-UNEXPECTED-FAIL/WARNING/ so this isn't a fatal failure (at least until bug 782633 is resolved)?
Attached patch Patch v1 (deleted) — Splinter Review
No objections to the email/bug comment, so just going to do this to stop me being driven nuts by this failure.
Assignee: nobody → emorley
Status: NEW → ASSIGNED
Attachment #701201 - Flags: review?(ted)
Note: Happy to file a followup for someone to fix this for real & fix the false positive for PROCESS-CRASHes and revert back to TEST-UNEXPECTED-FAIL when done.
Comment on attachment 701201 [details] [diff] [review] Patch v1 Review of attachment 701201 [details] [diff] [review]: ----------------------------------------------------------------- I guess the only thing we'd miss out on here is if a child process failed to write a leak log, right?
Attachment #701201 - Flags: review?(ted) → review+
https://tbpl.mozilla.org/php/getParsedLog.php?id=18746404&tree=Mozilla-Inbound Traceback (most recent call last): File "/home/cltbld/talos-slave/test/build/mochitest/runtests.py", line 960, in <module> main() File "/home/cltbld/talos-slave/test/build/mochitest/runtests.py", line 957, in main sys.exit(mochitest.runTests(options)) File "/home/cltbld/talos-slave/test/build/mochitest/runtests.py", line 751, in runTests processLeakLog(self.leak_report_file, options.leakThreshold) File "/home/cltbld/talos-slave/test/build/mochitest/automationutils.py", line 419, in processLeakLog processSingleLeakFile(thisFile, processPID, processType, leakThreshold) File "/home/cltbld/talos-slave/test/build/mochitest/automationutils.py", line 388, in processSingleLeakFile processString) TypeError: not all arguments converted during string formatting
Bah I'm an idiot. Followup to fix: https://tbpl.mozilla.org/php/getParsedLog.php?id=18746404&tree=Mozilla-Inbound { Traceback (most recent call last): File "/home/cltbld/talos-slave/test/build/mochitest/runtests.py", line 960, in <module> main() File "/home/cltbld/talos-slave/test/build/mochitest/runtests.py", line 957, in main sys.exit(mochitest.runTests(options)) File "/home/cltbld/talos-slave/test/build/mochitest/runtests.py", line 751, in runTests processLeakLog(self.leak_report_file, options.leakThreshold) File "/home/cltbld/talos-slave/test/build/mochitest/automationutils.py", line 419, in processLeakLog processSingleLeakFile(thisFile, processPID, processType, leakThreshold) File "/home/cltbld/talos-slave/test/build/mochitest/automationutils.py", line 388, in processSingleLeakFile processString) TypeError: not all arguments converted during string formatting } https://hg.mozilla.org/integration/mozilla-inbound/rev/d8599591d07c
Depends on: 831223
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: