Bugzilla

Assignee

Comment 2

•

5 years ago

If I were to throw a wild guess out there I'd suspect some timeupdate elements being dispatched late, or some such. A few of the leaks had allocation stacks with HTMLMediaElement::DispatchEvent and HTMLCanvasElement::GetContext in them. It looks very fun to debug this...

Assignee: nobody → apehrson

Status: NEW → ASSIGNED

Flags: needinfo?(apehrson)

Comment hidden (Intermittent Failures Robot)

Assignee

Comment 4

•

5 years ago

Attached file Bug 1593739 - Create a dedicated Unlink path for mSrcStream. r?bryce — Details

Assignee

Comment 5

•

5 years ago

Bug 1473183 is the debug version of this. I'll try further in debug to see if I can figure out the classes the leak checker thinks we're leaking. That has helped in the past.

Comment 7

•

5 years ago

We could look at the tips for tracking down a leak linked to bug 1583955.

Comment 13

•

5 years ago

I checked the DOMWINDOW logs and for the leaking process there are 5 windows hanging around. 3 inner and 2 outer. One inner-outer pair are created close to process startup. For the other outer there is one inner created right after the start of dom/media/test/test_mediatrack_events.html and one at shutdown.

I'll try to focus on dom/media/test/test_mediatrack_events.html here.

Assignee

Comment 14

•

5 years ago

With that test disabled we are no longer leaking: https://treeherder.mozilla.org/#/jobs?repo=try&revision=06e3bde274a2d9617a759886b21f1bd3d7dd6297
And for reproducing, the good news is it can be found with test-verify on only this test (rate is similar or slightly higher compared to mda1): https://treeherder.mozilla.org/#/jobs?repo=try&revision=e5b44b07817439e5007a6390f997873d8c001127

I haven't had success locally so far though.

Assignee

Comment 15

•

5 years ago

Following the brief instructions in bug 1567448 comment 42 and the linked mdn page, I got cc-logging and dmd hooked up in automation with the mochitest test-verify job. I'll attach the patch that achieved this later.

The repro rate was not affected.

So far I have the root from the cc log figured out:

pehrsons@pehrsons-X299:~/dev/leaks/dmd-on-try/1$ python ~/dev/heapgraph/find_roots.py ./cc-edges.2588-1.log 0x7f0140bd3400
Parsing ./cc-edges.2588-1.log. Done loading graph.

0x7f0140fd7760 [nsNodeInfoManager]
--[mDocument]--> 0x7f013e6df000 [Document normal (xhtml) https://example.com/tests/dom/media/test/test_mediatrack_events.html]
--[Preserved wrapper]--> 0x20530f3c72e0 [JS Object (HTMLDocument)]
--[group_global]--> 0x20530f3ad100 [JS Object (Window)]
--[UnwrapDOMObject(obj)]--> 0x7f0140bd3400 [nsGlobalWindowInner # 4294967343 inner https://example.com/tests/dom/media/test/test_mediatrack_events.html]
Root 0x7f0140fd7760 is a ref counted object with 1 unknown edge(s).
known edges:
   0x7f0141a9a300 [NodeInfo (xhtml) title] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f014144c980 [NodeInfo ([none]) #document] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f0140b30500 [NodeInfo (xhtml) iframe] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f0141943680 [NodeInfo (xhtml) head] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f01416c9c00 [NodeInfo (xhtml) body] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f0141a9ab80 [NodeInfo (xhtml) script] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f0141942500 [NodeInfo ([none]) #document-type] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f01419a3500 [NodeInfo (xhtml) html] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f0141a9a200 [NodeInfo ([none]) #text] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f0142153900 [NodeInfo (xhtml) link] --[mOwnerManager]--> 0x7f0140fd7760
   0x7f0142077380 [NodeInfo (xhtml) pre] --[mOwnerManager]--> 0x7f0140fd7760

I'm continuing per the mdn page to figure out the unknown edge.

Assignee

Comment 16

•

5 years ago

Per DMD, the unknown edge is:

0x7f013e6df000 size = 3224 bytes at byte offset 512  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                               
  moz_xmalloc [memory/mozalloc/mozalloc.cpp:53]                                                                                                                                                                    
  NS_NewHTMLDocument(mozilla::dom::Document**, bool) [dom/html/nsHTMLDocument.cpp:131]                                                                                                                             
  nsContentDLF::CreateInstance(char const*, nsIChannel*, nsILoadGroup*, nsTSubstring<char> const&, nsIDocShell*, nsISupports*, nsIStreamListener**,                                                                
  nsContentDLF::CreateDocument(char const*, nsIChannel*, nsILoadGroup*, nsIDocShell*, already_AddRefed<mozilla::dom::Document> (*)(), nsIStreamList                                                                
  nsContentDLF::CreateInstance(char const*, nsIChannel*, nsILoadGroup*, nsTSubstring<char> const&, nsIDocShell*, nsISupports*, nsIStreamListener**,                                                                
  nsDocShell::NewContentViewerObj(nsTSubstring<char> const&, nsIRequest*, nsILoadGroup*, nsIStreamListener**, nsIContentViewer**) [docshell/base/ns                                                                
  nsDocShell::CreateContentViewer(nsTSubstring<char> const&, nsIRequest*, nsIStreamListener**) [docshell/base/nsDocShell.cpp:7807]

And this object was also held by the nsNodeInfoManager:

--[mDocument]--> 0x7f013e6df000 [Document normal (xhtml) https://example.com/tests/dom/media/test/test_mediatrack_events.html]

Unsure what to make of this so far.

Comment 17

•

5 years ago

Comment 16 means that the reference is from an nsHTMLDocument. However, nsHTMLDocument::mInfoManager is actually a weak reference, so I think it can't be holding the info manager alive. If there are really no heap references to the nsNodeInfoManager that don't also appear in the known edges list (and I'd double check that before going any further), then the only thing I can think of is there might be some refcounting error for the node info manager. That would be a little surprising, though, because the info manager stuff is pretty standard and hidden away from most DOM code, so I wouldn't think you could end up with errors there.

What I would have guessed based only on comment 15 is that there's some DOM node that is leaking the info manager via its node info, because I think node infos are the only things that hold strong refs to the node info manager, and nodes are the only thing that hold strong refs to node infos. But comment 16 indicates that might not be the case.

Assignee

Comment 18

•

5 years ago

Attached patch Patch to enable Shutdown CC and DMD logs in mochitests on try, debug builds only — Details — Splinter Review

Well, here's the patch to get the logs going on try for mochitest. Might be useful.

I'll note that when symbolicating the DMD logs (with the help of BREAKPAD_SYMBOLS_PATH) there were two libxul.so in the crashreporter_symbols tarball, and because fileid wasn't packaged with the build from try it couldn't figure out which to use. I ran block_analyzer.py on both and only one of them gave me stacks that made sense...

Assignee

Comment 19

•

5 years ago

(In reply to Andrew McCreight [:mccr8] from comment #17)

Comment 16 means that the reference is from an nsHTMLDocument. However, nsHTMLDocument::mInfoManager is actually a weak reference, so I think it can't be holding the info manager alive. If there are really no heap references to the nsNodeInfoManager that don't also appear in the known edges list (and I'd double check that before going any further), then the only thing I can think of is there might be some refcounting error for the node info manager. That would be a little surprising, though, because the info manager stuff is pretty standard and hidden away from most DOM code, so I wouldn't think you could end up with errors there.

What I would have guessed based only on comment 15 is that there's some DOM node that is leaking the info manager via its node info, because I think node infos are the only things that hold strong refs to the node info manager, and nodes are the only thing that hold strong refs to node infos. But comment 16 indicates that might not be the case.

Thanks for the input.

I've noted this weak reference as well and confirmed that the document that DMD is pointing out also has a known strong ref through mNodeInfo:

0x7f0140fd7760 [nsNodeInfoManager]
    --[mDocument]--> 0x7f013e6df000 [Document normal (xhtml) https://example.com/tests/dom/media/test/test_mediatrack_events.html]
    --[mNodeInfo]--> 0x7f014144c980 [NodeInfo ([none]) #document]

--[mNodeInfo]--> 0x7f014144c980 [NodeInfo ([none]) #document] is seen in comment 15 as a known edge.

DMD points out exactly the 11 known edges from comment 15, and the weak ref in comment 16. Here's the output from block_analyzer.py on 0x7f0140fd7760 (stacks removed):

  1 0x7f0141a9ab80 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
  2 0x7f0140b30500 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
  3 0x7f0142077380 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
  4 0x7f013e6df000 size = 3224 bytes at byte offset 512  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                           
  5 0x7f0141942500 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
  6 0x7f014144c980 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
  7 0x7f01419a3500 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
  8 0x7f0142153900 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
  9 0x7f0141a9a200 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
 10 0x7f01416c9c00 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
 11 0x7f0141943680 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]                                                                                             
 12 0x7f0141a9a300 size = 128 bytes at byte offset 72  replace_malloc(unsigned long) [memory/replace/dmd/DMD.cpp:1071]

https://pernos.co/debug/nR83VsAZNGlNzqEtWjDFtw/index.html

Comment 20

•

5 years ago

Olli, do you have any ideas? This leak sounds pretty odd.

Flags: needinfo?(bugs)

Comment hidden (Intermittent Failures Robot)

Kyle Huey [:khuey]

Comment 22

•

5 years ago

I'm not sure how useful it will be but it does appear that we caught this in Pernosco.

Assignee

Comment 23

•

5 years ago

Soooo, that was a fun exercise.

To crack this (I went down the wrong nsNodeInfoManager at first) I copied the NodePool's internal state as it got cleared after CC shutdown.

With a minor vim exercise I then eliminated all GCed objects (refcount 0) and those that had matching mInternalRefs to mRefCount (expected). Left were 4 objects:

[161] = { mPointer=0x7f0cffe9d040, mParticipant=0x7f0d1060d018《::BrowsingContext::_cycleCollectorGlobal》, mColor=0, mInternalRefs=1, mRefCount=3, mFirstChild.mPointer=0x7f0cf866b7b0 },
[336] = { mPointer=0x7f0d1a839840, mParticipant=0x7f0d1060d5e8《nsWebBrowser::_cycleCollectorGlobal》, mColor=0, mInternalRefs=1, mRefCount=2, mFirstChild.mPointer=0x7f0cf866d318 },
[2140] = { mPointer=0x7f0d006fdac0, mParticipant=0x7f0d1060d018《::BrowsingContext::_cycleCollectorGlobal》, mColor=0, mInternalRefs=2, mRefCount=3, mFirstChild.mPointer=0x7f0cf8686490 },
[2680] = { mPointer=0x7f0cf6034030, mParticipant=0x7f0d105ec0c8《nsNodeInfoManager::_cycleCollectorGlobal》, mColor=0, mInternalRefs=11, mRefCount=12, mFirstChild.mPointer=0x7f0cf6cc0608 },

Seeing that CC logs suggested nsNodeInfoManager in the past (comment 15) I went for that one.

With the Dataflow of mRefCount I could see when the mRefCount=12 got read from the nsNodeInfoManager's refcount. And with a watchpoint on mInternalRefs I could see which NodeInfos were traversed.

I also tracked the nsNodeInfoManager's mRefCntAndFlags to see which reference was not accounted for.

It turned out to be quite the shutdown sequence that led to this leak, and it did indeed involve a media element, and bug 1577505 is indeed the regressor. Though with a fair bit of indirection.

The sequence:

nsCycleCollector::ShutdownCollect() happens and runs two shutdown collections (at least, but we only care about the first two)
The first shutdown collection traverses an HTMLMediaElement. It gets unlinked too. But is kept alive by a non-cc-participating PerCallbackWatcher Runnable.
The second shutdown collection does not traverse the HTMLMediaElement or its mNodeInfo (it was unlinked, I guess), but it still holds a strong-ref to the nsNodeInfoManager (through said mNodeInfo). This is the unknown edge seen in comment 15.
Because of this unknown edge, the nsNodeInfoManager is not unlinked.
After the cycle collector has shut down the HTMLMediaElement is deleted. There are now only 11 strong-refs to the nsNodeInfoManager on the heap.

The cause:
The patch I already have on this bug was strikingly close to solve this in its first rev, had the added line just been a bit higher up.
The Runnable that kept the media element alive came from EndSrcMediaStreamPlayback(). Specifically from this line which with bug 1577505 assigns to a watchable which adds a direct task with a strong ref to the media element.

Flags: needinfo?(bugs)

Comment hidden (Intermittent Failures Robot)

Pulsebot

Comment 25

•

5 years ago

Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/0f20566c7b2f
Shut down the watch manager during Unlink to prevent future notify tasks. r=bryce

https://treeherder.mozilla.org/#/jobs?repo=try&revision=364754f21db0f580feacf8c7e75dba1377ac5269

Assignee

Comment 26

•

5 years ago

Noemi Erli[:noemi_erli]

Comment 27

•

5 years ago

Backed out changeset 0f20566c7b2f (Bug 1593739) for causing assertion in StateWatching.h CLOSED TREE

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&selectedJob=276409267&resultStatus=testfailed%2Cbusted%2Cexception&revision=0f20566c7b2fa7b1204e432828940fd81ab2a197

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=276409267&repo=autoland&lineNumber=1746

Backout: https://hg.mozilla.org/integration/autoland/rev/d215b3534e043455cad3bf14a90e5f80e9f8cdd0

Flags: needinfo?(apehrson)

Comment 28

•

5 years ago

(In reply to Andreas Pehrson [:pehrsons] from comment #23)

The first shutdown collection traverses an HTMLMediaElement. It gets unlinked too. But is kept alive by a non-cc-participating PerCallbackWatcher Runnable.

I don't understand this step. Why does the CC think that it can unlink the media element if there is a strong reference to it from the runnable?

The second shutdown collection does not traverse the HTMLMediaElement or its mNodeInfo (it was unlinked, I guess), but it still holds a strong-ref to the nsNodeInfoManager (through said mNodeInfo). This is the unknown edge seen in comment 15.

Interesting. I guess we traverse mNodeInfo, but don't unlink it, and normally that is okay because node to nodeinfo is kind of acyclic. Even in this case, we're only leaking the info manager because we're leaking the media element anyways (to this point).

After the cycle collector has shut down the HTMLMediaElement is deleted. There are now only 11 strong-refs to the nsNodeInfoManager on the heap.

I guess the runnable finally gets destroyed when we shut down threads or something, but that's after the CC is gone, and if there's a cycle that needs the CC to be broken, then we just leak.

Comment hidden (Intermittent Failures Robot)

Updated

•

5 years ago

Whiteboard: [stockwell disable-recommended] → [stockwell needswork][comment 28]

Comment hidden (Intermittent Failures Robot)

Assignee

Comment 32

•

5 years ago

(In reply to Andrew McCreight [:mccr8] from comment #28)

(In reply to Andreas Pehrson [:pehrsons] from comment #23)

The first shutdown collection traverses an HTMLMediaElement. It gets unlinked too. But is kept alive by a non-cc-participating PerCallbackWatcher Runnable.

I don't understand this step. Why does the CC think that it can unlink the media element if there is a strong reference to it from the runnable?

There isn't. That strong reference is created during unlink.

The second shutdown collection does not traverse the HTMLMediaElement or its mNodeInfo (it was unlinked, I guess), but it still holds a strong-ref to the nsNodeInfoManager (through said mNodeInfo). This is the unknown edge seen in comment 15.

Interesting. I guess we traverse mNodeInfo, but don't unlink it, and normally that is okay because node to nodeinfo is kind of acyclic. Even in this case, we're only leaking the info manager because we're leaking the media element anyways (to this point).

After the cycle collector has shut down the HTMLMediaElement is deleted. There are now only 11 strong-refs to the nsNodeInfoManager on the heap.

I guess the runnable finally gets destroyed when we shut down threads or something, but that's after the CC is gone, and if there's a cycle that needs the CC to be broken, then we just leak.

It's a direct task so it runs at the end of shutdown, in ProcessStableStateQueue(). See the stack in pernosco. But yes, this would need another CC to be broken.

Flags: needinfo?(apehrson)

Phabricator Automation

Updated

•

5 years ago

Attachment #9106692 - Attachment description: Bug 1593739 - Shut down the watch manager during Unlink to prevent future notify tasks. r?bryce → Bug 1593739 - Create a dedicated Unlink path for mSrcStream. r?bryce

Comment 33

•

5 years ago

(In reply to Andreas Pehrson [:pehrsons] from comment #32)

There isn't. That strong reference is created during unlink.

Ah, I see. That's a questionable pattern, because we're generally assuming that unlinked objects are going to go away, so I don't think we can guarantee anything reasonable will happen. I'll try to keep that in mind.

Pulsebot

Comment 34

•

5 years ago

Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/100092ccffcd
Create a dedicated Unlink path for mSrcStream. r=bryce

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Cquantumrender%2Cdebug%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux64-qr%2Fdebug-mochitest-media-fis-e10s&fromchange=90678a02990b0a6e81066a5c790d0b60a6a792d2&tochange=25cfc79bf77c58372a6233bc15b5b93161b30cef&selectedJob=276854849

Comment 35

•

5 years ago

Backed out changeset 100092ccffcd (Bug 1593739) for RefPtr mda perma-failures

Backout link: https://hg.mozilla.org/integration/autoland/rev/25cfc79bf77c58372a6233bc15b5b93161b30cef

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=276854849&repo=autoland&lineNumber=28604

[task 2019-11-18T22:18:42.037Z] 22:18:42 [task 2019-11-18T22:18:42.073Z] 22:18:42 [task 2019-11-18T22:18:42.115Z] 22:18:42 [task 2019-11-18T22:18:42.185Z] 22:18:42 [task 2019-11-18T22:18:42.246Z] 22:18:42 [task 2019-11-18T22:18:42.356Z] 22:18:42 [task 2019-11-18T22:18:42.357Z] 22:18:42 [task 2019-11-18T22:18:42.373Z] 22:18:42 [task 2019-11-18T22:18:42.388Z] 22:18:42 [task 2019-11-18T22:18:42.390Z] 22:18:42 [task 2019-11-18T22:18:42.506Z] 22:18:42 [task 2019-11-18T22:18:42.507Z] 22:18:42 [task 2019-11-18T22:18:42.508Z] 22:18:42 [task 2019-11-18T22:18:42.508Z] 22:18:42 [task 2019-11-18T22:18:42.509Z] 22:18:42 [task 2019-11-18T22:18:42.510Z] 22:18:42 [task 2019-11-18T22:18:42.511Z] 22:18:42 [task 2019-11-18T22:18:42.511Z] 22:18:42 [task 2019-11-18T22:18:42.512Z] 22:18:42 [task 2019-11-18T22:18:42.513Z] 22:18:42 [task 2019-11-18T22:18:42.513Z] 22:18:42 [task 2019-11-18T22:18:42.514Z] 22:18:42 [task 2019-11-18T22:18:42.515Z] 22:18:42 [task 2019-11-18T22:18:42.516Z] 22:18:42 [task 2019-11-18T22:18:42.516Z] 22:18:42 [task 2019-11-18T22:18:42.517Z] 22:18:42 [task 2019-11-18T22:18:42.519Z] 22:18:42 [task 2019-11-18T22:18:42.519Z] 22:18:42 [task 2019-11-18T22:18:42.520Z] 22:18:42 [task 2019-11-18T22:18:42.603Z] 22:18:42 [task 2019-11-18T22:18:42.604Z] 22:18:42 [task 2019-11-18T22:18:42.605Z] 22:18:42 [task 2019-11-18T22:18:42.606Z] 22:18:42 [task 2019-11-18T22:18:42.608Z] 22:18:42 [task 2019-11-18T22:18:42.609Z] 22:18:42 [task 2019-11-18T22:18:42.708Z] 22:18:42 [task 2019-11-18T22:18:42.710Z] 22:18:42 [task 2019-11-18T22:18:42.711Z] 22:18:42 [task 2019-11-18T22:18:42.712Z] 22:18:42 [task 2019-11-18T22:18:42.716Z] 22:18:42 [task 2019-11-18T22:19:05.369Z] 22:19:05 [task 2019-11-18T22:19:05.371Z] 22:19:05 [task 2019-11-18T22:19:05.372Z] 22:19:05 [task 2019-11-18T22:19:05.372Z] 22:19:05 [task 2019-11-18T22:19:05.373Z] 22:19:05 [task 2019-11-18T22:19:05.374Z] 22:19:05 [task 2019-11-18T22:19:05.375Z] 22:19:05 [task 2019-11-18T22:19:05.376Z] 22:19:05 [task 2019-11-18T22:19:05.376Z] 22:19:05 [task 2019-11-18T22:19:05.377Z] 22:19:05 [task 2019-11-18T22:19:05.378Z] 22:19:05 [task 2019-11-18T22:19:05.379Z] 22:19:05 [task 2019-11-18T22:19:05.379Z] 22:19:05 [task 2019-11-18T22:19:05.380Z] 22:19:05 [task 2019-11-18T22:19:05.381Z] 22:19:05 [task 2019-11-18T22:19:05.382Z] 22:19:05 [task 2019-11-18T22:19:05.382Z] 22:19:05 [task 2019-11-18T22:19:05.383Z] 22:19:05 [task 2019-11-18T22:19:05.384Z] 22:19:05 [task 2019-11-18T22:19:05.384Z] 22:19:05 [task 2019-11-18T22:19:05.386Z] 22:19:05 [task 2019-11-18T22:19:05.387Z] 22:19:05 [task 2019-11-18T22:19:05.388Z] 22:19:05 [task 2019-11-18T22:19:05.388Z] 22:19:05 [task 2019-11-18T22:19:05.389Z] 22:19:05 [task 2019-11-18T22:19:05.390Z] 22:19:05 [task 2019-11-18T22:19:05.391Z] 22:19:05 [task 2019-11-18T22:19:05.391Z] 22:19:05 [task 2019-11-18T22:19:05.392Z] 22:19:05 [task 2019-11-18T22:19:05.393Z] 22:19:05 [task 2019-11-18T22:19:05.394Z] 22:19:05 [task 2019-11-18T22:19:05.395Z] 22:19:05 [task 2019-11-18T22:19:05.396Z] 22:19:05 [task 2019-11-18T22:19:05.397Z] 22:19:05 [task 2019-11-18T22:19:05.579Z] 22:19:05 [task 2019-11-18T22:19:05.580Z] 22:19:05 [task 2019-11-18T22:19:05.580Z] 22:19:05 [task 2019-11-18T22:19:05.581Z] 22:19:05 [task 2019-11-18T22:19:05.582Z] 22:19:05 [task 2019-11-18T22:19:05.582Z] 22:19:05 [task 2019-11-18T22:19:05.582Z] 22:19:05 [task 2019-11-18T22:19:05.583Z] 22:19:05 [task 2019-11-18T22:19:05.583Z] 22:19:05 [task 2019-11-18T22:19:05.586Z] 22:19:05 [task 2019-11-18T22:19:05.586Z] 22:19:05 [task 2019-11-18T22:19:05.587Z] 22:19:05 [task 2019-11-18T22:19:05.588Z] 22:19:05 [task 2019-11-18T22:19:05.588Z] 22:19:05 [task 2019-11-18T22:19:05.589Z] 22:19:05 [task 2019-11-18T22:19:05.595Z] 22:19:05 [task 2019-11-18T22:19:05.595Z] 22:19:05 [task 2019-11-18T22:19:05.596Z] 22:19:05 [task 2019-11-18T22:19:05.596Z] 22:19:05 [task 2019-11-18T22:19:05.597Z] 22:19:05 [task 2019-11-18T22:19:05.598Z] 22:19:05 [task 2019-11-18T22:19:05.598Z] 22:19:05 [task 2019-11-18T22:19:05.599Z] 22:19:05 [task 2019-11-18T22:19:05.599Z] 22:19:05 [task 2019-11-18T22:19:05.600Z] 22:19:05 [task 2019-11-18T22:19:05.600Z] 22:19:05 [task 2019-11-18T22:19:05.601Z] 22:19:05 [task 2019-11-18T22:19:05.601Z] 22:19:05 [task 2019-11-18T22:19:05.602Z] 22:19:05 [task 2019-11-18T22:19:05.602Z] 22:19:05 [task 2019-11-18T22:19:05.603Z] 22:19:05 [task 2019-11-18T22:19:05.603Z] 22:19:05 [task 2019-11-18T22:19:05.603Z] 22:19:05 [task 2019-11-18T22:19:05.604Z] 22:19:05 [task 2019-11-18T22:19:05.604Z] 22:19:05 [task 2019-11-18T22:19:05.605Z] 22:19:05 [task 2019-11-18T22:19:05.605Z] 22:19:05 [task 2019-11-18T22:19:05.606Z] 22:19:05 [task 2019-11-18T22:19:05.606Z] 22:19:05 [task 2019-11-18T22:19:05.606Z] 22:19:05 [task 2019-11-18T22:19:05.607Z] 22:19:05 [task 2019-11-18T22:19:05.607Z] 22:19:05 [task 2019-11-18T22:19:05.607Z] 22:19:05 [task 2019-11-18T22:19:05.608Z] 22:19:05 [task 2019-11-18T22:19:05.608Z] 22:19:05 [task 2019-11-18T22:19:05.609Z] 22:19:05 [task 2019-11-18T22:19:05.609Z] 22:19:05 [task 2019-11-18T22:19:05.610Z] 22:19:05 [task 2019-11-18T22:19:05.611Z] 22:19:05 [task 2019-11-18T22:19:05.611Z] 22:19:05 [task 2019-11-18T22:19:05.612Z] 22:19:05 [task 2019-11-18T22:19:05.612Z] 22:19:05 [task 2019-11-18T22:19:05.613Z] 22:19:05 [task 2019-11-18T22:19:05.616Z] 22:19:05 [task 2019-11-18T22:19:05.616Z] 22:19:05 [task 2019-11-18T22:19:05.617Z] 22:19:05 [task 2019-11-18T22:19:05.617Z] 22:19:05 [task 2019-11-18T22:19:05.618Z] 22:19:05 [task 2019-11-18T22:19:05.618Z] 22:19:05 [task 2019-11-18T22:19:05.619Z] 22:19:05 [task 2019-11-18T22:19:05.619Z] 22:19:05 [task 2019-11-18T22:19:05.620Z] 22:19:05 [task 2019-11-18T22:19:05.620Z] 22:19:05 [task 2019-11-18T22:19:05.621Z] 22:19:05 [task 2019-11-18T22:19:05.621Z] 22:19:05 [task 2019-11-18T22:19:05.621Z] 22:19:05 [task 2019-11-18T22:19:05.622Z] 22:19:05 [task 2019-11-18T22:19:05.622Z] 22:19:05 [task 2019-11-18T22:19:05.623Z] 22:19:05 [task 2019-11-18T22:19:05.623Z] 22:19:05 [task 2019-11-18T22:19:05.623Z] 22:19:05 [task 2019-11-18T22:19:05.624Z] 22:19:05 [task 2019-11-18T22:19:05.624Z] 22:19:05 [task 2019-11-18T22:19:05.625Z] 22:19:05 [task 2019-11-18T22:19:05.626Z] 22:19:05 [task 2019-11-18T22:19:05.626Z] 22:19:05 [task 2019-11-18T22:19:05.626Z] 22:19:05 ...
...
[task 2019-11-18T22:19:05.657Z] 22:19:05 [task 2019-11-18T22:19:05.657Z] 22:19:05 [task 2019-11-18T22:19:05.657Z] 22:19:05 [task 2019-11-18T22:19:05.658Z] 22:19:05 [task 2019-11-18T22:19:05.658Z] 22:19:05 [task 2019-11-18T22:19:05.659Z] 22:19:05 [task 2019-11-18T22:19:05.659Z] 22:19:05 [task 2019-11-18T22:19:05.659Z] 22:19:05 [task 2019-11-18T22:19:05.660Z] 22:19:05 [task 2019-11-18T22:19:05.660Z] 22:19:05 [task 2019-11-18T22:19:05.660Z] 22:19:05 [task 2019-11-18T22:19:05.661Z] 22:19:05 [task 2019-11-18T22:19:05.661Z] 22:19:05 [task 2019-11-18T22:19:05.662Z] 22:19:05 [task 2019-11-18T22:19:05.662Z] 22:19:05 [task 2019-11-18T22:19:05.662Z] 22:19:05 [task 2019-11-18T22:19:05.663Z] 22:19:05 [task 2019-11-18T22:19:05.663Z] 22:19:05 [task 2019-11-18T22:19:05.663Z] 22:19:05 [task 2019-11-18T22:19:05.664Z] 22:19:05 [task 2019-11-18T22:19:10.414Z] 22:19:10 [task 2019-11-18T22:19:10.415Z] 22:19:10 [task 2019-11-18T22:19:10.514Z] 22:19:10 [task 2019-11-18T22:19:10.515Z] 22:19:10 [task 2019-11-18T22:19:10.515Z] 22:19:10 [task 2019-11-18T22:19:10.516Z] 22:19:10 [task 2019-11-18T22:19:10.516Z] 22:19:10 [task 2019-11-18T22:19:10.516Z] 22:19:10 [task 2019-11-18T22:19:10.517Z] 22:19:10 [task 2019-11-18T22:19:10.517Z] 22:19:10 [task 2019-11-18T22:19:10.517Z] 22:19:10 [task 2019-11-18T22:19:10.518Z] 22:19:10 [task 2019-11-18T22:19:10.518Z] 22:19:10 [task 2019-11-18T22:19:10.518Z] 22:19:10 [task 2019-11-18T22:19:10.519Z] 22:19:10 [task 2019-11-18T22:19:10.519Z] 22:19:10 [task 2019-11-18T22:19:10.519Z] 22:19:10 [task 2019-11-18T22:19:10.519Z] 22:19:10 [task 2019-11-18T22:19:10.520Z] 22:19:10 [task 2019-11-18T22:19:10.520Z] 22:19:10 [task 2019-11-18T22:19:10.520Z] 22:19:10 [task 2019-11-18T22:19:10.520Z] 22:19:10 [task 2019-11-18T22:19:10.520Z] 22:19:10 [task 2019-11-18T22:19:10.521Z] 22:19:10 [task 2019-11-18T22:19:10.521Z] 22:19:10 [task 2019-11-18T22:19:10.521Z] 22:19:10 [task 2019-11-18T22:19:10.521Z] 22:19:10 [task 2019-11-18T22:19:10.521Z] 22:19:10 [task 2019-11-18T22:19:10.522Z] 22:19:10 [task 2019-11-18T22:19:10.522Z] 22:19:10 [task 2019-11-18T22:19:10.522Z] 22:19:10 [task 2019-11-18T22:19:10.522Z] 22:19:10 [task 2019-11-18T22:19:10.522Z] 22:19:10 [task 2019-11-18T22:19:10.523Z] 22:19:10 [task 2019-11-18T22:19:10.523Z] 22:19:10 [task 2019-11-18T22:19:10.523Z] 22:19:10 [task 2019-11-18T22:19:10.523Z] 22:19:10 [task 2019-11-18T22:19:10.524Z] 22:19:10 [task 2019-11-18T22:19:10.524Z] 22:19:10 [task 2019-11-18T22:19:10.524Z] 22:19:10 [task 2019-11-18T22:19:10.524Z] 22:19:10 [task 2019-11-18T22:19:10.524Z] 22:19:10 [task 2019-11-18T22:19:10.525Z] 22:19:10 [task 2019-11-18T22:19:10.525Z] 22:19:10 [task 2019-11-18T22:19:10.525Z] 22:19:10 [task 2019-11-18T22:19:10.525Z] 22:19:10 [task 2019-11-18T22:19:10.525Z] 22:19:10 [task 2019-11-18T22:19:10.526Z] 22:19:10 [task 2019-11-18T22:19:10.526Z] 22:19:10 [task 2019-11-18T22:19:10.526Z] 22:19:10 [task 2019-11-18T22:19:10.526Z] 22:19:10 [task 2019-11-18T22:19:10.526Z] 22:19:10 [task 2019-11-18T22:19:10.527Z] 22:19:10 [task 2019-11-18T22:19:10.527Z] 22:19:10 [task 2019-11-18T22:19:10.527Z] 22:19:10 [task 2019-11-18T22:19:10.527Z] 22:19:10 [task 2019-11-18T22:19:10.528Z] 22:19:10 [task 2019-11-18T22:19:10.528Z] 22:19:10 [task 2019-11-18T22:19:10.528Z] 22:19:10 [task 2019-11-18T22:19:10.528Z] 22:19:10 [task 2019-11-18T22:19:10.528Z] 22:19:10 [task 2019-11-18T22:19:10.529Z] 22:19:10 [task 2019-11-18T22:19:10.529Z] 22:19:10 [task 2019-11-18T22:19:10.529Z] 22:19:10 [task 2019-11-18T22:19:10.529Z] 22:19:10 [task 2019-11-18T22:19:10.529Z] 22:19:10 [task 2019-11-18T22:19:10.530Z] 22:19:10 [task 2019-11-18T22:19:10.530Z] 22:19:10 [task 2019-11-18T22:19:10.530Z] 22:19:10 [task 2019-11-18T22:19:10.530Z] 22:19:10 [task 2019-11-18T22:19:10.530Z] 22:19:10 [task 2019-11-18T22:19:10.530Z] 22:19:10 [task 2019-11-18T22:19:10.531Z] 22:19:10 [task 2019-11-18T22:19:10.531Z] 22:19:10 [task 2019-11-18T22:19:10.531Z] 22:19:10 [task 2019-11-18T22:19:10.531Z] 22:19:10 [task 2019-11-18T22:19:10.531Z] 22:19:10 [task 2019-11-18T22:19:10.532Z] 22:19:10 [task 2019-11-18T22:19:10.532Z] 22:19:10 [task 2019-11-18T22:19:10.532Z] 22:19:10 [task 2019-11-18T22:19:10.532Z] 22:19:10 [task 2019-11-18T22:19:10.533Z] 22:19:10 [task 2019-11-18T22:19:10.533Z] 22:19:10 [task 2019-11-18T22:19:10.533Z] 22:19:10 [task 2019-11-18T22:19:10.533Z] 22:19:10 [task 2019-11-18T22:19:10.534Z] 22:19:10 [task 2019-11-18T22:19:10.534Z] 22:19:10 [task 2019-11-18T22:19:10.534Z] 22:19:10 [task 2019-11-18T22:19:10.534Z] 22:19:10 [task 2019-11-18T22:19:10.534Z] 22:19:10 [task 2019-11-18T22:19:10.535Z] 22:19:10 [task 2019-11-18T22:19:10.535Z] 22:19:10 [task 2019-11-18T22:19:10.535Z] 22:19:10 [task 2019-11-18T22:19:10.535Z] 22:19:10 [task 2019-11-18T22:19:10.536Z] 22:19:10 [task 2019-11-18T22:19:10.536Z] 22:19:10 [task 2019-11-18T22:19:10.536Z] 22:19:10 [task 2019-11-18T22:19:10.544Z] 22:19:10 [task 2019-11-18T22:19:10.544Z] 22:19:10 [task 2019-11-18T22:19:10.544Z] 22:19:10 [task 2019-11-18T22:19:10.545Z] 22:19:10 [task 2019-11-18T22:19:10.545Z] 22:19:10 [task 2019-11-18T22:19:10.546Z] 22:19:10 [task 2019-11-18T22:19:10.546Z] 22:19:10 [task 2019-11-18T22:19:10.547Z] 22:19:10 [task 2019-11-18T22:19:10.547Z] 22:19:10 [task 2019-11-18T22:19:10.547Z] 22:19:10 [task 2019-11-18T22:19:10.548Z] 22:19:10 [task 2019-11-18T22:19:10.548Z] 22:19:10 [task 2019-11-18T22:19:10.548Z] 22:19:10 [task 2019-11-18T22:19:10.549Z] 22:19:10 [task 2019-11-18T22:19:10.549Z] 22:19:10 [task 2019-11-18T22:19:10.550Z] 22:19:10 [task 2019-11-18T22:19:10.550Z] 22:19:10 [task 2019-11-18T22:19:10.550Z] 22:19:10 [task 2019-11-18T22:19:10.551Z] 22:19:10 [task 2019-11-18T22:19:10.551Z] 22:19:10 [task 2019-11-18T22:19:10.551Z] 22:19:10 [task 2019-11-18T22:19:10.552Z] 22:19:10 [task 2019-11-18T22:19:10.552Z] 22:19:10 [task 2019-11-18T22:19:10.552Z] 22:19:10 [task 2019-11-18T22:19:10.553Z] 22:19:10 [task 2019-11-18T22:19:10.553Z] 22:19:10 [task 2019-11-18T22:19:10.554Z] 22:19:10 [task 2019-11-18T22:19:10.554Z] 22:19:10 [task 2019-11-18T22:19:10.554Z] 22:19:10 [task 2019-11-18T22:19:10.555Z] 22:19:10 [task 2019-11-18T22:19:10.555Z] 22:19:10 [task 2019-11-18T22:19:10.555Z] 22:19:10 [task 2019-11-18T22:19:10.556Z] 22:19:10 [task 2019-11-18T22:19:10.556Z] 22:19:10 [task 2019-11-18T22:19:10.556Z] 22:19:10 [task 2019-11-18T22:19:10.556Z] 22:19:10 [task 2019-11-18T22:19:10.557Z] 22:19:10 [task 2019-11-18T22:19:10.558Z] 22:19:10 [task 2019-11-18T22:19:10.558Z] 22:19:10 [task 2019-11-18T22:19:10.558Z] 22:19:10 [task 2019-11-18T22:19:10.559Z] 22:19:10 [task 2019-11-18T22:19:10.559Z] 22:19:10 [task 2019-11-18T22:19:10.559Z] 22:19:10 [task 2019-11-18T22:19:10.560Z] 22:19:10 [task 2019-11-18T22:19:10.560Z] 22:19:10 [task 2019-11-18T22:19:10.560Z] 22:19:10 [task 2019-11-18T22:19:10.561Z] 22:19:10 [task 2019-11-18T22:19:10.561Z] 22:19:10 [task 2019-11-18T22:19:10.562Z] 22:19:10 [task 2019-11-18T22:19:10.562Z] 22:19:10 [task 2019-11-18T22:19:10.563Z] 22:19:10 [task 2019-11-18T22:19:10.563Z] 22:19:10 [task 2019-11-18T22:19:10.564Z] 22:19:10 [task 2019-11-18T22:19:10.564Z] 22:19:10 [task 2019-11-18T22:19:10.564Z] 22:19:10 [task 2019-11-18T22:19:10.565Z] 22:19:10 [task 2019-11-18T22:19:10.565Z] 22:19:10 [task 2019-11-18T22:19:10.565Z] 22:19:10 ... INFO - TEST-START | dom/media/tests/mochitest/test_peerConnection_basicAudioVideoVerifyExtmapSendonly.html
INFO - GECKO(4139) | --DOCSHELL 0x7f2d58343800 == 2 [pid = 4315] [id = {b27e99e3-e4b8-4dfd-9736-cd72c679ddac}] [url = about:blank]
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4563
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: NS_ENSURE_TRUE(aCSP) failed: file /builds/worker/workspace/build/src/dom/security/FramingChecker.cpp, line 176
INFO - GECKO(4139) | ++DOMWINDOW == 8 (0x7f2d64e2fc00) [pid = 4315] [serial = 289] [outer = 0x7f2d682fc6a0]
INFO - GECKO(4139) | ++DOCSHELL 0x7f2d58320000 == 3 [pid = 4315] [id = {fbb074e2-f95a-4277-b5f4-20619f14fe04}]
INFO - GECKO(4139) | ++DOMWINDOW == 9 (0x7f2d647e3f20) [pid = 4315] [serial = 290] [outer = (nil)]
INFO - GECKO(4139) | ++DOMWINDOW == 10 (0x7f2d675b7c00) [pid = 4315] [serial = 291] [outer = 0x7f2d647e3f20]
INFO - GECKO(4139) | TEST DEVICES: Got loopback audio: Monitor of Null Output
INFO - GECKO(4139) | TEST DEVICES: Got loopback video: Dummy video device (0x0000)
INFO - GECKO(4139) | Timecard created 1574115520.480085
INFO - GECKO(4139) | Timestamp | Delta | Event | File | Function
INFO - GECKO(4139) | ========================================================================================================
INFO - GECKO(4139) | 0.000029 | 0.000029 | Constructor Completed | PeerConnectionImpl.cpp:336 | PeerConnectionImpl
INFO - GECKO(4139) | 0.000917 | 0.000888 | Initializing PC Ctx | PeerConnectionImpl.cpp:462 | Initialize
INFO - GECKO(4139) | 1.021143 | 1.020226 | Create Offer | PeerConnectionImpl.cpp:1258 | CreateOffer
INFO - GECKO(4139) | 1.030076 | 0.008933 | Set Local Description | PeerConnectionImpl.cpp:1319 | SetLocalDescription
INFO - GECKO(4139) | 2.019815 | 0.989739 | Destructor Invoked | PeerConnectionImpl.cpp:345 | ~PeerConnectionImpl
INFO - GECKO(4139) | [Child 4315: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:370: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for b6b3195f85f7026c
INFO - GECKO(4139) | Timecard created 1574115520.485803
INFO - GECKO(4139) | Timestamp | Delta | Event | File | Function
INFO - GECKO(4139) | ==========================================================================================================
INFO - GECKO(4139) | 0.000024 | 0.000024 | Constructor Completed | PeerConnectionImpl.cpp:336 | PeerConnectionImpl
INFO - GECKO(4139) | 0.000735 | 0.000711 | Initializing PC Ctx | PeerConnectionImpl.cpp:462 | Initialize
INFO - GECKO(4139) | 1.055788 | 1.055053 | Set Remote Description | PeerConnectionImpl.cpp:1407 | SetRemoteDescription
INFO - GECKO(4139) | 1.179028 | 0.123240 | Create Answer | PeerConnectionImpl.cpp:1285 | CreateAnswer
INFO - GECKO(4139) | 1.189791 | 0.010763 | Set Local Description | PeerConnectionImpl.cpp:1319 | SetLocalDescription
INFO - GECKO(4139) | 2.014399 | 0.824608 | Destructor Invoked | PeerConnectionImpl.cpp:345 | ~PeerConnectionImpl
INFO - GECKO(4139) | [Child 4315: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:370: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for 14f189f4de5f7d7d
INFO - GECKO(4139) | [Child 4315, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6827
INFO - GECKO(4139) | [Child 4315, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6827
INFO - GECKO(4139) | [Child 4315, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6827
INFO - GECKO(4139) | [Child 4315, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6827
INFO - GECKO(4139) | [Child 4315, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6827
INFO - GECKO(4139) | [Child 4315, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/workspace/build/src/dom/base/Document.cpp, line 6827
INFO - GECKO(4139) | --DOMWINDOW == 9 (0x7f2d583f5800) [pid = 4315] [serial = 287] [outer = (nil)] [url = about:blank]
INFO - GECKO(4139) | --DOMWINDOW == 8 (0x7f2d64e6f800) [pid = 4315] [serial = 288] [outer = (nil)] [url = https://example.com/tests/SimpleTest/iframe-between-tests.html]
INFO - GECKO(4139) | --DOMWINDOW == 7 (0x7f2d647e3d40) [pid = 4315] [serial = 286] [outer = (nil)] [url = about:blank]
INFO - GECKO(4139) | --DOMWINDOW == 6 (0x7f2d58395800) [pid = 4315] [serial = 285] [outer = (nil)] [url = https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_basicAudioVideoVerifyExtmap.html]
INFO - GECKO(4139) | Assertion failure: mRawPtr != nullptr (You can't dereference a NULL RefPtr with operator->().), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RefPtr.h:307
INFO - GECKO(4139) | #01: mozilla::dom::HTMLMediaElement::UpdateMediaSize(mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> const&) [dom/html/HTMLMediaElement.cpp:6232]
INFO -
INFO - GECKO(4139) | #02: mozilla::dom::HTMLVideoElement::UpdateMediaSize(mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> const&) [dom/html/HTMLVideoElement.cpp:100]
INFO -
INFO - GECKO(4139) | #03: mozilla::dom::HTMLMediaElement::Invalidate(bool, mozilla::Maybe<mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> >&, bool) [dom/html/HTMLMediaElement.cpp:6197]
INFO -
INFO - GECKO(4139) | #04: mozilla::dom::HTMLVideoElement::Invalidate(bool, mozilla::Maybe<mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> >&, bool) [dom/html/HTMLVideoElement.cpp:138]
INFO -
INFO - GECKO(4139) | #05: mozilla::VideoFrameContainer::InvalidateWithFlags(unsigned int) [dom/media/VideoFrameContainer.cpp:261]
INFO -
INFO - GECKO(4139) | #06: mozilla::detail::RunnableMethodImpl<RefPtr<mozilla::VideoFrameContainer> const, void (mozilla::VideoFrameContainer::)(), true, (mozilla::RunnableKind)0>::Run() [xpcom/threads/nsThreadUtils.h:1179]
INFO -
INFO - GECKO(4139) | #07: mozilla::EventTargetWrapper::Runner::Run() [xpcom/threads/AbstractThread.cpp:113]
INFO -
INFO - GECKO(4139) | #08: mozilla::SchedulerGroup::Runnable::Run() [xpcom/threads/SchedulerGroup.cpp:295]
INFO -
INFO - GECKO(4139) | #09: nsThread::ProcessNextEvent(bool, bool) [xpcom/threads/nsThread.cpp:1250]
INFO -
INFO - GECKO(4139) | #10: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:486]
INFO -
INFO - GECKO(4139) | #11: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:88]
INFO -
INFO - GECKO(4139) | #12: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
INFO -
INFO - GECKO(4139) | #13: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:139]
INFO -
INFO - GECKO(4139) | #14: XRE_RunAppShell() [toolkit/xre/nsEmbedFunctions.cpp:934]
INFO -
INFO - GECKO(4139) | #15: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:238]
INFO -
INFO - GECKO(4139) | #16: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
INFO -
INFO - GECKO(4139) | #17: XRE_InitChildProcess(int, char**, XREChildData const*) [toolkit/xre/nsEmbedFunctions.cpp:769]
INFO -
INFO - GECKO(4139) | #18: content_process_main(mozilla::Bootstrap*, int, char**) [ipc/contentproc/plugin-container.cpp:57]
INFO -
INFO - GECKO(4139) | #19: main [browser/app/nsBrowserApp.cpp:272]
INFO -
INFO - GECKO(4139) | #20: libc.so.6 + 0x20830
INFO -
INFO - GECKO(4139) | #21: _start
INFO -
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/workspace/build/src/ipc/glue/ProtocolUtils.cpp, line 481
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/workspace/build/src/ipc/glue/ProtocolUtils.cpp, line 481
INFO - GECKO(4139) | ++DOCSHELL 0x7fd61c140800 == 7 [pid = 4139] [id = {6c736cd3-51da-4b44-b677-b18a9b359dbe}]
INFO - GECKO(4139) | ++DOMWINDOW == 14 (0x7fd61d8213e0) [pid = 4139] [serial = 192] [outer = (nil)]
INFO - GECKO(4139) | ++DOMWINDOW == 15 (0x7fd61c322c00) [pid = 4139] [serial = 193] [outer = 0x7fd61d8213e0]
ERROR - GECKO(4139) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4563
INFO - GECKO(4139) | --DOCSHELL 0x7f342213c800 == 2 [pid = 4266] [id = {4778e9ff-61cd-4d3f-9501-8e69aa249a0e}] [url = moz-extension://03aea81a-db59-4cbe-94d4-96345f05bf31/_generated_background_page.html]
INFO - GECKO(4139) | --DOCSHELL 0x7f342213a800 == 1 [pid = 4266] [id = {ce42fafc-8cf2-4701-ae85-3e65ddae2cd4}] [url = moz-extension://9c636594-3b1c-4723-845b-455dc224ec0d/_generated_background_page.html]
INFO - GECKO(4139) | --DOCSHELL 0x7f3421b0d000 == 0 [pid = 4266] [id = {51bae7f5-8897-4110-b5a0-3c1dfd350aa9}] [url = moz-extension://8ff869c1-1c9d-4fc7-b925-08b1eae076de/_generated_background_page.html]
INFO - GECKO(4139) | ++DOMWINDOW == 16 (0x7fd61e2ed000) [pid = 4139] [serial = 194] [outer = 0x7fd61d8213e0]
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4563
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: '!mIMContext', file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 6371
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: '!mIMContext', file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 6371
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Cannot set transparency mode on non-popup windows.: file /builds/worker/workspace/build/src/widget/gtk/nsWindow.cpp, line 4563
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: '!inner', file /builds/worker/workspace/build/src/dom/ipc/JSWindowActorService.cpp, line 181
INFO - GECKO(4139) | [GPU 4162, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/workspace/build/src/gfx/layers/apz/src/APZUpdater.cpp, line 429
INFO - GECKO(4139) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - GECKO(4139) | [2019-11-18T22:18:43Z WARN xulstore::persist] tried to remove key that isn't in the store
INFO - GECKO(4139) | [2019-11-18T22:18:43Z WARN xulstore::persist] tried to remove key that isn't in the store
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsCacheService.cpp, line 859
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsCacheService.cpp, line 822
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file /builds/worker/workspace/build/src/netwerk/cache/nsApplicationCacheService.cpp, line 159
INFO - GECKO(4139) | --DOMWINDOW == 5 (0x7f343b0ee3e0) [pid = 4266] [serial = 5] [outer = (nil)] [url = moz-extension://03aea81a-db59-4cbe-94d4-96345f05bf31/_generated_background_page.html]
INFO - GECKO(4139) | --DOMWINDOW == 4 (0x7f343b0ef4c0) [pid = 4266] [serial = 3] [outer = (nil)] [url = moz-extension://9c636594-3b1c-4723-845b-455dc224ec0d/_generated_background_page.html]
INFO - GECKO(4139) | --DOMWINDOW == 3 (0x7f343b0ef2e0) [pid = 4266] [serial = 1] [outer = (nil)] [url = moz-extension://8ff869c1-1c9d-4fc7-b925-08b1eae076de/_generated_background_page.html]
INFO - GECKO(4139) | --DOMWINDOW == 2 (0x7f3422128000) [pid = 4266] [serial = 7] [outer = (nil)] [url = moz-extension://8ff869c1-1c9d-4fc7-b925-08b1eae076de/_generated_background_page.html]
INFO - GECKO(4139) | --DOMWINDOW == 1 (0x7f342212a000) [pid = 4266] [serial = 8] [outer = (nil)] [url = moz-extension://9c636594-3b1c-4723-845b-455dc224ec0d/_generated_background_page.html]
INFO - GECKO(4139) | --DOMWINDOW == 0 (0x7f342212c400) [pid = 4266] [serial = 9] [outer = (nil)] [url = moz-extension://03aea81a-db59-4cbe-94d4-96345f05bf31/_generated_background_page.html]
INFO - GECKO(4139) | nsStringStats
INFO - GECKO(4139) | => mAllocCount: 15713
INFO - GECKO(4139) | => mReallocCount: 0
INFO - GECKO(4139) | => mFreeCount: 15713
INFO - GECKO(4139) | => mShareCount: 8385
INFO - GECKO(4139) | => mAdoptCount: 504
INFO - GECKO(4139) | => mAdoptFreeCount: 522
INFO - GECKO(4139) | => Process ID: 4266, Thread ID: 139862328416064
INFO - GECKO(4139) | --DOCSHELL 0x7fc460ada800 == 0 [pid = 4209] [id = {f8468733-b5dc-4683-842c-9f0746289262}] [url = about:newtab]
INFO - GECKO(4139) | --DOMWINDOW == 1 (0x7fc461387880) [pid = 4209] [serial = 4] [outer = (nil)] [url = about:newtab]
INFO - GECKO(4139) | --DOMWINDOW == 0 (0x7fc460afb000) [pid = 4209] [serial = 6] [outer = (nil)] [url = about:newtab]
INFO - GECKO(4139) | nsStringStats
INFO - GECKO(4139) | => mAllocCount: 16900
INFO - GECKO(4139) | => mReallocCount: 0
INFO - GECKO(4139) | => mFreeCount: 16900
INFO - GECKO(4139) | => mShareCount: 19392
INFO - GECKO(4139) | => mAdoptCount: 476
INFO - GECKO(4139) | => mAdoptFreeCount: 480
INFO - GECKO(4139) | => Process ID: 4209, Thread ID: 140481861920576
INFO - GECKO(4139) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - GECKO(4139) | --DOMWINDOW == 15 (0x7fd61c32cc00) [pid = 4139] [serial = 187] [outer = (nil)] [url = about:blank]
INFO - GECKO(4139) | --DOCSHELL 0x7fd61c13c000 == 6 [pid = 4139] [id = {0567030f-64a2-453e-ab28-2fde59d00349}] [url = chrome://browser/content/webrtcIndicator.xul]
INFO - GECKO(4139) | nsStringStats
INFO - GECKO(4139) | => mAllocCount: 8593
INFO - GECKO(4139) | => mReallocCount: 0
INFO - GECKO(4139) | => mFreeCount: 8593
INFO - GECKO(4139) | => mShareCount: 4055
INFO - GECKO(4139) | => mAdoptCount: 67
INFO - GECKO(4139) | => mAdoptFreeCount: 67
INFO - GECKO(4139) | => Process ID: 4236, Thread ID: 140272340358976
INFO - GECKO(4139) | --DOCSHELL 0x7fd61c14c000 == 5 [pid = 4139] [id = {49c61cb6-0509-43a8-96af-a828425c0d96}] [url = chrome://browser/content/webrtcIndicator.xul]
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | [Parent 4139, Main Thread] WARNING: Existing entry in StartupCache.: file /builds/worker/workspace/build/src/startupcache/StartupCache.cpp, line 434
INFO - GECKO(4139) | 1574115525038 Marionette TRACE Received observer notification xpcom-will-shutdown
INFO - TEST-INFO | Main app process: exit 0
INFO - runtests.py | Application ran for: 0:05:38.397447
INFO - zombiecheck | Reading PID log: /tmp/tmpVYyeMVpidlog
INFO - ==> process 4139 launched child process 4158
INFO - ==> process 4139 launched child process 4162
INFO - ==> process 4139 launched child process 4209
INFO - ==> process 4139 launched child process 4236
INFO - ==> process 4139 launched child process 4266
INFO - ==> process 4139 launched child process 4315
INFO - ==> process 4139 launched child process 4748
INFO - ==> process 4139 launched child process 5713
INFO - zombiecheck | Checking for orphan process with PID: 4162
INFO - zombiecheck | Checking for orphan process with PID: 5713
INFO - zombiecheck | Checking for orphan process with PID: 4748
INFO - zombiecheck | Checking for orphan process with PID: 4266
INFO - zombiecheck | Checking for orphan process with PID: 4236
INFO - zombiecheck | Checking for orphan process with PID: 4209
INFO - zombiecheck | Checking for orphan process with PID: 4315
INFO - zombiecheck | Checking for orphan process with PID: 4158
INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmppK4_zn.mozrunner/minidumps/388a5ad9-43b5-afb7-8002-d959be11f108.dmp /builds/worker/workspace/build/symbols
INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/388a5ad9-43b5-afb7-8002-d959be11f108.dmp
INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/388a5ad9-43b5-afb7-8002-d959be11f108.extra
INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ RefPtr<mozilla::dom::VideoStreamTrack>::operator->() const]
INFO - Crash dump filename: /tmp/tmppK4_zn.mozrunner/minidumps/388a5ad9-43b5-afb7-8002-d959be11f108.dmp
INFO - Operating system: Linux
INFO - 0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
INFO - CPU: amd64
INFO - family 6 model 85 stepping 4
INFO - 1 CPU
INFO -
INFO - GPU: UNKNOWN
INFO -
INFO - Crash reason: SIGSEGV /SEGV_MAPERR
INFO - Crash address: 0x0
INFO - Process uptime: not available
INFO -
INFO - Thread 0 (crashed)
INFO - 0 libxul.so!RefPtr<mozilla::dom::VideoStreamTrack>::operator->() const [RefPtr.h:100092ccffcdcdeea743bad5bc80c7696fba1844 : 306 + 0x29]
INFO - rax = 0x00007f2d7444f4ec rdx = 0x0000000000000000
INFO - rcx = 0x0000555649a01e28 rbx = 0x00007f2d5aa11000
INFO - rsi = 0x00007f2d8183b770 rdi = 0x00007f2d8183a540
INFO - rbp = 0x00007ffcfd8b6910 rsp = 0x00007ffcfd8b6910
INFO - r8 = 0x00007f2d8183b770 r9 = 0x00007f2d82897740
INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000000
INFO - r12 = 0x0000000000000000 r13 = 0x00000000ffffffff
INFO - r14 = 0x00007ffcfd8b69a8 r15 = 0x0000000000000001
INFO - rip = 0x00007f2d6f1f9b67
INFO - Found by: given as instruction pointer in context
INFO - 1 libxul.so!mozilla::dom::HTMLMediaElement::UpdateMediaSize(mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> const&) [HTMLMediaElement.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 6232 + 0xc]
INFO - rbx = 0x00007f2d5aa11000 rbp = 0x00007ffcfd8b6950
INFO - rsp = 0x00007ffcfd8b6920 r12 = 0x0000000000000000
INFO - r13 = 0x00000000ffffffff r14 = 0x00007ffcfd8b69a8
INFO - r15 = 0x0000000000000001 rip = 0x00007f2d708a1fd1
INFO - Found by: call frame info
INFO - 2 libxul.so!mozilla::dom::HTMLVideoElement::UpdateMediaSize(mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> const&) [HTMLVideoElement.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 98 + 0x5]
INFO - rbx = 0x00007f2d5aa11000 rbp = 0x00007ffcfd8b6990
INFO - rsp = 0x00007ffcfd8b6960 r12 = 0x0000000000000000
INFO - r13 = 0x00000000ffffffff r14 = 0x00007ffcfd8b69a8
INFO - r15 = 0x0000000000000001 rip = 0x00007f2d708db5ad
INFO - Found by: call frame info
INFO - 3 libxul.so!mozilla::dom::HTMLMediaElement::Invalidate(bool, mozilla::Maybe<mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> >&, bool) [HTMLMediaElement.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 6196 + 0xf]
INFO - rbx = 0x00007f2d5aa11000 rbp = 0x00007ffcfd8b69e0
INFO - rsp = 0x00007ffcfd8b69a0 r12 = 0x0000000000000000
INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000000
INFO - r15 = 0x0000000000000001 rip = 0x00007f2d708a1ded
INFO - Found by: call frame info
INFO - 4 libxul.so!mozilla::dom::HTMLVideoElement::Invalidate(bool, mozilla::Maybe<mozilla::gfx::IntSizeTyped<mozilla::gfx::UnknownUnits> >&, bool) [HTMLVideoElement.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 136 + 0x5]
INFO - rbx = 0x00007f2d5aa11000 rbp = 0x00007ffcfd8b6a00
INFO - rsp = 0x00007ffcfd8b69f0 r12 = 0x00007f2d81293901
INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000000
INFO - r15 = 0x00007ffcfd8b6a18 rip = 0x00007f2d708db698
INFO - Found by: call frame info
INFO - 5 libxul.so!mozilla::VideoFrameContainer::InvalidateWithFlags(unsigned int) [VideoFrameContainer.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 260 + 0x17]
INFO - rbx = 0x00007ffcfd8b6a28 rbp = 0x00007ffcfd8b6a60
INFO - rsp = 0x00007ffcfd8b6a10 r12 = 0x00007f2d81293901
INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000000
INFO - r15 = 0x00007ffcfd8b6a18 rip = 0x00007f2d7093045b
INFO - Found by: call frame info
INFO - 6 libxul.so!mozilla::detail::RunnableMethodImpl<RefPtr<mozilla::VideoFrameContainer> const, void (mozilla::VideoFrameContainer::)(), true, (mozilla::RunnableKind)0>::Run() [nsThreadUtils.h:100092ccffcdcdeea743bad5bc80c7696fba1844 : 1176 + 0x17]
INFO - rbx = 0x00007f2d5aad7f38 rbp = 0x00007ffcfd8b6a70
INFO - rsp = 0x00007ffcfd8b6a70 r12 = 0x00007f2d81293900
INFO - r13 = 0x00000000ffffffff r14 = 0x00007f2d812ae000
INFO - r15 = 0x00007f2d5b1ce2c0 rip = 0x00007f2d708b02af
INFO - Found by: call frame info
INFO - 7 libxul.so!mozilla::EventTargetWrapper::Runner::Run() [AbstractThread.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 113 + 0x15]
INFO - rbx = 0x00007f2d5aad7f38 rbp = 0x00007ffcfd8b6aa0
INFO - rsp = 0x00007ffcfd8b6a80 r12 = 0x00007f2d81293900
INFO - r13 = 0x00000000ffffffff r14 = 0x00007f2d812ae000
INFO - r15 = 0x00007f2d5b1ce2c0 rip = 0x00007f2d6e72b85a
INFO - Found by: call frame info
INFO - 8 libxul.so!mozilla::SchedulerGroup::Runnable::Run() [SchedulerGroup.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 295 + 0x15]
INFO - rbx = 0x00007f2d5b1ce290 rbp = 0x00007ffcfd8b6ad0
INFO - rsp = 0x00007ffcfd8b6ab0 r12 = 0x00007f2d81293900
INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000001
INFO - r15 = 0x00007f2d5b1ce2c0 rip = 0x00007f2d6e728e32
INFO - Found by: call frame info
INFO - 9 libxul.so!nsThread::ProcessNextEvent(bool, bool) [nsThread.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 1250 + 0x11]
INFO - rbx = 0x00007ffcfd8b6b20 rbp = 0x00007ffcfd8b7030
INFO - rsp = 0x00007ffcfd8b6ae0 r12 = 0x00007f2d81293900
INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000001
INFO - r15 = 0x00007f2d812939f0 rip = 0x00007f2d6e73d378
INFO - Found by: call frame info
INFO - 10 libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 486 + 0xc]
INFO - rbx = 0x0000000000000000 rbp = 0x00007ffcfd8b7060
INFO - rsp = 0x00007ffcfd8b7040 r12 = 0x0000000000000001
INFO - r13 = 0x00007f2d8129ccb0 r14 = 0x00007ffcfd8b7047
INFO - r15 = 0x0000000000000001 rip = 0x00007f2d6e74050f
INFO - Found by: call frame info
INFO - 11 libxul.so!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [MessagePump.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 88 + 0x7]
INFO - rbx = 0x00007f2d8129cc90 rbp = 0x00007ffcfd8b70c0
INFO - rsp = 0x00007ffcfd8b7070 r12 = 0x0000000000000001
INFO - r13 = 0x00007f2d8129ccb0 r14 = 0x00007ffcfd8b7228
INFO - r15 = 0x0000000000000001 rip = 0x00007f2d6ecd61e0
INFO - Found by: call frame info
INFO - 12 libxul.so!MessageLoop::Run() [message_loop.cc:100092ccffcdcdeea743bad5bc80c7696fba1844 : 290 + 0x8]
INFO - rbx = 0x00007ffcfd8b7228 rbp = 0x00007ffcfd8b7100
INFO - rsp = 0x00007ffcfd8b70d0 r12 = 0x00007f2d812e3000
INFO - r13 = 0x00007ffcfd8b8668 r14 = 0x00007ffcfd8b70d0
INFO - r15 = 0x000000000000102b rip = 0x00007f2d6ec89e17
INFO - Found by: call frame info
INFO - 13 libxul.so!nsBaseAppShell::Run() [nsBaseAppShell.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 137 + 0xd]
INFO - rbx = 0x00007f2d6844dac0 rbp = 0x00007ffcfd8b7120
INFO - rsp = 0x00007ffcfd8b7110 r12 = 0x00007f2d812e3000
INFO - r13 = 0x00007ffcfd8b8668 r14 = 0x00007f2d81293900
INFO - r15 = 0x000000000000102b rip = 0x00007f2d712615d1
INFO - Found by: call frame info
INFO - 14 libxul.so!XRE_RunAppShell() [nsEmbedFunctions.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 934 + 0xe]
INFO - rbx = 0x00007ffcfd8b7130 rbp = 0x00007ffcfd8b7150
INFO - rsp = 0x00007ffcfd8b7130 r12 = 0x00007f2d812e3000
INFO - r13 = 0x00007ffcfd8b8668 r14 = 0x0000000000000000
INFO - r15 = 0x000000000000102b rip = 0x00007f2d72398e38
INFO - Found by: call frame info
INFO - 15 libxul.so!mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) [MessagePump.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 238 + 0x5]
INFO - rbx = 0x00007ffcfd8b7228 rbp = 0x00007ffcfd8b7180
INFO - rsp = 0x00007ffcfd8b7160 r12 = 0x00007f2d812e3000
INFO - r13 = 0x00007ffcfd8b8668 r14 = 0x00007f2d8129cc90
INFO - r15 = 0x000000000000102b rip = 0x00007f2d6ecd6789
INFO - Found by: call frame info
INFO - 16 libxul.so!MessageLoop::Run() [message_loop.cc:100092ccffcdcdeea743bad5bc80c7696fba1844 : 290 + 0x8]
INFO - rbx = 0x00007ffcfd8b7228 rbp = 0x00007ffcfd8b71c0
INFO - rsp = 0x00007ffcfd8b7190 r12 = 0x00007f2d812e3000
INFO - r13 = 0x00007ffcfd8b8668 r14 = 0x00007ffcfd8b7190
INFO - r15 = 0x000000000000102b rip = 0x00007f2d6ec89e17
INFO - Found by: call frame info
INFO - 17 libxul.so!XRE_InitChildProcess(int, char**, XREChildData const*) [nsEmbedFunctions.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 769 + 0x5]
INFO - rbx = 0x0000000000000001 rbp = 0x00007ffcfd8b74c0
INFO - rsp = 0x00007ffcfd8b71d0 r12 = 0x00007f2d812e3000
INFO - r13 = 0x00007ffcfd8b8668 r14 = 0x0000000080004005
INFO - r15 = 0x000000000000102b rip = 0x00007f2d72398aa1
INFO - Found by: call frame info
INFO - 18 firefox-bin!content_process_main(mozilla::Bootstrap*, int, char**) [plugin-container.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 56 + 0x11]
INFO - rbx = 0x0000000000000013 rbp = 0x00007ffcfd8b7500
INFO - rsp = 0x00007ffcfd8b74d0 r12 = 0x00007ffcfd8b74d0
INFO - r13 = 0x0000090dc11d1e20 r14 = 0x00007ffcfd8b8668
INFO - r15 = 0x00007f2d81202730 rip = 0x000055564993dd2e
INFO - Found by: call frame info
INFO - 19 firefox-bin!main [nsBrowserApp.cpp:100092ccffcdcdeea743bad5bc80c7696fba1844 : 272 + 0x19]
INFO - rbx = 0x00007ffcfd8b7550 rbp = 0x00007ffcfd8b8580
INFO - rsp = 0x00007ffcfd8b7510 r12 = 0x00007ffcfd8b8668
INFO - r13 = 0x0000090dc11d1e20 r14 = 0x0000000000000014
INFO - r15 = 0x0000555649a01668 rip = 0x000055564993e034
INFO - Found by: call frame info
INFO - 20 libc-2.23.so + 0x20830
INFO - rbx = 0x0000000000000000 rbp = 0x00005556499d2b50
INFO - rsp = 0x00007ffcfd8b8590 r12 = 0x000055564993dbb4
INFO - r13 = 0x00007ffcfd8b8660 r14 = 0x0000000000000000
INFO - r15 = 0x0000000000000000 rip = 0x00007f2d81495830
INFO - Found by: call frame info
INFO - 21 libmozsandbox.so!_fini + 0xa880
INFO - rsp = 0x00007ffcfd8b8598 rip = 0x00007f2d8292c3d8
INFO - Found by: stack scanning
INFO - 22 firefox-bin!<name omitted> [UniquePtr.h:100092ccffcdcdeea743bad5bc80c7696fba1844 : 274 + 0x17]
INFO - rsp = 0x00007ffcfd8b85b0 rip = 0x000055564993dd71
INFO - Found by: stack scanning
INFO -

Flags: needinfo?(apehrson)

Comment 36

•

5 years ago

Also seems to introduce this crash: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=276831442&repo=autoland&lineNumber=22573

Alexandru Michis [:malexandru]

Assignee

Comment 37

•

5 years ago

I got some guards in place and it's looking better: https://treeherder.mozilla.org/#/jobs?repo=try&revision=ffad9efabf830dab29e37a533733c7aa37e58125

Flags: needinfo?(apehrson)

Pulsebot

Comment 38

•

5 years ago

Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/d2ac59316460
Create a dedicated Unlink path for mSrcStream. r=bryce

Comment hidden (Intermittent Failures Robot)

Comment 40

•

5 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/d2ac59316460

Status: ASSIGNED → RESOLVED

Closed: 5 years ago

status-firefox72: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla72

Assignee

Comment 41

•

5 years ago

Phew. Fun. To follow up on this: Andrew, do you think anything could be done in the cycle collector to mitigate issues like these? I'm thinking forbidding AddRef on a cycle collection participant while it is being unlinked would be helpful. Would it be reasonable and feasible to do?

Flags: needinfo?(continuation)

Ryan VanderMeulen [:RyanVM]

Comment 42

•

5 years ago

(In reply to Andreas Pehrson [:pehrsons] from comment #41)

Phew. Fun. To follow up on this: Andrew, do you think anything could be done in the cycle collector to mitigate issues like these? I'm thinking forbidding AddRef on a cycle collection participant while it is being unlinked would be helpful. Would it be reasonable and feasible to do?

That's an interesting idea, but I think there are some practical difficulties.

We actually do something like that during the Traverse phase, because somebody was actually calling AddRef and Release during Traverse which caused problems (bug 1189122). This is done by setting nsCycleCollector::mScanInProgress.

This mechanism doesn't currently distinguish AddRef from Release, and we call Release during Unlink by necessity, so it would require rejiggering (probably something like passing in a flag to Suspect in debug builds to indicate if we're addref or release). It wouldn't catch the case where we did a release before we did an addref (this could happen if some other object with a reference to the object happens to get unlinked first), because we only suspect an object once, but it could still catch things sometimes.

Unlink code also tends to involve more wacky stuff than Traverse code so I would be worried about spurious failures. There's probably code that takes stack references to objects while it is running, which should be okay.

Flags: needinfo?(continuation)

Updated

•

5 years ago

status-firefox70: --- → unaffected

status-firefox71: --- → unaffected

status-firefox-esr68: --- → unaffected

Keywords: memory-leak

Updated

•

5 years ago

Blocks: 1598245

Olli Pettay [:smaug][bugs@pettay.fi]

Assignee

Updated

•

5 years ago

No longer blocks: 1598245

Comment 43

•

5 years ago

(In reply to Andrew McCreight [:mccr8] from comment #42)

(In reply to Andreas Pehrson [:pehrsons] from comment #41)

Phew. Fun. To follow up on this: Andrew, do you think anything could be done in the cycle collector to mitigate issues like these? I'm thinking forbidding AddRef on a cycle collection participant while it is being unlinked would be helpful. Would it be reasonable and feasible to do?

That's an interesting idea, but I think there are some practical difficulties.

We actually do something like that during the Traverse phase, because somebody was actually calling AddRef and Release during Traverse which caused problems (bug 1189122). This is done by setting nsCycleCollector::mScanInProgress.

This mechanism doesn't currently distinguish AddRef from Release, and we call Release during Unlink by necessity, so it would require rejiggering (probably something like passing in a flag to Suspect in debug builds to indicate if we're addref or release). It wouldn't catch the case where we did a release before we did an addref (this could happen if some other object with a reference to the object happens to get unlinked first), because we only suspect an object once, but it could still catch things sometimes.

Unlink code also tends to involve more wacky stuff than Traverse code so I would be worried about spurious failures. There's probably code that takes stack references to objects while it is running, which should be okay.

Yeah I'm thinking of only forbidding AddRef on the object being Unlinked, to keep things as narrow as possible. And I assume the CC is keeping a reference to the object it is unlinking, so if any object's Unlink takes a stack reference to itself, that should be easily changed in my mind.

I guess this would leave out a class of bugs where an object in Unlink takes a (non-stack) reference to another object that was already Unlinked. Perhaps another measure could mitigate that somehow.

Comment 44

•

5 years ago

Unlink method implementations may do some work asynchronously to reduce jank. ContentUnbinder comes to my mind - it is used to
break down DOM trees. And such async helper object needs to of course have strong pointers to the objects to destroy.