849010 - Intermittent test_peerConnection_bug827843.html | Exited with code 1 during test run | application crashed [@ 0x7fffffe001a0]

Status: RESOLVED WORKSFORME

(Core :: WebRTC: Signaling, defect)

Description

[Ryan VanderMeulen [:RyanVM]]

+++ This bug was initially created as a clone of Bug #848966 +++

Not sure if this is related to bug 848966 or not.

https://tbpl.mozilla.org/php/getParsedLog.php?id=20433897&tree=Mozilla-Inbound

Rev4 MacOSX Snow Leopard 10.6 mozilla-inbound debug test mochitest-2 on 2013-03-07 13:25:44 PST for push b57e338dd933
slave: talos-r4-snow-078

13:53:04     INFO -  26812 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | pcRemote.remoteDescription body length is plausible
13:53:04     INFO -  ************************************************************
13:53:04     INFO -  * Call to xpconnect wrapped JSObject produced this error:  *
13:53:04     INFO -  [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 92"  data: no]
13:53:04     INFO -  ************************************************************
13:53:04     INFO -  26813 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | attempt to access pcLocal.localDescription after close throws exception
13:53:04     INFO -  ************************************************************
13:53:04     INFO -  * Call to xpconnect wrapped JSObject produced this error:  *
13:53:04     INFO -  [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 95"  data: no]
13:53:04     INFO -  ************************************************************
13:53:04     INFO -  26814 INFO TEST-PASS | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | attempt to access pcLocal.remoteDescription after close throws exception
13:53:06  WARNING -  TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | Exited with code 1 during test run
13:53:06  WARNING -  This is a harness error.
13:53:06     INFO -  INFO | automation.py | Application ran for: 0:26:24.349812
13:53:06     INFO -  INFO | automation.py | Reading PID log: /var/folders/Hs/HsDn6a9SG8idoIya6p9mtE+++TI/-Tmp-/tmpfZhMETpidlog
13:53:23     INFO -  PROCESS-CRASH | /tests/dom/media/tests/mochitest/test_peerConnection_bug827843.html | application crashed [@ 0x7fffffe001a0]
13:53:23     INFO -  Crash dump filename: /var/folders/Hs/HsDn6a9SG8idoIya6p9mtE+++TI/-Tmp-/tmpk85BbH/minidumps/4FCAEF6C-4BC3-4B23-B265-8F8C76173915.dmp
13:53:23     INFO -  Operating system: Mac OS X
13:53:23     INFO -                    10.6.8 10K549
13:53:23     INFO -  CPU: amd64
13:53:23     INFO -       family 6 model 23 stepping 10
13:53:23     INFO -       2 CPUs
13:53:23     INFO -  Crash reason:  EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
13:53:23     INFO -  Crash address: 0x154
13:53:23     INFO -  Thread 4 (crashed)
13:53:23     INFO -   0  0x7fffffe001a0
13:53:23     INFO -      rbx = 0x000000015deba5e0   r12 = 0x000000015098c920
13:53:23     INFO -      r13 = 0x0000000000000630   r14 = 0x000000000000015c
13:53:23     INFO -      r15 = 0x0000000000000154   rip = 0x00007fffffe001a0
13:53:23     INFO -      rsp = 0x0000000106006f40   rbp = 0x0000000106007030
13:53:23     INFO -      Found by: given as instruction pointer in context
13:53:23     INFO -   1  libSystem.B.dylib + 0x617d
13:53:23     INFO -      rip = 0x00007fff828c817e   rsp = 0x0000000106006f48
13:53:23     INFO -      rbp = 0x0000000106007030
13:53:23     INFO -      Found by: stack scanning
13:53:23     INFO -   2  XUL!sctp_add_to_readq [sctputil.c:b57e338dd933 : 4736 + 0x19]
13:53:23     INFO -      rip = 0x00000001011ff17c   rsp = 0x0000000106006f50
13:53:23     INFO -      rbp = 0x0000000106007030
13:53:23     INFO -      Found by: stack scanning
13:53:23     INFO -   3  libSystem.B.dylib + 0x2c87
13:53:23     INFO -      rip = 0x00007fff828c4c88   rsp = 0x0000000106006fd0
13:53:23     INFO -      rbp = 0x0000000106007030
13:53:23     INFO -      Found by: stack scanning
13:53:23     INFO -   4  libSystem.B.dylib + 0x617d
13:53:23     INFO -      rip = 0x00007fff828c817e   rsp = 0x0000000106006fe8
13:53:23     INFO -      rbp = 0x0000000106007030
13:53:23     INFO -      Found by: stack scanning
13:53:23     INFO -   5  XUL!sctp_build_readq_entry [sctp_indata.c:b57e338dd933 : 147 + 0x7]
13:53:23     INFO -      rip = 0x00000001011bc289   rsp = 0x0000000106006ff0
13:53:23     INFO -      rbp = 0x0000000106007030
13:53:23     INFO -      Found by: stack scanning
13:53:23     INFO -   6  XUL!sctp_ulp_notify [sctputil.c:b57e338dd933 : 3185 + 0x1b]
13:53:23     INFO -      rip = 0x00000001011ff958   rsp = 0x0000000106007040
13:53:23     INFO -      rbp = 0x00000001060070f0
13:53:23     INFO -      Found by: stack scanning

Comment 1

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

Attachment: Full stack of the crashed thread

Comment 2

[Ryan VanderMeulen [:RyanVM]]

https://tbpl.mozilla.org/php/getParsedLog.php?id=20443646&tree=Mozilla-Inbound

Yikes.

Comment 3

[Adam Roach [:abr]]

Yikes, indeed. I wonder why we're logging this successful condition as an error:

  CSFLogError(logTag, "%s Inserted A Frame", __FUNCTION__);
  return kMediaConduitNoError;

Comment 4

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

(In reply to Adam Roach [:abr] from comment #3)
> Yikes, indeed. I wonder why we're logging this successful condition as an
> error:
> 
>   CSFLogError(logTag, "%s Inserted A Frame", __FUNCTION__);
>   return kMediaConduitNoError;

We shouldn't be.

And this looks like another instance of failure to shut down.  SIPCC believes it cleared the call, the app closed both pc's, but it's still sending video frames. until it gets killed.

Probably a dup of some other failure-to-exit cases (perhaps for audio).  It does appear that sipcc thinks the call is over, so it should have released things; but media is never shut down.  I'll attached the start of the problem. 

Also note that RTCP sends start failing almost immediatedly, and eventually it stops trying to send.

Comment 5

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

Attachment: Snippet of log showing the start of the problem

Comment 7

[Jan-Ivar Bruaroey [:jib] (needinfo? me)]

Any sign of this?

Comment 8

[Jason Smith [:jsmith]]

Hasn't been seen in over 2 months. Closing, but reopen if this still reproduces.