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

RESOLVED FIXED in Firefox 65

Status

()

defect
P2
critical
Rank:
15
RESOLVED FIXED
4 months ago
3 months ago

People

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

Tracking

({crash, intermittent-failure})

unspecified
mozilla66
Points:
---

Firefox Tracking Flags

(firefox-esr60 unaffected, firefox64 unaffected, firefox65 fixed, firefox66 fixed)

Details

(Whiteboard: [retriggered], crash signature)

Attachments

(1 attachment)

(Reporter)

Description

4 months ago
treeherder
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)

Updated

3 months ago
Assignee: nobody → apehrson
Status: NEW → ASSIGNED
Rank: 15
Flags: needinfo?(apehrson)
Priority: P5 → P2
(Assignee)

Updated

3 months ago
Blocks: 1513973
Comment hidden (Intermittent Failures Robot)
(Assignee)

Updated

3 months ago
See Also: 1517941

Comment 6

3 months ago
Pushed by pehrsons@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/fc3e620149ec
Avoid calling SetPullingEnabled on a destroyed MediaStream. r=padenot
(Assignee)

Comment 7

3 months ago
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+

Comment 10

3 months ago
bugherder
https://hg.mozilla.org/mozilla-central/rev/fc3e620149ec
Status: ASSIGNED → RESOLVED
Last Resolved: 3 months 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)
(Assignee)

Updated

3 months ago
Duplicate of this bug: 1517960
(Assignee)

Comment 13

3 months ago

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)
(Assignee)

Updated

3 months ago
See Also: → 1517711
Comment hidden (Intermittent Failures Robot)
You need to log in before you can comment on or make changes to this bug.