Closed Bug 1517710 Opened 6 years ago Closed 6 years ago

Intermittent PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::MediaStreamGraphImpl::AppendMessage(mozilla::UniquePtr<mozilla::ControlMessage, mozilla::DefaultDelete<mozilla::ControlMessage> >)]

Categories

(Core :: WebRTC, defect, P2)

defect

Tracking

()

RESOLVED FIXED
mozilla66
Tracking Status
firefox-esr60 --- unaffected
firefox64 --- unaffected
firefox65 --- fixed
firefox66 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: pehrsons)

References

Details

(Keywords: crash, intermittent-failure, Whiteboard: [retriggered])

Crash Data

Attachments

(1 file)

Filed by: csabou [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=219938890&repo=autoland https://queue.taskcluster.net/v1/task/b1gA_T08Qsms5jnvgYvDSw/runs/0/artifacts/public/logs/live_backing.log [task 2019-01-04T10:41:18.946Z] 10:41:18 INFO - TEST-OK | dom/media/tests/mochitest/test_peerConnection_audioSynchronizationSources.html | took 6701ms [task 2019-01-04T10:41:18.982Z] 10:41:18 INFO - GECKO(1892) | JavaScript error: , line 0: InvalidStateError: An attempt was made to use an object that is not, or is no longer, usable [task 2019-01-04T10:41:18.986Z] 10:41:18 INFO - TEST-START | dom/media/tests/mochitest/test_peerConnection_audioSynchronizationSourcesUnidirectional.html [task 2019-01-04T10:41:19.164Z] 10:41:19 INFO - GECKO(1892) | TEST DEVICES: Got loopback audio: Monitor of Null Output [task 2019-01-04T10:41:19.165Z] 10:41:19 INFO - GECKO(1892) | TEST DEVICES: Got loopback video: Dummy video device (0x0000) [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | Timecard created 1546598472.567948 [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | Timestamp | Delta | Event | File | Function [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | ====================================================================================================================== [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 0.000024 | 0.000024 | Constructor Completed | PeerConnectionImpl.cpp:336 | PeerConnectionImpl [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 0.000418 | 0.000394 | Initializing PC Ctx | PeerConnectionImpl.cpp:456 | Initialize [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.366933 | 2.366515 | Create Offer | PeerConnectionImpl.cpp:1236 | CreateOffer [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.370290 | 0.003357 | Set Local Description | PeerConnectionImpl.cpp:1322 | SetLocalDescription [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.411034 | 0.040744 | Set Remote Description | PeerConnectionImpl.cpp:1424 | SetRemoteDescription [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.444904 | 0.033870 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2659 | IceGatheringStateChange [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.467184 | 0.022280 | Ice gathering state: complete | PeerConnectionImpl.cpp:2662 | IceGatheringStateChange [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.589809 | 0.122625 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.614435 | 0.024626 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.251Z] 10:41:19 INFO - GECKO(1892) | 2.637124 | 0.022689 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.253Z] 10:41:19 INFO - GECKO(1892) | 2.653749 | 0.016625 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.255Z] 10:41:19 INFO - GECKO(1892) | 2.655319 | 0.001570 | Ice state: checking | PeerConnectionImpl.cpp:2614 | IceConnectionStateChange [task 2019-01-04T10:41:19.256Z] 10:41:19 INFO - GECKO(1892) | 2.659799 | 0.004480 | Ice state: connected | PeerConnectionImpl.cpp:2617 | IceConnectionStateChange [task 2019-01-04T10:41:19.257Z] 10:41:19 INFO - GECKO(1892) | 6.669272 | 4.009473 | Destructor Invoked | PeerConnectionImpl.cpp:345 | ~PeerConnectionImpl [task 2019-01-04T10:41:19.257Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:370: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for bb19bf17d0173efb [task 2019-01-04T10:41:19.258Z] 10:41:19 INFO - GECKO(1892) | Timecard created 1546598472.573111 [task 2019-01-04T10:41:19.259Z] 10:41:19 INFO - GECKO(1892) | Timestamp | Delta | Event | File | Function [task 2019-01-04T10:41:19.259Z] 10:41:19 INFO - GECKO(1892) | ====================================================================================================================== [task 2019-01-04T10:41:19.260Z] 10:41:19 INFO - GECKO(1892) | 0.000160 | 0.000160 | Constructor Completed | PeerConnectionImpl.cpp:336 | PeerConnectionImpl [task 2019-01-04T10:41:19.261Z] 10:41:19 INFO - GECKO(1892) | 0.000727 | 0.000567 | Initializing PC Ctx | PeerConnectionImpl.cpp:456 | Initialize [task 2019-01-04T10:41:19.261Z] 10:41:19 INFO - GECKO(1892) | 2.373251 | 2.372524 | Set Remote Description | PeerConnectionImpl.cpp:1424 | SetRemoteDescription [task 2019-01-04T10:41:19.262Z] 10:41:19 INFO - GECKO(1892) | 2.398371 | 0.025120 | Create Answer | PeerConnectionImpl.cpp:1276 | CreateAnswer [task 2019-01-04T10:41:19.263Z] 10:41:19 INFO - GECKO(1892) | 2.401803 | 0.003432 | Set Local Description | PeerConnectionImpl.cpp:1322 | SetLocalDescription [task 2019-01-04T10:41:19.269Z] 10:41:19 INFO - GECKO(1892) | 2.461643 | 0.059840 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2659 | IceGatheringStateChange [task 2019-01-04T10:41:19.270Z] 10:41:19 INFO - GECKO(1892) | 2.462257 | 0.000614 | Ice gathering state: complete | PeerConnectionImpl.cpp:2662 | IceGatheringStateChange [task 2019-01-04T10:41:19.271Z] 10:41:19 INFO - GECKO(1892) | 2.471564 | 0.009307 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.274Z] 10:41:19 INFO - GECKO(1892) | 2.474203 | 0.002639 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.277Z] 10:41:19 INFO - GECKO(1892) | 2.476873 | 0.002670 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.279Z] 10:41:19 INFO - GECKO(1892) | 2.481505 | 0.004632 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.281Z] 10:41:19 INFO - GECKO(1892) | 2.489350 | 0.007845 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.283Z] 10:41:19 INFO - GECKO(1892) | 2.520282 | 0.030932 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.285Z] 10:41:19 INFO - GECKO(1892) | 2.547850 | 0.027568 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.287Z] 10:41:19 INFO - GECKO(1892) | 2.566523 | 0.018673 | Add Ice Candidate | PeerConnectionImpl.cpp:1594 | AddIceCandidate [task 2019-01-04T10:41:19.289Z] 10:41:19 INFO - GECKO(1892) | 2.649903 | 0.083380 | Ice state: checking | PeerConnectionImpl.cpp:2614 | IceConnectionStateChange [task 2019-01-04T10:41:19.290Z] 10:41:19 INFO - GECKO(1892) | 2.653330 | 0.003427 | Ice state: connected | PeerConnectionImpl.cpp:2617 | IceConnectionStateChange [task 2019-01-04T10:41:19.291Z] 10:41:19 INFO - GECKO(1892) | 6.664791 | 4.011461 | Destructor Invoked | PeerConnectionImpl.cpp:345 | ~PeerConnectionImpl [task 2019-01-04T10:41:19.293Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:370: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for ca8b6ea0de0e9d53 [task 2019-01-04T10:41:19.377Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:335: PeerConnectionImpl: PeerConnectionImpl constructor for [task 2019-01-04T10:41:19.387Z] 10:41:19 INFO - GECKO(1892) | [Parent 1892: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses [task 2019-01-04T10:41:19.388Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:335: PeerConnectionImpl: PeerConnectionImpl constructor for [task 2019-01-04T10:41:19.393Z] 10:41:19 INFO - GECKO(1892) | [Parent 1892: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses [task 2019-01-04T10:41:19.415Z] 10:41:19 INFO - GECKO(1892) | TEST DEVICES: Got loopback audio: Monitor of Null Output [task 2019-01-04T10:41:19.418Z] 10:41:19 INFO - GECKO(1892) | TEST DEVICES: Got loopback video: Dummy video device (0x0000) [task 2019-01-04T10:41:19.422Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:51: OnProxyAvailable: Proxy Available: 0 [task 2019-01-04T10:41:19.423Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:66: SetProxyOnPcm: Had proxyinfo [task 2019-01-04T10:41:19.425Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:51: OnProxyAvailable: Proxy Available: 0 [task 2019-01-04T10:41:19.427Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:66: SetProxyOnPcm: Had proxyinfo [task 2019-01-04T10:41:19.428Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:79: OnStunAddrsAvailable: receiving (5) stun addrs [task 2019-01-04T10:41:19.429Z] 10:41:19 INFO - GECKO(1892) | [Child 2009: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:79: OnStunAddrsAvailable: receiving (5) stun addrs [task 2019-01-04T10:41:19.531Z] 10:41:19 INFO - GECKO(1892) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x1E0087,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv [task 2019-01-04T10:41:19.589Z] 10:41:19 INFO - GECKO(1892) | A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down [task 2019-01-04T10:41:19.950Z] 10:41:19 INFO - GECKO(1892) | 1546598479939 Marionette TRACE Received observer notification xpcom-will-shutdown [task 2019-01-04T10:41:19.953Z] 10:41:19 INFO - GECKO(1892) | 1546598479939 Marionette INFO Stopped listening on port 2828 [task 2019-01-04T10:41:19.955Z] 10:41:19 INFO - GECKO(1892) | 1546598479939 Marionette DEBUG Remote service is inactive [task 2019-01-04T10:41:20.060Z] 10:41:20 INFO - TEST-INFO | Main app process: exit 0 [task 2019-01-04T10:41:20.060Z] 10:41:20 INFO - runtests.py | Application ran for: 0:03:22.472168 [task 2019-01-04T10:41:20.061Z] 10:41:20 INFO - zombiecheck | Reading PID log: /tmp/tmptUQEAIpidlog [task 2019-01-04T10:41:20.062Z] 10:41:20 INFO - ==> process 1892 launched child process 1917 [task 2019-01-04T10:41:20.063Z] 10:41:20 INFO - ==> process 1892 launched child process 1988 [task 2019-01-04T10:41:20.063Z] 10:41:20 INFO - ==> process 1892 launched child process 2009 [task 2019-01-04T10:41:20.064Z] 10:41:20 INFO - ==> process 1892 launched child process 2059 [task 2019-01-04T10:41:20.065Z] 10:41:20 INFO - ==> process 1892 launched child process 3018 [task 2019-01-04T10:41:20.066Z] 10:41:20 INFO - zombiecheck | Checking for orphan process with PID: 2009 [task 2019-01-04T10:41:20.067Z] 10:41:20 INFO - zombiecheck | Checking for orphan process with PID: 3018 [task 2019-01-04T10:41:20.067Z] 10:41:20 INFO - zombiecheck | Checking for orphan process with PID: 2059 [task 2019-01-04T10:41:20.068Z] 10:41:20 INFO - zombiecheck | Checking for orphan process with PID: 1988 [task 2019-01-04T10:41:20.069Z] 10:41:20 INFO - zombiecheck | Checking for orphan process with PID: 1917 [task 2019-01-04T10:41:20.070Z] 10:41:20 INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/Q5w4DW7XS5iPVAKKJ4NR7A/artifacts/public/build/target.crashreporter-symbols.zip [task 2019-01-04T10:41:27.776Z] 10:41:27 INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmpOyVm3Y.mozrunner/minidumps/59a89173-e37c-42a0-da6d-727d829b1e72.dmp /tmp/tmpcApQDk [task 2019-01-04T10:41:39.989Z] 10:41:39 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/59a89173-e37c-42a0-da6d-727d829b1e72.dmp [task 2019-01-04T10:41:39.991Z] 10:41:39 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/59a89173-e37c-42a0-da6d-727d829b1e72.extra [task 2019-01-04T10:41:40.092Z] 10:41:40 INFO - PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::MediaStreamGraphImpl::AppendMessage(mozilla::UniquePtr<mozilla::ControlMessage, mozilla::DefaultDelete<mozilla::ControlMessage> >)] [task 2019-01-04T10:41:40.092Z] 10:41:40 INFO - Crash dump filename: /tmp/tmpOyVm3Y.mozrunner/minidumps/59a89173-e37c-42a0-da6d-727d829b1e72.dmp [task 2019-01-04T10:41:40.092Z] 10:41:40 INFO - Operating system: Linux [task 2019-01-04T10:41:40.093Z] 10:41:40 INFO - 0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64 [task 2019-01-04T10:41:40.093Z] 10:41:40 INFO - CPU: amd64 [task 2019-01-04T10:41:40.094Z] 10:41:40 INFO - family 6 model 62 stepping 4 [task 2019-01-04T10:41:40.094Z] 10:41:40 INFO - 2 CPUs [task 2019-01-04T10:41:40.094Z] 10:41:40 INFO - [task 2019-01-04T10:41:40.095Z] 10:41:40 INFO - GPU: UNKNOWN [task 2019-01-04T10:41:40.095Z] 10:41:40 INFO - [task 2019-01-04T10:41:40.096Z] 10:41:40 INFO - Crash reason: SIGSEGV /SEGV_MAPERR [task 2019-01-04T10:41:40.096Z] 10:41:40 INFO - Crash address: 0x158 [task 2019-01-04T10:41:40.096Z] 10:41:40 INFO - Process uptime: not available [task 2019-01-04T10:41:40.097Z] 10:41:40 INFO - [task 2019-01-04T10:41:40.097Z] 10:41:40 INFO - Thread 0 (crashed) [task 2019-01-04T10:41:40.097Z] 10:41:40 INFO - 0 libxul.so!mozilla::MediaStreamGraphImpl::AppendMessage(mozilla::UniquePtr<mozilla::ControlMessage, mozilla::DefaultDelete<mozilla::ControlMessage> >) [atomic_base.h:777128d1fd48dff16999326fb8a475784a5de03a : 500 + 0x0] [task 2019-01-04T10:41:40.097Z] 10:41:40 INFO - rax = 0x7b5c9821241d2600 rdx = 0x00007f6036400020 [task 2019-01-04T10:41:40.098Z] 10:41:40 INFO - rcx = 0x00007f602c94b5b0 rbx = 0x0000000000000000 [task 2019-01-04T10:41:40.098Z] 10:41:40 INFO - rsi = 0x00007ffdd292d5c0 rdi = 0x0000000000000000 [task 2019-01-04T10:41:40.098Z] 10:41:40 INFO - rbp = 0x00007ffdd292d5b0 rsp = 0x00007ffdd292d570 [task 2019-01-04T10:41:40.099Z] 10:41:40 INFO - r8 = 0x0000000000000000 r9 = 0x0000000000000000 [task 2019-01-04T10:41:40.099Z] 10:41:40 INFO - r10 = 0x00007f6036400110 r11 = 0x0000000000000005 [task 2019-01-04T10:41:40.099Z] 10:41:40 INFO - r12 = 0x0000000000000000 r13 = 0x00000000ffffffff [task 2019-01-04T10:41:40.100Z] 10:41:40 INFO - r14 = 0x0000000000000000 r15 = 0x0000000000000002 [task 2019-01-04T10:41:40.100Z] 10:41:40 INFO - rip = 0x00007f602743212b [task 2019-01-04T10:41:40.100Z] 10:41:40 INFO - Found by: given as instruction pointer in context [task 2019-01-04T10:41:40.101Z] 10:41:40 INFO - 1 libxul.so!mozilla::SourceMediaStream::SetPullingEnabled(int, bool) [MediaStreamGraph.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 2533 + 0x8] [task 2019-01-04T10:41:40.101Z] 10:41:40 INFO - rbx = 0x00007f60176c6540 rbp = 0x00007ffdd292d5f0 [task 2019-01-04T10:41:40.101Z] 10:41:40 INFO - rsp = 0x00007ffdd292d5c0 r12 = 0x0000000000000000 [task 2019-01-04T10:41:40.102Z] 10:41:40 INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000000 [task 2019-01-04T10:41:40.102Z] 10:41:40 INFO - r15 = 0x0000000000000002 rip = 0x00007f6027437a54 [task 2019-01-04T10:41:40.102Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.103Z] 10:41:40 INFO - 2 libxul.so!mozilla::MediaEngineWebRTCMicrophoneSource::Stop(RefPtr<mozilla::AllocationHandle const> const&)::$_14::operator()() const [MediaEngineWebRTCAudio.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 621 + 0x7] [task 2019-01-04T10:41:40.103Z] 10:41:40 INFO - rbx = 0x00007f6014c1a8e0 rbp = 0x00007ffdd292d640 [task 2019-01-04T10:41:40.103Z] 10:41:40 INFO - rsp = 0x00007ffdd292d600 r12 = 0x00007f601fb121c0 [task 2019-01-04T10:41:40.104Z] 10:41:40 INFO - r13 = 0x00000000ffffffff r14 = 0x0000000000000000 [task 2019-01-04T10:41:40.104Z] 10:41:40 INFO - r15 = 0x0000000000000001 rip = 0x00007f60275e5655 [task 2019-01-04T10:41:40.104Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.105Z] 10:41:40 INFO - 3 libxul.so!mozilla::media::LambdaRunnable<mozilla::MediaEngineWebRTCMicrophoneSource::Stop(RefPtr<mozilla::AllocationHandle const> const&)::$_14>::Run() [MediaUtils.h:777128d1fd48dff16999326fb8a475784a5de03a : 73 + 0x9] [task 2019-01-04T10:41:40.105Z] 10:41:40 INFO - rbx = 0x0000000000000000 rbp = 0x00007ffdd292d650 [task 2019-01-04T10:41:40.105Z] 10:41:40 INFO - rsp = 0x00007ffdd292d650 r12 = 0x00007f601fb121c0 [task 2019-01-04T10:41:40.106Z] 10:41:40 INFO - r13 = 0x00000000ffffffff r14 = 0x00007f602cc6a4d8 [task 2019-01-04T10:41:40.106Z] 10:41:40 INFO - r15 = 0x0000000000000001 rip = 0x00007f60275e557d [task 2019-01-04T10:41:40.106Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.107Z] 10:41:40 INFO - 4 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 1157 + 0x6] [task 2019-01-04T10:41:40.107Z] 10:41:40 INFO - rbx = 0x0000000000000000 rbp = 0x00007ffdd292db80 [task 2019-01-04T10:41:40.108Z] 10:41:40 INFO - rsp = 0x00007ffdd292d660 r12 = 0x00007f601fb121c0 [task 2019-01-04T10:41:40.108Z] 10:41:40 INFO - r13 = 0x00000000ffffffff r14 = 0x00007f602cc6a4d8 [task 2019-01-04T10:41:40.108Z] 10:41:40 INFO - r15 = 0x0000000000000001 rip = 0x00007f602923e7df [task 2019-01-04T10:41:40.109Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.109Z] 10:41:40 INFO - 5 libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 468 + 0xd] [task 2019-01-04T10:41:40.109Z] 10:41:40 INFO - rbx = 0x0000000000000000 rbp = 0x00007ffdd292dbb0 [task 2019-01-04T10:41:40.110Z] 10:41:40 INFO - rsp = 0x00007ffdd292db90 r12 = 0x00007f6036394ba0 [task 2019-01-04T10:41:40.110Z] 10:41:40 INFO - r13 = 0x00007f6036394bc0 r14 = 0x00007ffdd292dd70 [task 2019-01-04T10:41:40.110Z] 10:41:40 INFO - r15 = 0x0000000000000001 rip = 0x00007f602924063a [task 2019-01-04T10:41:40.111Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.111Z] 10:41:40 INFO - 6 libxul.so!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [MessagePump.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 88 + 0xb] [task 2019-01-04T10:41:40.111Z] 10:41:40 INFO - rbx = 0x0000000000000001 rbp = 0x00007ffdd292dbf0 [task 2019-01-04T10:41:40.112Z] 10:41:40 INFO - rsp = 0x00007ffdd292dbc0 r12 = 0x00007f6036394ba0 [task 2019-01-04T10:41:40.112Z] 10:41:40 INFO - r13 = 0x00007f6036394bc0 r14 = 0x00007ffdd292dd70 [task 2019-01-04T10:41:40.112Z] 10:41:40 INFO - r15 = 0x0000000000000001 rip = 0x00007f60293e0523 [task 2019-01-04T10:41:40.113Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.113Z] 10:41:40 INFO - 7 libxul.so!MessageLoop::Run() [message_loop.cc:777128d1fd48dff16999326fb8a475784a5de03a : 314 + 0x8] [task 2019-01-04T10:41:40.114Z] 10:41:40 INFO - rbx = 0x00007f601fb2cf40 rbp = 0x00007ffdd292dc20 [task 2019-01-04T10:41:40.114Z] 10:41:40 INFO - rsp = 0x00007ffdd292dc00 r12 = 0x00007ffdd292e098 [task 2019-01-04T10:41:40.114Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x00007f601fb121c0 [task 2019-01-04T10:41:40.115Z] 10:41:40 INFO - r15 = 0x0000000080004005 rip = 0x00007f60293cd6d2 [task 2019-01-04T10:41:40.115Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.116Z] 10:41:40 INFO - 8 libxul.so!nsBaseAppShell::Run() [nsBaseAppShell.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 137 + 0x8] [task 2019-01-04T10:41:40.116Z] 10:41:40 INFO - rbx = 0x00007f601fb2cf40 rbp = 0x00007ffdd292dc40 [task 2019-01-04T10:41:40.117Z] 10:41:40 INFO - rsp = 0x00007ffdd292dc30 r12 = 0x00007ffdd292e098 [task 2019-01-04T10:41:40.117Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x00007f601fb121c0 [task 2019-01-04T10:41:40.118Z] 10:41:40 INFO - r15 = 0x0000000080004005 rip = 0x00007f60279fb0e9 [task 2019-01-04T10:41:40.118Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.119Z] 10:41:40 INFO - 9 libxul.so!XRE_RunAppShell() [nsEmbedFunctions.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 915 + 0x6] [task 2019-01-04T10:41:40.119Z] 10:41:40 INFO - rbx = 0x00007f603636d000 rbp = 0x00007ffdd292dc70 [task 2019-01-04T10:41:40.120Z] 10:41:40 INFO - rsp = 0x00007ffdd292dc50 r12 = 0x00007ffdd292e098 [task 2019-01-04T10:41:40.120Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x0000000000000764 [task 2019-01-04T10:41:40.121Z] 10:41:40 INFO - r15 = 0x0000000080004005 rip = 0x00007f6028a1b964 [task 2019-01-04T10:41:40.121Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.122Z] 10:41:40 INFO - 10 libxul.so!MessageLoop::Run() [message_loop.cc:777128d1fd48dff16999326fb8a475784a5de03a : 314 + 0x8] [task 2019-01-04T10:41:40.123Z] 10:41:40 INFO - rbx = 0x00007f603636d000 rbp = 0x00007ffdd292dca0 [task 2019-01-04T10:41:40.123Z] 10:41:40 INFO - rsp = 0x00007ffdd292dc80 r12 = 0x00007ffdd292e098 [task 2019-01-04T10:41:40.124Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x0000000000000764 [task 2019-01-04T10:41:40.124Z] 10:41:40 INFO - r15 = 0x0000000080004005 rip = 0x00007f60293cd6d2 [task 2019-01-04T10:41:40.125Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.125Z] 10:41:40 INFO - 11 libxul.so!XRE_InitChildProcess(int, char**, XREChildData const*) [nsEmbedFunctions.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 753 + 0x5] [task 2019-01-04T10:41:40.126Z] 10:41:40 INFO - rbx = 0x00007f603636d000 rbp = 0x00007ffdd292df40 [task 2019-01-04T10:41:40.126Z] 10:41:40 INFO - rsp = 0x00007ffdd292dcb0 r12 = 0x00007ffdd292e098 [task 2019-01-04T10:41:40.127Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x0000000000000764 [task 2019-01-04T10:41:40.128Z] 10:41:40 INFO - r15 = 0x0000000080004005 rip = 0x00007f6028a1b74c [task 2019-01-04T10:41:40.128Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.129Z] 10:41:40 INFO - 12 firefox-bin!content_process_main(mozilla::Bootstrap*, int, char**) [plugin-container.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 49 + 0x12] [task 2019-01-04T10:41:40.129Z] 10:41:40 INFO - rbx = 0x0000000000000015 rbp = 0x00007ffdd292df80 [task 2019-01-04T10:41:40.130Z] 10:41:40 INFO - rsp = 0x00007ffdd292df50 r12 = 0x0000077f328d11d2 [task 2019-01-04T10:41:40.130Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x00007ffdd292e098 [task 2019-01-04T10:41:40.131Z] 10:41:40 INFO - r15 = 0x00007f6036329720 rip = 0x00005622794e56e9 [task 2019-01-04T10:41:40.132Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.132Z] 10:41:40 INFO - 13 firefox-bin!main [nsBrowserApp.cpp:777128d1fd48dff16999326fb8a475784a5de03a : 265 + 0xa] [task 2019-01-04T10:41:40.133Z] 10:41:40 INFO - rbx = 0x0000000000000016 rbp = 0x00007ffdd292dfb0 [task 2019-01-04T10:41:40.133Z] 10:41:40 INFO - rsp = 0x00007ffdd292df90 r12 = 0x0000077f328d11d2 [task 2019-01-04T10:41:40.134Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x00007ffdd292e098 [task 2019-01-04T10:41:40.134Z] 10:41:40 INFO - r15 = 0x00007ffdd292e150 rip = 0x00005622794e5821 [task 2019-01-04T10:41:40.135Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.135Z] 10:41:40 INFO - 14 libc-2.23.so + 0x20830 [task 2019-01-04T10:41:40.136Z] 10:41:40 INFO - rbx = 0x0000000000000000 rbp = 0x000056227950e7e0 [task 2019-01-04T10:41:40.136Z] 10:41:40 INFO - rsp = 0x00007ffdd292dfc0 r12 = 0x000056227950037c [task 2019-01-04T10:41:40.137Z] 10:41:40 INFO - r13 = 0x00007ffdd292e090 r14 = 0x0000000000000000 [task 2019-01-04T10:41:40.137Z] 10:41:40 INFO - r15 = 0x0000000000000000 rip = 0x00007f6036566830 [task 2019-01-04T10:41:40.138Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.139Z] 10:41:40 INFO - 15 firefox-bin + 0x86f0 [task 2019-01-04T10:41:40.139Z] 10:41:40 INFO - rsp = 0x00007ffdd292dfc8 rip = 0x00005622794e66f0 [task 2019-01-04T10:41:40.140Z] 10:41:40 INFO - Found by: stack scanning [task 2019-01-04T10:41:40.140Z] 10:41:40 INFO - 16 firefox-bin + 0x7740 [task 2019-01-04T10:41:40.141Z] 10:41:40 INFO - rsp = 0x00007ffdd292dfe0 rip = 0x00005622794e5740 [task 2019-01-04T10:41:40.141Z] 10:41:40 INFO - Found by: stack scanning [task 2019-01-04T10:41:40.142Z] 10:41:40 INFO - 17 firefox-bin!double_conversion::Bignum::Bignum() [bignum.cc:777128d1fd48dff16999326fb8a475784a5de03a : 38 + 0x5] [task 2019-01-04T10:41:40.142Z] 10:41:40 INFO - rsp = 0x00007ffdd292dff8 rip = 0x000056227950037c [task 2019-01-04T10:41:40.143Z] 10:41:40 INFO - Found by: stack scanning [task 2019-01-04T10:41:40.143Z] 10:41:40 INFO - 18 0x7ffdd292e090 [task 2019-01-04T10:41:40.144Z] 10:41:40 INFO - rbx = 0x0000000000000000 rbp = 0x000056227950037c [task 2019-01-04T10:41:40.144Z] 10:41:40 INFO - rsp = 0x00007ffdd292e000 r14 = 0x5a83a5c37b804d48 [task 2019-01-04T10:41:40.145Z] 10:41:40 INFO - rip = 0x00007ffdd292e090 [task 2019-01-04T10:41:40.146Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.146Z] 10:41:40 INFO - 19 firefox-bin + 0x7740 [task 2019-01-04T10:41:40.147Z] 10:41:40 INFO - rsp = 0x00007ffdd292e048 rip = 0x00005622794e5740 [task 2019-01-04T10:41:40.147Z] 10:41:40 INFO - Found by: stack scanning [task 2019-01-04T10:41:40.148Z] 10:41:40 INFO - 20 firefox-bin + 0x307d0 [task 2019-01-04T10:41:40.151Z] 10:41:40 INFO - rsp = 0x00007ffdd292e050 rip = 0x000056227950e7d0 [task 2019-01-04T10:41:40.152Z] 10:41:40 INFO - Found by: stack scanning [task 2019-01-04T10:41:40.153Z] 10:41:40 INFO - 21 firefox-bin!double_conversion::Bignum::Bignum() [bignum.cc:777128d1fd48dff16999326fb8a475784a5de03a : 38 + 0x5] [task 2019-01-04T10:41:40.153Z] 10:41:40 INFO - rsp = 0x00007ffdd292e068 rip = 0x000056227950037c [task 2019-01-04T10:41:40.154Z] 10:41:40 INFO - Found by: stack scanning [task 2019-01-04T10:41:40.154Z] 10:41:40 INFO - 22 0x7ffdd292e090 [task 2019-01-04T10:41:40.155Z] 10:41:40 INFO - rbx = 0x0000000000000000 rbp = 0x000056227950037c [task 2019-01-04T10:41:40.156Z] 10:41:40 INFO - rsp = 0x00007ffdd292e070 r14 = 0x0000000000000000 [task 2019-01-04T10:41:40.157Z] 10:41:40 INFO - rip = 0x00007ffdd292e090 [task 2019-01-04T10:41:40.158Z] 10:41:40 INFO - Found by: call frame info [task 2019-01-04T10:41:40.158Z] 10:41:40 INFO - 23 firefox-bin!_start + 0x29 [task 2019-01-04T10:41:40.159Z] 10:41:40 INFO - rsp = 0x00007ffdd292e080 rip = 0x00005622795003a5 [task 2019-01-04T10:41:40.160Z] 10:41:40 INFO - Found by: stack scanning
Assignee: nobody → apehrson
Status: NEW → ASSIGNED
Rank: 15
Flags: needinfo?(apehrson)
Priority: P5 → P2
Blocks: 1513973
See Also: → 1517941
See Also: 1517941
Pushed by pehrsons@gmail.com: https://hg.mozilla.org/integration/autoland/rev/fc3e620149ec Avoid calling SetPullingEnabled on a destroyed MediaStream. r=padenot
Comment on attachment 9034642 [details] Bug 1517710 - Avoid calling SetPullingEnabled on a destroyed MediaStream. r?padenot [Beta/Release Uplift Approval Request] Feature/Bug causing the regression: Bug 1513973 User impact if declined: Null pointer crashes when doing microphone capture Is this code covered by automated tests?: Yes Has the fix been verified in Nightly?: No Needs manual test from QE?: No If yes, steps to reproduce: List of other uplifts needed: None Risk to taking this patch: Low Why is the change risky/not risky? (and alternatives if risky): Trivial change moving a call to be behind an existing if-statement that's meant to protect from the kind of crash we're seeing here. The ordering change is insignificant as all these events will be applied between the same two MediaStreamGraph iterations. String changes made/needed:
Attachment #9034642 - Flags: approval-mozilla-beta?
Comment on attachment 9034642 [details] Bug 1517710 - Avoid calling SetPullingEnabled on a destroyed MediaStream. r?padenot [Triage Comment] Fixes a crash caused by bug 1513973. Approved for 65.0b9.
Attachment #9034642 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla66

Bug 1518043 just hit again on Beta tip (which would have included this uplift). Not sure this is really fixed.
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=220383590&repo=mozilla-beta&lineNumber=11799

Flags: needinfo?(apehrson)
Blocks: 1517960

It would have been real nice if it had walked the stack too, but I got it after some fiddling around:

(gdb) bt
#0  0x000055f1f7d0690e in mozilla::detail::MutexImpl::lock() ()
#1  0x00007fed0de1b66c in mozilla::OffTheBooksMutex::Lock() () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#2  0x00007fed0fde1b8d in mozilla::SourceMediaStream::SetPullingEnabled(int, bool)::Message::Run() () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#3  0x00007fed0fdd130c in mozilla::MediaStreamGraphImpl::RunMessagesInQueue() () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#4  0x00007fed0fdd2839 in mozilla::MediaStreamGraphImpl::OneIteration(long) () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#5  0x00007fed0fcffce5 in mozilla::ThreadedDriver::RunThread() () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#6  0x00007fed0fd0b6f1 in mozilla::MediaStreamGraphInitThreadRunnable::Run() () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#7  0x00007fed0de39334 in nsThread::ProcessNextEvent(bool, bool*) () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#8  0x00007fed0de3b98f in NS_ProcessNextEvent(nsIThread*, bool) () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#9  0x00007fed0e32cd3b in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#10 0x00007fed0e2ec36b in MessageLoop::RunInternal() () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#11 0x00007fed0e2ec2c6 in MessageLoop::Run() () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#12 0x00007fed0de3705e in nsThread::ThreadFunc(void*) () from /home/pehrsons/dev/bug1517710/firefox/libxul.so
#13 0x00007fed20534250 in _pt_root () from /home/pehrsons/dev/bug1517710/firefox/libnspr4.so

This is a different failure mode, and bug 1517711, bug 1517844, bug 1517845, bug 1517913, and bug 1517990 are symptoms of this mode, rather than the one I fixed here (AppendMessage()). They're probably heavily related, but let's still take the fix to bug 1517711.

I'll take the fix to bug 1517711.

No longer blocks: 1517844, 1517845, 1517913, 1517990, 1517960
Flags: needinfo?(apehrson)
See Also: → 1517711
See Also: → 1690524
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: