Closed Bug 1233774 Opened 4 years ago Closed 4 years ago

Intermittent TEST-UNEXPECTED-FAIL | leakcheck | default process: 1060 bytes leaked (CondVar, EventTokenBucket, Mutex, nsCancelableRunnable, nsDeque, ...)

Categories

(Core :: Networking, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
mozilla46
Tracking Status
e10s + ---
firefox45 --- fixed
firefox46 --- fixed

People

(Reporter: aryx, Assigned: mcmanus)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, memory-leak, Whiteboard: [MemShrink:P3])

Attachments

(1 file)

https://treeherder.mozilla.org/logviewer.html#?job_id=18765416&repo=mozilla-inbound

03:58:06     INFO -  nsStringStats
03:58:06     INFO -   => mAllocCount:         579741
03:58:06     INFO -   => mReallocCount:        52657
03:58:06     INFO -   => mFreeCount:          579741
03:58:06     INFO -   => mShareCount:         734169
03:58:06     INFO -   => mAdoptCount:          46717
03:58:06     INFO -   => mAdoptFreeCount:      46717
03:58:06     INFO -   => Process ID: 892, Thread ID: 3836
03:58:06     INFO -  TEST-INFO | Main app process: exit 0
03:58:06     INFO -  runtests.py | Application ran for: 0:02:24.876000
03:58:06     INFO -  zombiecheck | Reading PID log: c:\users\cltbld\appdata\local\temp\tmpv5va33pidlog
03:58:06     INFO -  Stopping web server
03:58:06     INFO -  Stopping web socket server
03:58:06     INFO -  Stopping ssltunnel
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leak threshold set at 0 bytes
03:58:06     INFO -  TEST-INFO | leakcheck | plugin process: leak threshold set at 0 bytes
03:58:06     INFO -  TEST-INFO | leakcheck | tab process: leak threshold set at 10000 bytes
03:58:06     INFO -  TEST-INFO | leakcheck | geckomediaplugin process: leak threshold set at 20000 bytes
03:58:06     INFO -  == BloatView: ALL (cumulative) LEAK AND BLOAT STATISTICS, default process 892
03:58:06     INFO -       |<----------------Class--------------->|<-----Bytes------>|<----Objects---->|
03:58:06     INFO -       |                                      | Per-Inst   Leaked|   Total      Rem|
03:58:06     INFO -     0 |TOTAL                                 |       16     1060|36141897       17|
03:58:06     INFO -   137 |CondVar                               |       24       72|     722        3|
03:58:06     INFO -   247 |EventTokenBucket                      |      168      168|       1        1|
03:58:06     INFO -   447 |Mutex                                 |       20       80|   10170        4|
03:58:06     INFO -   912 |nsCancelableRunnable                  |       12       12|    2574        1|
03:58:06     INFO -   971 |nsDeque                               |       52       52|   11251        1|
03:58:06     INFO -  1297 |nsSocketTransportService              |      200      200|       1        1|
03:58:06     INFO -  1352 |nsTArray_base                         |        4        8| 8531602        2|
03:58:06     INFO -  1362 |nsThread                              |      148      148|      67        1|
03:58:06     INFO -  1367 |nsTimerEvent                          |       48       48|    2400        1|
03:58:06     INFO -  1368 |nsTimerImpl                           |      136      272|   10720        2|
03:58:06     INFO -  nsTraceRefcnt::DumpStatistics: 1495 entries
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 3 CondVar
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 1 EventTokenBucket
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 4 Mutex
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 1 nsCancelableRunnable
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 1 nsDeque
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 1 nsSocketTransportService
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 2 nsTArray_base
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 1 nsThread
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 1 nsTimerEvent
03:58:06     INFO -  TEST-INFO | leakcheck | default process: leaked 2 nsTimerImpl
03:58:06  WARNING -  TEST-UNEXPECTED-FAIL | leakcheck | default process: 1060 bytes leaked (CondVar, EventTokenBucket, Mutex, nsCancelableRunnable, nsDeque, ...)
Component: General → Networking
Keywords: mlk
Whiteboard: [MemShrink]
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1218297
(In reply to Patrick McManus [:mcmanus] from comment #4)
> 
> *** This bug has been marked as a duplicate of bug 1218297 ***

Might be worth reopening this bug, & marking this as "depends-on" instead of a dupe, since TreeHerder auto-suggests this bug (and only this bug) for failures of this sort?  (And clearly people are still starring failures as this bug, & can't easily discover the dupe-target when starring)
Flags: needinfo?(mcmanus)
since the bug this is dup'd to was just merged I presume this will be a nop/wfm very soon
Flags: needinfo?(mcmanus)
This is still happening on inbound.
Status: RESOLVED → REOPENED
Resolution: DUPLICATE → ---
Service workers is triggering network loads just before shutdown.  This could be related to bug 1232558.  I'm working on it.
See Also: → 1232558
I'm going to mark this depends on 1232558 and come back to it if that bug is resolved and this doesn't clear up
Depends on: 1232558
So, I now think its less likely this is related to bug 1232558:

1) This triggers in non-e10s, while bug 1232558 mainly triggers in e10s
2) This triggers in windows M(3) and M(5) while bug 1232558 only triggers in linux m-e10s(1).

They could still be related, but just wanted to note the differences since I missed them before.
I see a ton of assertion in the latest logs.  I wonder if the leak is a side effect of another failure.  Stuff like:

17:15:19     INFO -  [3416] ###!!! ASSERTION: Can only call this on frames that have been reflowed: '!(GetStateBits() & NS_FRAME_FIRST_REFLOW) || (GetParent()->GetStateBits() & NS_FRAME_TOO_DEEP_IN_FRAME_TREE)', file c:/builds/moz2_slave/fx-team-w32-d-0000000000000000/build/src/layout/generic/nsTextFrame.cpp, line 2795
17:15:19     INFO -  #01: PropertyProvider::InitializeForDisplay(bool) [layout/generic/nsTextFrame.cpp:3481]
17:15:19     INFO -  #02: nsTextFrame::GetCharacterOffsetAtFramePointInternal(nsPoint,bool) [layout/generic/nsTextFrame.cpp:6895]
17:15:19     INFO -  #03: nsTextFrame::CalcContentOffsetsFromFramePoint(nsPoint) [layout/generic/nsTextFrame.cpp:6871]

Daniel, do you know if these layout assertions are expected?
Flags: needinfo?(dholbert)
I'm pretty sure we report mochitest failures for unexpected assertion-failures (and mochitests with "known" assertion failures are annotated with SimpleTest.expectAssertions()).

So given that those assertions aren't triggering mochitest failures (I assume?), they're "expected" for some sense of the word. So I don't see a strong reason to suspect a connection to this leak.  Moreover, the leaked objects don't seem related to text-reflow at all.

(If you've checked other logs for the same platform & *only* see these assertions in cases where stuff was leaked, then I'd see more reason to believe that there was a connection. But in the absence of that data, I'd say it's unrelated.)
Flags: needinfo?(dholbert)
I'm going to investigate this to see if its a service worker update running during shutdown.  If not, then I will pass to Patrick and necko team to investigate.
Assignee: nobody → bkelly
Status: REOPENED → ASSIGNED
Patrick, I believe the failures in comment 25 show this is unrelated to service worker background updates.  The debug output does not show before these shutdown leaks.  In addition, the test dirs triggering this don't use service workers.  The dirs are:

  dom/permissions/tests
  parser/htmlparser/tests/mochitest

Those seem somewhat unrelated functionality.  Can you investigate this from a netwerk stack point of view?
No longer depends on: 1232558
Flags: needinfo?(mcmanus)
It appears to me that an EventTokenBucket timer is scheduled on the SocketTransportService's gSocketThread during shutdown.  I'm not sure how that's supposed to work, though.
Assignee: bkelly → nobody
Status: ASSIGNED → NEW
Patrick suggests we wait and see if bug 1238910 addresses this.
Depends on: 1238910
Flags: needinfo?(mcmanus)
Whiteboard: [MemShrink] → [MemShrink:P3]
This intermittent occurs ~50% of the time on mochitest-e10s chunk 5 on win7-debug. Example log:

https://treeherder.mozilla.org/logviewer.html#?job_id=15415893&repo=try

This currently blocks us from enabling mochitest-e10s on win7-debug.
Blocks: 1232780
The leak in comment 34 is happening in parser/htmlparser/tests/mochitest/
There are about 50 tests in that directory. Somebody with a Win7 machine could try bisecting down which test might be causing it. Assuming all of the failures are in that one directory. (Which seems likely if it m-5 is the only one showing this leak.)
(In reply to Andrew McCreight [:mccr8] from comment #36)
> There are about 50 tests in that directory. Somebody with a Win7 machine
> could try bisecting down which test might be causing it. Assuming all of the
> failures are in that one directory. (Which seems likely if it m-5 is the
> only one showing this leak.)

It doesn't appear to be a single test; I've tried bisecting and run into this leak with a large variety of tests in this dir.
Assignee: nobody → mcmanus
Flags: needinfo?(mcmanus)
fwiw I am actively working this.
I'm pretty sure this is because the finegrainresettimer event is still outstanding during shutdown. This is a windows only event which matches the reports. I'll verify on try.
Attachment #8711276 - Flags: review?(dd.mozilla)
Attachment #8711276 - Flags: review?(dd.mozilla) → review+
Comment on attachment 8711276 [details] [diff] [review]
fix Leak EventTokenBucket on shutdown

This is a top tbpl orange - interfering with testing of a number of suites, esp mochi-3. It only impacts windows and has no end user impact.

Approval Request Comment
[Feature/regressing bug #]: 819734 (gecko 18). I'm not sure what has changed in the test suite more recently to make it happen frequently.
[User impact if declined]: none. This is a 1KB leak that might happen during shutdown.
[Describe test coverage new/current, TreeHerder]: exercised across a number of mochitest suites as integration coverage
[Risks and why]: low risk as code is only added in cleanup path
[String/UUID change made/needed]: none
Attachment #8711276 - Flags: approval-mozilla-beta?
Attachment #8711276 - Flags: approval-mozilla-aurora?
https://hg.mozilla.org/mozilla-central/rev/4bb2cf3f0847
Status: NEW → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla46
Comment on attachment 8711276 [details] [diff] [review]
fix Leak EventTokenBucket on shutdown

Improve the testsuite, taking it.
Attachment #8711276 - Flags: approval-mozilla-beta?
Attachment #8711276 - Flags: approval-mozilla-aurora?
Attachment #8711276 - Flags: approval-mozilla-aurora+
You need to log in before you can comment on or make changes to this bug.