Closed Bug 1045255 Opened 6 years ago Closed 6 years ago

There's no leak logging

Categories

(Testing :: General, defect)

defect
Not set

Tracking

(firefox32 unaffected, firefox33 fixed, firefox34 fixed)

RESOLVED FIXED
mozilla34
Tracking Status
firefox32 --- unaffected
firefox33 --- fixed
firefox34 --- fixed

People

(Reporter: khuey, Assigned: chmanchester)

References

Details

(Whiteboard: [MemShrink:P1])

Attachments

(1 file)

It's totally busted now.  Hurray.
Whiteboard: [MemShrink]
Whiteboard: [MemShrink] → [MemShrink:P0]
Kyle suspects this is a regression from https://hg.mozilla.org/integration/mozilla-inbound/rev/a283c1237d96 , but is testing things now.
(Changing to a MemShrink:P1 so that it shows up in our standard P1 searches.)
Whiteboard: [MemShrink:P0] → [MemShrink:P1]
Trunk and Aurora trees closed at 2014-07-28T14:58:26
Oh yay. More regressions!

So, a couple changes had to be done to ShutdownLeaks to make it work with structured logs:
http://dxr.mozilla.org/mozilla-central/source/build/automationutils.py#608

I'm not really familiar with leaks logging so I might've skipped some useful messages.
So the leak logging steps are still being run, but their output is going to a different place than the rest of the test output, and not showing up in the logs on tinderbox.

Kyle is testing whether a failure in the output causes the tree to turn orange, although it currently appears that it doesn't.  (Running the tests locally doesn't provide a clear indicator of whether the tree would be orange.)
I filed bug 1045316 on adding regression checking for our leak finding infrastructure.
We're probably going to have to disable mochitest-e10s-1 debug builds, which got enabled on Friday or so. There was a leak there that I was working on and it went away unexpectedly. I figured someone might have fixed it, but it was probably this.
Depends on: 1045335
Assignee: nobody → cmanchester
Status: NEW → ASSIGNED
I looked through all of the Mochitest logs on our ASan runs, and there was only a single unexpected leak (this is on Linux64) in M1 (bug 1045335), so hopefully things aren't too bad.  And that was inbound-only.
I see this leak in mochitest-3 across multiple trees: https://tbpl.mozilla.org/php/getParsedLog.php?id=44758939&tree=Mozilla-Central

18:11:17     INFO -  61201 INFO [Parent 969] WARNING: '!compMgr', file /builds/slave/b2g-in-osx64-d-000000000000000/build/xpcom/glue/nsComponentManagerUtils.cpp, line 63
18:11:17     INFO -  61202 INFO nsStringStats
18:11:17     INFO -  61203 INFO  => mAllocCount:        4141872
18:11:17     INFO -  61204 INFO  => mReallocCount:       228328
18:11:17     INFO -  61205 INFO  => mFreeCount:         4141872
18:11:17     INFO -  61206 INFO  => mShareCount:        9720160
18:11:17     INFO -  61207 INFO  => mAdoptCount:         402839
18:11:17     INFO -  61208 INFO  => mAdoptFreeCount:     402839
18:11:17     INFO -  61209 INFO  => Process ID: 969, Thread ID: 140735078186176
18:11:17     INFO -  61210 INFO [979] WARNING: Abnormal shutdown of GMP process!: file /builds/slave/b2g-in-osx64-d-000000000000000/build/content/media/gmp/GMPChild.cpp, line 137
18:11:17     INFO -  TEST-INFO | Main app process: exit 0
18:11:17     INFO -  61211 INFO runtests.py | Application ran for: 0:23:20.851462
18:11:17     INFO -  61212 INFO zombiecheck | Reading PID log: /var/folders/+Z/+ZLiBbEdGpeS9D6LHqNGKk+++-k/-Tmp-/tmpl_Ov58pidlog
18:11:17     INFO -  61213 INFO Stopping web server
18:11:17     INFO -  61214 INFO Stopping web socket server
18:11:17     INFO -  61215 INFO Stopping ssltunnel
18:11:17     INFO -  == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 969
18:11:17     INFO -       |<----------------Class--------------->|<-----Bytes------>|<----------------Objects---------------->|<--------------References-------------->|
18:11:17     INFO -                                                Per-Inst   Leaked    Total      Rem      Mean       StdDev     Total      Rem      Mean       StdDev
18:11:17     INFO -     0 TOTAL                                          19      632 426054788        5 (32562.61 +/- 63308.79) 274967149        0 ( 8345.84 +/- 15123.86)
18:11:17     INFO -   139 CondVar                                        32       32    19260        1 (   38.38 +/-     4.55)        0        0 (    0.00 +/-     0.00)
18:11:17     INFO -   153 CrashReporterParent                           152      152       14        1 (    1.56 +/-     1.12)        0        0 (    0.00 +/-     0.00)
18:11:17     INFO -   284 GeckoChildProcessHost                         376      376       14        1 (    1.56 +/-     1.12)        0        0 (    0.00 +/-     0.00)
18:11:17     INFO -   478 Mutex                                          24       24   109391        1 (  288.27 +/-    34.28)        0        0 (    0.00 +/-     0.00)
18:11:17     INFO -   518 PCrashReporterParent                           48       48       14        1 (    1.56 +/-     1.12)        0        0 (    0.00 +/-     0.00)
18:11:17     INFO -  nsTraceRefcnt::DumpStatistics: 1645 entries
18:11:17     INFO -  TEST-INFO | leakcheck | leaked 1 CondVar (32 bytes)
18:11:17     INFO -  TEST-INFO | leakcheck | leaked 1 CrashReporterParent (152 bytes)
18:11:17     INFO -  TEST-INFO | leakcheck | leaked 1 GeckoChildProcessHost (376 bytes)
18:11:17     INFO -  TEST-INFO | leakcheck | leaked 1 Mutex (24 bytes)
18:11:17     INFO -  TEST-INFO | leakcheck | leaked 1 PCrashReporterParent (48 bytes)
18:11:17  WARNING -  TEST-UNEXPECTED-FAIL | leakcheck | 632 bytes leaked (CondVar, CrashReporterParent, GeckoChildProcessHost, Mutex, PCrashReporterParent)
18:11:17     INFO -  ==> process 981 will purposefully crash
18:11:17     INFO -  TEST-INFO | leakcheck | plugin process: deliberate crash and thus no leak log
18:11:17     INFO -  ==> process 983 will purposefully crash
18:11:17     INFO -  TEST-INFO | leakcheck | plugin process: deliberate crash and thus no leak log
18:11:17     INFO -  ==> process 984 will purposefully crash
18:11:17     INFO -  TEST-INFO | leakcheck | plugin process: deliberate crash and thus no leak log
18:11:17     INFO -  ==> process 986 will purposefully crash
18:11:17     INFO -  TEST-INFO | leakcheck | plugin process: deliberate crash and thus no leak log
18:11:17     INFO -  ==> process 976 will purposefully crash
18:11:17     INFO -  TEST-INFO | leakcheck | tab process: deliberate crash and thus no leak log
18:11:17     INFO -  61216 INFO runtests.py | Running tests: end.
18:11:17     INFO -  61217 INFO TEST-START | Shutdown
18:11:17     INFO -  61218 INFO Passed:  42050
18:11:17     INFO -  61219 INFO Failed:  0
18:11:17     INFO -  61220 INFO Todo:    393
18:11:17     INFO -  61221 INFO Slowest: 32967ms - /tests/dom/tests/mochitest/ajax/jquery/test_jQuery.html
18:11:17     INFO -  61222 INFO SimpleTest FINISHED
18:11:17     INFO -  61223 INFO TEST-INFO | Ran 1 Loops
18:11:17     INFO -  61224 INFO SimpleTest FINISHED
18:11:17     INFO -  61225 INFO SUITE-END | took 1400s
18:11:18     INFO - Return code: 0
18:11:18     INFO - TinderboxPrint: mochitest-plain-chunked<br/>42050/0/393&nbsp;<em class="testfail">LEAK</em>
18:11:18  WARNING - # TBPL WARNING #


Needinfo-ing Jesup since it looks like it's leaking in GMP stuff.
Flags: needinfo?(rjesup)
Leaks are definitely showing up again. Will get this uplifted to Aurora in the morning.
Flags: needinfo?(rjesup) → needinfo?(ryanvm)
Target Milestone: --- → mozilla34
(In reply to Ryan VanderMeulen [:RyanVM UTC-4] from comment #12)
> Leaks are definitely showing up again. Will get this uplifted to Aurora in
> the morning.

Did it for you now. :)

https://hg.mozilla.org/releases/mozilla-aurora/rev/1ceea59bf3e2
Flags: needinfo?(ryanvm)
I've hidden mochitest-e10s-1 debug builds on m-c, m-i, fx-team, and b-i as per billm's recommendation.
And on try as well, now.
The GMP leaks are/should be fixed by bug 1043531 and bug 1044550 which are on inbound and should merge to central "soon".
Yes, it indeed looks like the leaks are fixed on inbound, so once inbound is green, it should be able to be merged to central and then central merged elsewhere, and trees can reopen once they get what's now on inbound.
(Note that inbound is currently cleaning up from merge bustage related to the merge of bug 977026 and bug 1045067.)
See Also: → 1045433
(In reply to David Baron [:dbaron] (UTC-7) (needinfo? for questions) from comment #18)
> (Note that inbound is currently cleaning up from merge bustage related to
> the merge of bug 977026 and bug 1045067.)

and we are back in business, trees are open and merges from m-i to m-c and back to the other integration trees done
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
See Also: → 1045525
You need to log in before you can comment on or make changes to this bug.