842749 - Assertion-failure in RUN_ON_THREAD in PeerConnectionMedia::SelfDestruct

Status: RESOLVED FIXED

(Core :: WebRTC: Signaling, defect)

Description

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

Attachment: Callstack, vars and output

While trying to reproduce Bug 835023, I'm seeing a class of bugs that feel a bit like exiting a moving car. They involve spinning up a bunch of PeerConnections and then quitting the browser while they're still churning.

Reproduce steps:
1. Open URL
2. Quit the browser within 10 seconds or so.

When running in the debugger, this always either hangs or produces asserts.

Once, I saw it hang. In that case the main thread was in ReentrantMonitor::Wait, along with most threads except the STS thread, the GSM thread and one other (!)

But on most runs I see the assert in the subject and attachment, which is really weird:

  RefPtr<nsIRunnable> runnable_ref(runnable);
  if (thread) {
    bool on;
    nsresult rv;
    rv = thread->IsOnCurrentThread(&on);
=>  MOZ_ASSERT(NS_SUCCEEDED(rv));       <Thread 1: EXC_BAD_ACCESS (code=1, address=0x0)
    NS_ENSURE_SUCCESS(rv, rv);
    if(!on) {
      return thread->Dispatch(runnable_ref, flags);
    }
  }
  return runnable_ref->Run();
}

rv	nsresult	NS_ERROR_NOT_INITIALIZED

Comment 1

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

Attachment: Output from another run with nsSocketTransport:5

The reason it fails is because we've survived the Socket thread (see "STS thread exit" in this output), and there are still "PeerConnectionImpl Close" calls happening.

Detail: The NS_ERROR_NOT_INITIALIZED came from http://mxr.mozilla.org/mozilla-central/source/netwerk/base/src/nsSocketTransportService2.cpp#126 :

NS_IMETHODIMP
nsSocketTransportService::IsOnCurrentThread(bool *result)
{
    nsCOMPtr<nsIThread> thread = GetThreadSafely();
+   if (!thread) {
+ =>  MOZ_CRASH();
+   }
    NS_ENSURE_TRUE(thread, NS_ERROR_NOT_INITIALIZED);
    return thread->IsOnCurrentThread(result);
}

The NS_ENSURE_TRUE is in the original output as well, though I wish that macro had been noisier.

Comment 2

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

Attachment: Output with "this =" printfs, showing problem PC was never closed

The asserting PC here is 0x100542ae0, which was never closed (looks like all the other ones were).

Comment 3

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

Attachment: Work in progress patch

Comment 4

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

I talked with khuey/ekr/derf/smaug/ms2ger today, and as I suspected, the likely culprit with the loop back into the JS observer is due to NS_DISPATCH_SYNC being used from MainThread to a non-MainThread thread

Comment 5

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

Attachment: Output showing JS re-entrancy happening

With the dump() statements from the Work In Progress patch here, we observe JS re-entrancy during shutdown (quitting the browser while on the page in the URL):

...
PCJS: queueOrRun _pc.createOffer...
PCJS:   queueOrRun QUEUED function createOffer().
PCJS: ...out the other end of _pc.createOffer.
PCJS: queueOrRun _pc.initialize...
PCJS:   queueOrRun DOING function initialize() directly...
PCJS:   ...queueOrRun done with function initialize() directly.
PCJS: ...out the other end of _pc.initialize.
PCJS: queueOrRun _pc.createOffer...
PCJS:   queueOrRun QUEUED function createOffer().
PCJS: ...out the other end of _pc.createOffer.
PCJS: queueOrRun _pc.initialize...
PCJS:   queueOrRun DOING function initialize() directly...
PCJS:   executeNext doing function createOffer()...
PCJS:   ...executeNext done with function createOffer().
PCJS:   executeNext doing function createOffer()...
PCJS:   ...executeNext done with function createOffer().
PCJS:   executeNext doing function createOffer()...
PCJS:   ...executeNext done with function createOffer().
PCJS:   executeNext doing function createOffer()...
PCJS:   ...executeNext done with function createOffer().
PCJS:   executeNext doing function createOffer()...
PCJS:   ...executeNext done with function createOffer().
PCJS:   executeNext doing function createOffer()...
PCJS:   ...executeNext done with function createOffer().
PCJS:   executeNext doing function createOffer()...
PCJS:   ...executeNext done with function createOffer().
PCJS: WINDOW DESTROY!!!
PCJS: Window destroy done.
Assertion failure: on, at /Users/Jan/moz/mozilla-central/obj-x86_64-apple-darwin12.2.1-debug/media/mtransport/build/nr_timer.cpp:118
(lldb) 

The WINDOW DESTROY observer JS code executes before the queueOrRun _pc.initialize JS call has returned.

Comment 6

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

Attachment: Output verifying culprit is NS_SYNC_DISPATCH

Callstack of breakpoint in PeerConnection::Close. Frame 59 shows what led mainthread to execute the WINDOW DESTROY observer JS:

#59: in sipcc::PeerConnectionMedia::Init(), line 127:

  // Start gathering
  nsresult res;
  mIceCtx->thread()->Dispatch(WrapRunnableRet(
    mIceCtx, &NrIceCtx::StartGathering, &res), NS_DISPATCH_SYNC
  );

Comment 8

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

Attachment: Work in progress patch (2)

Refreshed stale patch. Expect it'll be useful to verify things after sync patches land.

Comment 9

[Maire Reavy [:mreavy]]

Jan-Ivar, can you retest now that Bug 844493 is fixed?

Comment 10

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

I've verified that the JS re-entrancy and the assert reported here are fixed by Bug 84493.

However, I now find that it hangs if I manage to quit before the test is done. :-(
I'm closing this as fixed and I've filed Bug 855498 for the new hang, since the cause is likely different.

Comment 11

[Maire Reavy [:mreavy]]

Fixed by other bugs.  See Comment 10.  Clearing webrtc-uplift flag.