840045 - Intermittent test_peerConnection_bug827843.html | This test left crash dumps behind, but we weren't expecting it to! | application timed out after 330 seconds with no output (ASSERTION: Wrong thread!: 'NS_IsMainThread()')

Status: VERIFIED WORKSFORME

(Core :: WebRTC, defect, P5)

Description

[Ryan VanderMeulen [:RyanVM]]

https://tbpl.mozilla.org/php/getParsedLog.php?id=19620638&tree=Firefox

Rev3 WINNT 5.1 mozilla-central debug test mochitest-2 on 2013-02-10 08:39:55 PST for push e68796fdcb5d
slave: talos-r3-xp-089

26101 INFO TEST-START | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html
++DOMWINDOW == 45 (23638B78) [serial = 3062] [outer = 0A02EE50]
--DOMWINDOW == 44 (11C4CD20) [serial = 3015] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/indexedDB/test/test_success_events_after_abort.html]
--DOMWINDOW == 43 (0A67EDB8) [serial = 3022] [outer = 0D3D4DD0] [url = http://mochi.test:8888/tests/dom/indexedDB/test/third_party_iframe2.html]
--DOMWINDOW == 42 (0D3D4DD0) [serial = 3020] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/indexedDB/test/third_party_iframe2.html]
--DOMWINDOW == 41 (1277A650) [serial = 3034] [outer = 1205F610] [url = http://mochi.test:8888/tests/dom/indexedDB/test/third_party_iframe2.html]
--DOMWINDOW == 40 (1205F610) [serial = 3032] [outer = 00000000] [url = http://mochi.test:8888/tests/dom/indexedDB/test/third_party_iframe2.html]
--DOMWINDOW == 39 (3372D098) [serial = 3035] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/indexedDB/test/test_traffic_jam.html]
--DOMWINDOW == 38 (13627358) [serial = 3036] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/indexedDB/test/test_transaction_abort.html]
--DOMWINDOW == 37 (11A21C50) [serial = 3037] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/indexedDB/test/test_transaction_lifetimes.html]
--DOMWINDOW == 36 (1078AED8) [serial = 3038] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/indexedDB/test/test_transaction_lifetimes_nested.html]
--DOMWINDOW == 35 (26CFDA20) [serial = 3039] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/indexedDB/test/test_transaction_ordering.html]
--DOMWINDOW == 34 (0C0F2BF8) [serial = 3043] [outer = 00000000] [url = about:blank]
--DOMWINDOW == 33 (265FE560) [serial = 3046] [outer = 00000000] [url = about:blank]
--DOMWINDOW == 32 (10B80690) [serial = 3050] [outer = 00000000] [url = about:blank]
--DOMWINDOW == 31 (222C6D48) [serial = 3053] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/media/tests/mochitest/test_getUserMedia_basicAudio.html]
--DOMWINDOW == 30 (21722098) [serial = 3054] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/media/tests/mochitest/test_getUserMedia_basicVideo.html]
--DOMWINDOW == 29 (09B92990) [serial = 3055] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/media/tests/mochitest/test_getUserMedia_basicVideoAudio.html]
--DOMWINDOW == 28 (2392F728) [serial = 3056] [outer = 0A02EE50] [url = http://mochi.test:8888/tests/dom/media/tests/mochitest/test_getUserMedia_exceptions.html]
[Parent 1700] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004003: file e:/builds/moz2_slave/m-cen-w32-dbg/build/intl/uconv/src/nsCharsetConverterManager.cpp, line 301
26102 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Calling createOffer on local peer connection
26103 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Calling setLocalDescription on local peer connection
26104 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Calling setRemoteDescription on remote peer connection
26105 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Calling createAnswer on remote peer connection
26106 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Calling setLocalDescription on remote peer connection
26107 INFO TEST-INFO | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Calling setRemoteDescription on local peer connection
26108 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcLocal.localDescription is not null
26109 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcLocal.localDescription type is offer
26110 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcLocal.localDescription body length is plausible
26111 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcLocal.remoteDescription is not null
26112 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcLocal.remoteDescription type is answer
26113 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcLocal.remoteDescription body length is plausible
26114 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcRemote.localDescription is not null
26115 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcRemote.localDescription type is answer
26116 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcRemote.localDescription body length is plausible
26117 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcRemote.remoteDescription is not null
26118 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcRemote.remoteDescription type is offer
26119 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcRemote.remoteDescription body length is plausible
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'Error: Peer connection is closed' when calling method: [nsIDOMRTCPeerConnection::localDescription]"  nsresult: "0x8057001c (NS_ERROR_XPC_JS_THREW_JS_OBJECT)"  location: "JS frame :: http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html :: onSuccess/onSuccess/< :: line 88"  data: no]
************************************************************
26120 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | attempt to access pcLocal.localDescription after close throws exception
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'Error: Peer connection is closed' when calling method: [nsIDOMRTCPeerConnection::remoteDescription]"  nsresult: "0x8057001c (NS_ERROR_XPC_JS_THREW_JS_OBJECT)"  location: "JS frame :: http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html :: onSuccess/onSuccess/< :: line 91"  data: no]
************************************************************
26121 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | attempt to access pcLocal.remoteDescription after close throws exception
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'Error: Peer connection is closed' when calling method: [nsIDOMRTCPeerConnection::localDescription]"  nsresult: "0x8057001c (NS_ERROR_XPC_JS_THREW_JS_OBJECT)"  location: "JS frame :: http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html :: onSuccess/onSuccess/< :: line 96"  data: no]
************************************************************
26122 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | attempt to access pcRemote.localDescription after close throws exception
************************************************************
* Call to xpconnect wrapped JSObject produced this error:  *
[Exception... "'Error: Peer connection is closed' when calling method: [nsIDOMRTCPeerConnection::remoteDescription]"  nsresult: "0x8057001c (NS_ERROR_XPC_JS_THREW_JS_OBJECT)"  location: "JS frame :: http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html :: onSuccess/onSuccess/< :: line 99"  data: no]
************************************************************
26123 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | attempt to access pcRemote.remoteDescription after close throws exception
26124 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | This test left crash dumps behind, but we weren't expecting it to!
26125 INFO TEST-INFO | Found unexpected crash dump file c:\docume~1\cltbld\locals~1\temp\tmpovugje\minidumps\1078d0cd-1cc2-4057-8982-c8913b0b9362.dmp.
nsStringStats
 => mAllocCount:        2396705
 => mReallocCount:       108350
 => mFreeCount:         2379792  --  LEAKED 16913 !!!
 => mShareCount:        4503515
 => mAdoptCount:         141238
 => mAdoptFreeCount:     141232  --  LEAKED 6 !!!
[Parent 1700] ###!!! ASSERTION: Wrong thread!: 'NS_IsMainThread()', file e:/builds/moz2_slave/m-cen-w32-dbg/build/dom/quota/QuotaManager.cpp, line 201
TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | application timed out after 330 seconds with no output

Comment 1

[Randell Jesup [:jesup] (needinfo me)]

The "Wrong Thread" assertion seems unrelated to the peerconnection test:

[Parent 1700] ###!!! ASSERTION: Wrong thread!: 'NS_IsMainThread()', file e:/builds/moz2_slave/m-cen-w32-dbg/build/dom/quota/QuotaManager.cpp, line 201

Comment 2

[Randell Jesup [:jesup] (needinfo me)]

Looks like "good" runs and this run produce identical output up to when you get a) failure to exit, followed by the Quota wrong-thread assertion.  While there's a good chance this is something in the peerconnection stuff deadlocking or waiting on a signal that's not coming, there's an outside chance the Quota assertion is a pointer to the real problem and we're merely the victim.

Someone involved in Quota should look at this.

"good" run: https://tbpl.mozilla.org/php/getParsedLog.php?id=19633700&tree=Firefox&full=1

Comment 3

[Randell Jesup [:jesup] (needinfo me)]

Per above, not a webrtc bug

Comment 4

[Randell Jesup [:jesup] (needinfo me)]

Sorry, to be more clear: need the quota people to weigh in on it.

If the assertion is a separate issue with quota, please keep this bug - outside of that assertion this would be a dup of an existing intermittent.

Comment 5

[Legacy TBPL/Treeherder Robot]

edmorley
https://tbpl.mozilla.org/php/getParsedLog.php?id=20295391&tree=Mozilla-Inbound
Rev3 WINNT 6.1 mozilla-inbound debug test mochitest-3 on 2013-03-04 05:06:25
slave: talos-r3-w7-058

05:12:01     INFO -  425 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Assertion count 251 is greater than expected range 0-200 assertions.

Comment 6

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

comment 5 is something different

Comment 7

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

(In reply to Randell Jesup [:jesup] from comment #2)
> Looks like "good" runs and this run produce identical output up to when you
> get a) failure to exit, followed by the Quota wrong-thread assertion.  While
> there's a good chance this is something in the peerconnection stuff
> deadlocking or waiting on a signal that's not coming, there's an outside
> chance the Quota assertion is a pointer to the real problem and we're merely
> the victim.
> 
> Someone involved in Quota should look at this.
> 
> "good" run:
> https://tbpl.mozilla.org/php/getParsedLog.php?id=19633700&tree=Firefox&full=1

This is just an artifact of the timeout killer.  The way we kill processes on Windows for timeouts results in attempting to run C++ destructors.  Those destructors are run on whatever thread we created to crash the process, which is never the main thread.  There's a static autoptr holding the QuotaManager, so when this happens we destroy it off the main thread and assert.

Back over to WebRTC.

Comment 8

[Ed Morley [:emorley]]

(In reply to Kyle Huey [:khuey] ([e-mail]) from comment #6)
> comment 5 is something different

Ah sorry, I didn't open the log; fed up of the mochitest-assert logs hanging my browser, so only open a percentage now.

Comment 9

[Legacy TBPL/Treeherder Robot]

bholley
https://tbpl.mozilla.org/php/getParsedLog.php?id=20340684&tree=Try
Rev3 WINNT 6.1 try debug test mochitest-3 on 2013-03-05 05:56:50
slave: talos-r3-w7-056

06:00:46     INFO -  399 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_peerConnection_bug825703.html | Assertion count 455 is greater than expected range 0-280 assertions.
06:00:49     INFO -  424 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Assertion count 271 is greater than expected range 0-200 assertions.

Comment 10

[Jan Varga [:janv]]

Thanks Kyle, your analysis sounds reasonable.

Comment 11

[Randell Jesup [:jesup] (needinfo me)]

So, this is basically a straightforward failure-to-exit for mochitest test_peerConnection_bug827843.   And given the log, it looks like sipcc may have failed to initialize.

The one star from 3/5 is on the wrong bug; that was the buffer_underrun bug.  this may now be fixed given startup fixes for sipcc that have landed.

-> abr

Comment 12

[Adam Roach [:abr]]

Reading through this bug, it appears that the crash happened once, two months ago, and has not resurfaced since. In the interim, we have landed scads of stability patches in the signaling code, so the issue has quite plausibly been fixed.

I can't really double-check whether the problem matches any known-and-closed issues, since this bug doesn't contain the stack extracted from the dump file. The log looks perfectly normal until we see the "...left crash dumps behind..." message, so there's no way to match it to an existing pathology.

I suggest that we close this one under the assumption that it's been fixed by one of the other stability patches. Maire: do you agree?

Comment 13

[Maire Reavy [:mreavy]]

I completely agree with Adam.  We should close this.  It is very likely that this with fixed when we landed all our clean up and stability patches over the last 2 months.

Comment 14

[Jason Smith [:jsmith]]

Fine by me as well.