Closed Bug 1414829 Opened 2 years ago Closed 2 years ago

IntermittentGECKO(3199) | SUMMARY: AddressSanitizer: heap-use-after-free /builds/worker/workspace/build/src/clang/bin/../lib/gcc/x86_64-unknown-linux-gnu/4.9.4/../../../../include/c++/4.9.4/bits/stl_iterator.h:729:20 in __normal_iterator

Categories

(Core :: WebRTC: Audio/Video, defect, P1)

defect

Tracking

()

RESOLVED FIXED
mozilla62
Tracking Status
firefox-esr52 - wontfix
firefox-esr60 61+ fixed
firefox57 --- wontfix
firefox58 --- wontfix
firefox59 --- wontfix
firefox60 --- wontfix
firefox61 + fixed
firefox62 + fixed

People

(Reporter: aryx, Assigned: dminor)

References

Details

(Keywords: csectype-uaf, sec-high, Whiteboard: [adv-main61+][adv-esr60.1+][post-critsmash-triage])

Attachments

(2 files, 1 obsolete file)

https://treeherder.mozilla.org/logviewer.html#?job_id=142403163&repo=autoland

[task 2017-11-06T12:46:50.225Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:3132: CloseInt: Closing PeerConnectionImpl aa4a2aaad1408cec; ending call
[task 2017-11-06T12:46:50.226Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/jsep [1509972405190309 (id=2147483788 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_peerConnection_addSecondVideoSt]: stable -> closed
[task 2017-11-06T12:46:50.233Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:603: Destroying MediaPipeline: 9bca4110d9e62064| Transmit video[{cd0153f5-588a-46ab-b558-7c148c9d728c}]
[task 2017-11-06T12:46:50.234Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:603: Destroying MediaPipeline: 9bca4110d9e62064| Transmit video[{1db1e6bf-5eb1-42a9-a795-aef590af1ee0}]
[task 2017-11-06T12:46:50.236Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:603: Destroying MediaPipeline: 9bca4110d9e62064| Receive video[{67bf3bdf-abf2-4ecd-908b-7274bf6ec059}]
[task 2017-11-06T12:46:50.237Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:603: Destroying MediaPipeline: aa4a2aaad1408cec| Transmit video[{67bf3bdf-abf2-4ecd-908b-7274bf6ec059}]
[task 2017-11-06T12:46:50.238Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:603: Destroying MediaPipeline: aa4a2aaad1408cec| Receive video[{cd0153f5-588a-46ab-b558-7c148c9d728c}]
[task 2017-11-06T12:46:50.240Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: I/signaling [main|MediaPipeline] MediaPipeline.cpp:603: Destroying MediaPipeline: aa4a2aaad1408cec| Receive video[{1db1e6bf-5eb1-42a9-a795-aef590af1ee0}]
[task 2017-11-06T12:46:50.242Z] 12:46:50     INFO - GECKO(3199) | [MediaStreamGrph]: I/signaling [MediaStreamGrph|MediaPipeline] MediaPipeline.cpp:1822: MediaPipeline::NotifyDirectListenerUninstalled() listener=0x60c00068e3c0
[task 2017-11-06T12:46:50.243Z] 12:46:50     INFO - GECKO(3199) | [MediaStreamGrph]: I/signaling [MediaStreamGrph|MediaPipeline] MediaPipeline.cpp:1822: MediaPipeline::NotifyDirectListenerUninstalled() listener=0x60c0007b0e80
[task 2017-11-06T12:46:50.245Z] 12:46:50     INFO - GECKO(3199) | [MediaStreamGrph]: I/signaling [MediaStreamGrph|MediaPipeline] MediaPipeline.cpp:1822: MediaPipeline::NotifyDirectListenerUninstalled() listener=0x60c00077af40
[task 2017-11-06T12:46:50.263Z] 12:46:50     INFO - GECKO(3199) | [Main Thread]: E/signaling [main|WebrtcVideoSessionConduit] VideoConduit.cpp:1209: SyncTo called with no receive stream
[task 2017-11-06T12:46:50.284Z] 12:46:50     INFO - GECKO(3199) | MEMORY STAT | vsize 20974062MB | residentFast 1199MB
[task 2017-11-06T12:46:50.285Z] 12:46:50     INFO - GECKO(3199) | =================================================================
[task 2017-11-06T12:46:50.286Z] 12:46:50    ERROR - GECKO(3199) | ==3250==ERROR: AddressSanitizer: heap-use-after-free on address 0x61a0009900e8 at pc 0x7f6756f87cb1 bp 0x7ffee4d42370 sp 0x7ffee4d42368
[task 2017-11-06T12:46:50.287Z] 12:46:50     INFO - GECKO(3199) | READ of size 8 at 0x61a0009900e8 thread T0 (Web Content)
[task 2017-11-06T12:46:50.759Z] 12:46:50     INFO - GECKO(3199) |     #0 0x7f6756f87cb0 in __normal_iterator /builds/worker/workspace/build/src/clang/bin/../lib/gcc/x86_64-unknown-linux-gnu/4.9.4/../../../../include/c++/4.9.4/bits/stl_iterator.h:729:20
[task 2017-11-06T12:46:50.761Z] 12:46:50     INFO - GECKO(3199) |     #1 0x7f6756f87cb0 in begin /builds/worker/workspace/build/src/clang/bin/../lib/gcc/x86_64-unknown-linux-gnu/4.9.4/../../../../include/c++/4.9.4/bits/stl_vector.h:548
[task 2017-11-06T12:46:50.763Z] 12:46:50     INFO - GECKO(3199) |     #2 0x7f6756f87cb0 in FindSinkPair /builds/worker/workspace/build/src/media/webrtc/trunk/webrtc/media/base/videosourcebase.cc:50
[task 2017-11-06T12:46:50.764Z] 12:46:50     INFO - GECKO(3199) |     #3 0x7f6756f87cb0 in rtc::VideoSourceBase::AddOrUpdateSink(rtc::VideoSinkInterface<webrtc::VideoFrame>*, rtc::VideoSinkWants const&) /builds/worker/workspace/build/src/media/webrtc/trunk/webrtc/media/base/videosourcebase.cc:27
[task 2017-11-06T12:46:50.766Z] 12:46:50     INFO - GECKO(3199) |     #4 0x7f6756f86c6f in rtc::VideoBroadcaster::AddOrUpdateSink(rtc::VideoSinkInterface<webrtc::VideoFrame>*, rtc::VideoSinkWants const&) /builds/worker/workspace/build/src/media/webrtc/trunk/webrtc/media/base/videobroadcaster.cc:31:20
[task 2017-11-06T12:46:50.768Z] 12:46:50     INFO - GECKO(3199) |     #5 0x7f674ec366ca in operator() /builds/worker/workspace/build/src/media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:1891:35
[task 2017-11-06T12:46:50.769Z] 12:46:50     INFO - GECKO(3199) |     #6 0x7f674ec366ca in mozilla::media::LambdaRunnable<mozilla::WebrtcVideoConduit::AddOrUpdateSink(rtc::VideoSinkInterface<webrtc::VideoFrame>*, rtc::VideoSinkWants const&)::$_2>::Run() /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/media/MediaUtils.h:202
[task 2017-11-06T12:46:50.771Z] 12:46:50     INFO - GECKO(3199) |     #7 0x7f674d1f7d16 in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:1037:14
[task 2017-11-06T12:46:50.776Z] 12:46:50     INFO - GECKO(3199) |     #8 0x7f674d2121d8 in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp:513:10
[task 2017-11-06T12:46:50.777Z] 12:46:50     INFO - GECKO(3199) |     #9 0x7f674d1f67de in SpinEventLoopUntil<mozilla::ProcessFailureBehavior::ReportToCaller, (lambda at /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:800:22)> /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.h:323:25
[task 2017-11-06T12:46:50.778Z] 12:46:50     INFO - GECKO(3199) |     #10 0x7f674d1f67de in nsThread::Shutdown() /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:800
[task 2017-11-06T12:46:50.779Z] 12:46:50     INFO - GECKO(3199) |     #11 0x7f674d200cce in nsThreadPool::Shutdown() /builds/worker/workspace/build/src/xpcom/threads/nsThreadPool.cpp:344:17
[task 2017-11-06T12:46:50.780Z] 12:46:50     INFO - GECKO(3199) |     #12 0x7f674d209c02 in applyImpl<nsIThreadPool, nsresult (nsIThreadPool::*)()> /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.h:1142:12
[task 2017-11-06T12:46:50.781Z] 12:46:50     INFO - GECKO(3199) |     #13 0x7f674d209c02 in apply<nsIThreadPool, nsresult (nsIThreadPool::*)()> /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.h:1148
[task 2017-11-06T12:46:50.782Z] 12:46:50     INFO - GECKO(3199) |     #14 0x7f674d209c02 in mozilla::detail::RunnableMethodImpl<nsCOMPtr<nsIThreadPool>, nsresult (nsIThreadPool::*)(), true, (mozilla::RunnableKind)0>::Run() /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.h:1192
[task 2017-11-06T12:46:50.782Z] 12:46:50     INFO - GECKO(3199) |     #15 0x7f674d1f7d16 in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:1037:14
[task 2017-11-06T12:46:50.783Z] 12:46:50     INFO - GECKO(3199) |     #16 0x7f674d2121d8 in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp:513:10
[task 2017-11-06T12:46:50.785Z] 12:46:50     INFO - GECKO(3199) |     #17 0x7f674dfe3ed1 in mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) /builds/worker/workspace/build/src/ipc/glue/MessagePump.cpp:97:21
[task 2017-11-06T12:46:50.788Z] 12:46:50     INFO - GECKO(3199) |     #18 0x7f674df4452b in RunInternal /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:326:10
[task 2017-11-06T12:46:50.790Z] 12:46:50     INFO - GECKO(3199) |     #19 0x7f674df4452b in RunHandler /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:319
[task 2017-11-06T12:46:50.795Z] 12:46:50     INFO - GECKO(3199) |     #20 0x7f674df4452b in MessageLoop::Run() /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:299
[task 2017-11-06T12:46:50.796Z] 12:46:50     INFO - GECKO(3199) |     #21 0x7f67539b0e4f in nsBaseAppShell::Run() /builds/worker/workspace/build/src/widget/nsBaseAppShell.cpp:158:27
[task 2017-11-06T12:46:50.797Z] 12:46:50     INFO - GECKO(3199) |     #22 0x7f6757cbfbd7 in XRE_RunAppShell() /builds/worker/workspace/build/src/toolkit/xre/nsEmbedFunctions.cpp:877:22
[task 2017-11-06T12:46:50.799Z] 12:46:50     INFO - GECKO(3199) |     #23 0x7f674df4452b in RunInternal /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:326:10
[task 2017-11-06T12:46:50.800Z] 12:46:50     INFO - GECKO(3199) |     #24 0x7f674df4452b in RunHandler /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:319
[task 2017-11-06T12:46:50.801Z] 12:46:50     INFO - GECKO(3199) |     #25 0x7f674df4452b in MessageLoop::Run() /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:299
[task 2017-11-06T12:46:50.802Z] 12:46:50     INFO - GECKO(3199) |     #26 0x7f6757cbf58a in XRE_InitChildProcess(int, char**, XREChildData const*) /builds/worker/workspace/build/src/toolkit/xre/nsEmbedFunctions.cpp:703:34
[task 2017-11-06T12:46:50.803Z] 12:46:50     INFO - GECKO(3199) |     #27 0x4ec2de in content_process_main /builds/worker/workspace/build/src/browser/app/../../ipc/contentproc/plugin-container.cpp:63:30
[task 2017-11-06T12:46:50.804Z] 12:46:50     INFO - GECKO(3199) |     #28 0x4ec2de in main /builds/worker/workspace/build/src/browser/app/nsBrowserApp.cpp:280
[task 2017-11-06T12:46:50.865Z] 12:46:50     INFO - GECKO(3199) |     #29 0x7f676b68582f in __libc_start_main /build/glibc-bfm8X4/glibc-2.23/csu/../csu/libc-start.c:291
[task 2017-11-06T12:46:50.865Z] 12:46:50     INFO - GECKO(3199) |     #30 0x41dbc8 in _start (/builds/worker/workspace/build/application/firefox/firefox+0x41dbc8)
[task 2017-11-06T12:46:50.866Z] 12:46:50     INFO - GECKO(3199) | 0x61a0009900e8 is located 104 bytes inside of 1280-byte region [0x61a000990080,0x61a000990580)
[task 2017-11-06T12:46:50.866Z] 12:46:50     INFO - GECKO(3199) | freed by thread T0 (Web Content) here:
[task 2017-11-06T12:46:50.868Z] 12:46:50     INFO - GECKO(3199) |     #0 0x4bc0fb in __interceptor_free /builds/slave/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:47:3
[task 2017-11-06T12:46:50.868Z] 12:46:50     INFO - GECKO(3199) |     #1 0x7f674ec6c6b8 in Release /builds/worker/workspace/build/src/media/webrtc/signaling/src/media-conduit/MediaConduitInterface.h:275:3
[task 2017-11-06T12:46:50.868Z] 12:46:50     INFO - GECKO(3199) |     #2 0x7f674ec6c6b8 in Release /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RefPtr.h:41
[task 2017-11-06T12:46:50.868Z] 12:46:50     INFO - GECKO(3199) |     #3 0x7f674ec6c6b8 in Release /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RefPtr.h:398
[task 2017-11-06T12:46:50.870Z] 12:46:50     INFO - GECKO(3199) |     #4 0x7f674ec6c6b8 in ~RefPtr /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RefPtr.h:79
[task 2017-11-06T12:46:50.873Z] 12:46:50     INFO - GECKO(3199) |     #5 0x7f674ec6c6b8 in ~ConduitDeleteEvent /builds/worker/workspace/build/src/media/webrtc/signaling/src/mediapipeline/MediaPipeline.h:336
[task 2017-11-06T12:46:50.873Z] 12:46:50     INFO - GECKO(3199) |     #6 0x7f674ec6c6b8 in mozilla::ConduitDeleteEvent::~ConduitDeleteEvent() /builds/worker/workspace/build/src/media/webrtc/signaling/src/mediapipeline/MediaPipeline.h:336
[task 2017-11-06T12:46:50.875Z] 12:46:50     INFO - GECKO(3199) |     #7 0x7f674d20e89b in mozilla::Runnable::Release() /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp:48:1
[task 2017-11-06T12:46:50.876Z] 12:46:50     INFO - GECKO(3199) |     #8 0x7f674d1f7eee in ~nsCOMPtr_base /builds/worker/workspace/build/src/obj-firefox/dist/include/nsCOMPtr.h:313:7
[task 2017-11-06T12:46:50.877Z] 12:46:50     INFO - GECKO(3199) |     #9 0x7f674d1f7eee in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp:1043
[task 2017-11-06T12:46:50.878Z] 12:46:50     INFO - GECKO(3199) |     #10 0x7f674d2121d8 in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/workspace/build/src/xpcom/threads/nsThreadUtils.cpp:513:10
[task 2017-11-06T12:46:50.878Z] 12:46:50     INFO - GECKO(3199) |     #11 0x7f674dfe3ed1 in mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) /builds/worker/workspace/build/src/ipc/glue/MessagePump.cpp:97:21
[task 2017-11-06T12:46:50.879Z] 12:46:50     INFO - GECKO(3199) |     #12 0x7f674df4452b in RunInternal /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:326:10
[task 2017-11-06T12:46:50.881Z] 12:46:50     INFO - GECKO(3199) |     #13 0x7f674df4452b in RunHandler /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:319
[task 2017-11-06T12:46:50.881Z] 12:46:50     INFO - GECKO(3199) |     #14 0x7f674df4452b in MessageLoop::Run() /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:299
[task 2017-11-06T12:46:50.882Z] 12:46:50     INFO - GECKO(3199) |     #15 0x7f67539b0e4f in nsBaseAppShell::Run() /builds/worker/workspace/build/src/widget/nsBaseAppShell.cpp:158:27
[task 2017-11-06T12:46:50.883Z] 12:46:50     INFO - GECKO(3199) |     #16 0x7f6757cbfbd7 in XRE_RunAppShell() /builds/worker/workspace/build/src/toolkit/xre/nsEmbedFunctions.cpp:877:22
[task 2017-11-06T12:46:50.884Z] 12:46:50     INFO - GECKO(3199) |     #17 0x7f674df4452b in RunInternal /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:326:10
[task 2017-11-06T12:46:50.885Z] 12:46:50     INFO - GECKO(3199) |     #18 0x7f674df4452b in RunHandler /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:319
[task 2017-11-06T12:46:50.886Z] 12:46:50     INFO - GECKO(3199) |     #19 0x7f674df4452b in MessageLoop::Run() /builds/worker/workspace/build/src/ipc/chromium/src/base/message_loop.cc:299
[task 2017-11-06T12:46:50.887Z] 12:46:50     INFO - GECKO(3199) |     #20 0x7f6757cbf58a in XRE_InitChildProcess(int, char**, XREChildData const*) /builds/worker/workspace/build/src/toolkit/xre/nsEmbedFunctions.cpp:703:34
[task 2017-11-06T12:46:50.888Z] 12:46:50     INFO - GECKO(3199) |     #21 0x4ec2de in content_process_main /builds/worker/workspace/build/src/browser/app/../../ipc/contentproc/plugin-container.cpp:63:30
[task 2017-11-06T12:46:50.893Z] 12:46:50     INFO - GECKO(3199) |     #22 0x4ec2de in main /builds/worker/workspace/build/src/browser/app/nsBrowserApp.cpp:280
[task 2017-11-06T12:46:50.894Z] 12:46:50     INFO - GECKO(3199) |     #23 0x7f676b68582f in __libc_start_main /build/glibc-bfm8X4/glibc-2.23/csu/../csu/libc-start.c:291
[task 2017-11-06T12:46:50.895Z] 12:46:50     INFO - GECKO(3199) | previously allocated by thread T0 (Web Content) here:
[task 2017-11-06T12:46:50.895Z] 12:46:50     INFO - GECKO(3199) |     #0 0x4bc44c in malloc /builds/slave/moz-toolchain/src/llvm/projects/compiler-rt/lib/asan/asan_malloc_linux.cc:64:3
[task 2017-11-06T12:46:50.896Z] 12:46:50     INFO - GECKO(3199) |     #1 0x4ed85d in moz_xmalloc /builds/worker/workspace/build/src/memory/mozalloc/mozalloc.cpp:84:17
[task 2017-11-06T12:46:50.897Z] 12:46:50     INFO - GECKO(3199) |     #2 0x7f674ec05954 in operator new /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/mozalloc.h:206:12
[task 2017-11-06T12:46:50.898Z] 12:46:50     INFO - GECKO(3199) |     #3 0x7f674ec05954 in mozilla::VideoSessionConduit::Create(RefPtr<mozilla::WebRtcCallWrapper>) /builds/worker/workspace/build/src/media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:229
[task 2017-11-06T12:46:50.900Z] 12:46:50     INFO - GECKO(3199) |     #4 0x7f674ec86696 in mozilla::MediaPipelineFactory::GetOrCreateVideoConduit(mozilla::JsepTrackPair const&, mozilla::JsepTrack const&, RefPtr<mozilla::MediaSessionConduit>*) /builds/worker/workspace/build/src/media/webrtc/signaling/src/peerconnection/MediaPipelineFactory.cpp:802:15
[task 2017-11-06T12:46:50.902Z] 12:46:50     INFO - GECKO(3199) |     #5 0x7f674ec7faad in mozilla::MediaPipelineFactory::CreateOrUpdateMediaPipeline(mozilla::JsepTrackPair const&, mozilla::JsepTrack const&) /builds/worker/workspace/build/src/media/webrtc/signaling/src/peerconnection/MediaPipelineFactory.cpp:445:10
[task 2017-11-06T12:46:50.908Z] 12:46:50     INFO - GECKO(3199) |     #6 0x7f674ecc0c7c in mozilla::PeerConnectionMedia::UpdateMediaPipelines(mozilla::JsepSession const&) /builds/worker/workspace/build/src/media/webrtc/signaling/src/peerconnection/PeerConnectionMedia.cpp:608:20
[task 2017-11-06T12:46:50.909Z] 12:46:50     INFO - GECKO(3199) |     #7 0x7f674ecc6181 in mozilla::PeerConnectionImpl::SetSignalingState_m(mozilla::dom::PCImplSignalingState, bool) /builds/worker/workspace/build/src/media/webrtc/signaling/src/peerconnection/PeerConnectionImpl.cpp:3214:11
[task 2017-11-06T12:46:50.910Z] 12:46:50     INFO - GECKO(3199) |     #8 0x7f674ecb459a in UpdateSignalingState /builds/worker/workspace/build/src/media/webrtc/signaling/src/peerconnection/PeerConnectionImpl.cpp:3303:3
[task 2017-11-06T12:46:50.911Z] 12:46:50     INFO - GECKO(3199) |     #9 0x7f674ecb459a in mozilla::PeerConnectionImpl::SetRemoteDescription(int, char const*) /builds/worker/workspace/build/src/media/webrtc/signaling/src/peerconnection/PeerConnectionImpl.cpp:2089
[task 2017-11-06T12:46:50.928Z] 12:46:50     INFO - GECKO(3199) |     #10 0x7f675085f8d5 in SetRemoteDescription /builds/worker/workspace/build/src/media/webrtc/signaling/src/peerconnection/PeerConnectionImpl.h:374:10
[task 2017-11-06T12:46:50.928Z] 12:46:50     INFO - GECKO(3199) |     #11 0x7f675085f8d5 in mozilla::dom::PeerConnectionImplBinding::setRemoteDescription(JSContext*, JS::Handle<JSObject*>, mozilla::PeerConnectionImpl*, JSJitMethodCallArgs const&) /builds/worker/workspace/build/src/obj-firefox/dom/bindings/PeerConnectionImplBinding.cpp:231
[task 2017-11-06T12:46:50.930Z] 12:46:50     INFO - GECKO(3199) |     #12 0x7f6751b71340 in mozilla::dom::GenericBindingMethod(JSContext*, unsigned int, JS::Value*) /builds/worker/workspace/build/src/dom/bindings/BindingUtils.cpp:3040:13
[task 2017-11-06T12:46:50.938Z] 12:46:50     INFO - GECKO(3199) |     #13 0x7f6757f691f0 in CallJSNative /builds/worker/workspace/build/src/js/src/jscntxtinlines.h:291:15
[task 2017-11-06T12:46:50.940Z] 12:46:50     INFO - GECKO(3199) |     #14 0x7f6757f691f0 in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:472
[task 2017-11-06T12:46:50.941Z] 12:46:50     INFO - GECKO(3199) |     #15 0x7f6757f54a7b in CallFromStack /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:527:12
[task 2017-11-06T12:46:50.941Z] 12:46:50     INFO - GECKO(3199) |     #16 0x7f6757f54a7b in Interpret(JSContext*, js::RunState&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:3061
[task 2017-11-06T12:46:50.942Z] 12:46:50     INFO - GECKO(3199) |     #17 0x7f6757f3c65a in js::RunScript(JSContext*, js::RunState&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:422:12
[task 2017-11-06T12:46:50.942Z] 12:46:50     INFO - GECKO(3199) |     #18 0x7f6757f692ef in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:494:15
[task 2017-11-06T12:46:50.943Z] 12:46:50     INFO - GECKO(3199) |     #19 0x7f6757f6a1e2 in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:540:10
[task 2017-11-06T12:46:50.960Z] 12:46:50     INFO - GECKO(3199) |     #20 0x7f675804e099 in js::PromiseObject::create(JSContext*, JS::Handle<JSObject*>, JS::Handle<JSObject*>, bool) /builds/worker/workspace/build/src/js/src/builtin/Promise.cpp:1666:19
[task 2017-11-06T12:46:50.961Z] 12:46:50     INFO - GECKO(3199) |     #21 0x7f6758123b54 in PromiseConstructor(JSContext*, unsigned int, JS::Value*) /builds/worker/workspace/build/src/js/src/builtin/Promise.cpp:1594:30
[task 2017-11-06T12:46:50.962Z] 12:46:50     INFO - GECKO(3199) |     #22 0x7f6757f6a88e in CallJSNative /builds/worker/workspace/build/src/js/src/jscntxtinlines.h:291:15
[task 2017-11-06T12:46:50.963Z] 12:46:50     INFO - GECKO(3199) |     #23 0x7f6757f6a88e in CallJSNativeConstructor /builds/worker/workspace/build/src/js/src/jscntxtinlines.h:324
[task 2017-11-06T12:46:50.964Z] 12:46:50     INFO - GECKO(3199) |     #24 0x7f6757f6a88e in InternalConstruct(JSContext*, js::AnyConstructArgs const&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:567
[task 2017-11-06T12:46:50.965Z] 12:46:50     INFO - GECKO(3199) |     #25 0x7f6757f54ab2 in ConstructFromStack /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:605:12
[task 2017-11-06T12:46:50.966Z] 12:46:50     INFO - GECKO(3199) |     #26 0x7f6757f54ab2 in Interpret(JSContext*, js::RunState&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:3053
[task 2017-11-06T12:46:50.967Z] 12:46:50     INFO - GECKO(3199) |     #27 0x7f6757f3c65a in js::RunScript(JSContext*, js::RunState&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:422:12
[task 2017-11-06T12:46:50.968Z] 12:46:50     INFO - GECKO(3199) |     #28 0x7f6757f692ef in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:494:15
[task 2017-11-06T12:46:50.969Z] 12:46:50     INFO - GECKO(3199) |     #29 0x7f6757f6a1e2 in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:540:10
[task 2017-11-06T12:46:50.971Z] 12:46:50     INFO - GECKO(3199) |     #30 0x7f6758757309 in js::jit::InterpretResume(JSContext*, JS::Handle<JSObject*>, JS::Handle<JS::Value>, JS::Handle<js::PropertyName*>, JS::MutableHandle<JS::Value>) /builds/worker/workspace/build/src/js/src/jit/VMFunctions.cpp:926:12
[task 2017-11-06T12:46:50.971Z] 12:46:50     INFO - GECKO(3199) |     #31 0x7f670625f642  (<unknown module>)
[task 2017-11-06T12:46:50.974Z] 12:46:50     INFO - GECKO(3199) |     #32 0x7f670625e849  (<unknown module>)
[task 2017-11-06T12:46:50.983Z] 12:46:50     INFO - GECKO(3199) |     #33 0x7f67584b92ee in EnterJit /builds/worker/workspace/build/src/js/src/jit/Jit.cpp:99:9
[task 2017-11-06T12:46:50.984Z] 12:46:50     INFO - GECKO(3199) |     #34 0x7f67584b92ee in js::jit::MaybeEnterJit(JSContext*, js::RunState&) /builds/worker/workspace/build/src/js/src/jit/Jit.cpp:162
[task 2017-11-06T12:46:50.985Z] 12:46:50     INFO - GECKO(3199) |     #35 0x7f6757f3c48d in js::RunScript(JSContext*, js::RunState&) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:407:34
[task 2017-11-06T12:46:50.986Z] 12:46:50     INFO - GECKO(3199) |     #36 0x7f6757f692ef in js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:494:15
[task 2017-11-06T12:46:50.988Z] 12:46:50     INFO - GECKO(3199) |     #37 0x7f6757f6a1e2 in js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) /builds/worker/workspace/build/src/js/src/vm/Interpreter.cpp:540:10
[task 2017-11-06T12:46:50.997Z] 12:46:50     INFO - GECKO(3199) |     #38 0x7f6758f8c29a in js::CallSelfHostedFunction(JSContext*, JS::Handle<js::PropertyName*>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>) /builds/worker/workspace/build/src/js/src/vm/SelfHosting.cpp:1726:12
[task 2017-11-06T12:46:50.998Z] 12:46:50     INFO - GECKO(3199) | SUMMARY: AddressSanitizer: heap-use-after-free /builds/worker/workspace/build/src/clang/bin/../lib/gcc/x86_64-unknown-linux-gnu/4.9.4/../../../../include/c++/4.9.4/bits/stl_iterator.h:729:20 in __normal_iterator
[task 2017-11-06T12:46:51.000Z] 12:46:51     INFO - GECKO(3199) | Shadow bytes around the buggy address:
[task 2017-11-06T12:46:51.002Z] 12:46:51     INFO - GECKO(3199) |   0x0c3480129fc0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
[task 2017-11-06T12:46:51.002Z] 12:46:51     INFO - GECKO(3199) |   0x0c3480129fd0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
[task 2017-11-06T12:46:51.002Z] 12:46:51     INFO - GECKO(3199) |   0x0c3480129fe0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
[task 2017-11-06T12:46:51.003Z] 12:46:51     INFO - GECKO(3199) |   0x0c3480129ff0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
[task 2017-11-06T12:46:51.004Z] 12:46:51     INFO - GECKO(3199) |   0x0c348012a000: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
[task 2017-11-06T12:46:51.005Z] 12:46:51     INFO - GECKO(3199) | =>0x0c348012a010: fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]fd fd
[task 2017-11-06T12:46:51.008Z] 12:46:51     INFO - GECKO(3199) |   0x0c348012a020: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
[task 2017-11-06T12:46:51.009Z] 12:46:51     INFO - GECKO(3199) |   0x0c348012a030: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
[task 2017-11-06T12:46:51.010Z] 12:46:51     INFO - GECKO(3199) |   0x0c348012a040: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
[task 2017-11-06T12:46:51.010Z] 12:46:51     INFO - GECKO(3199) |   0x0c348012a050: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
[task 2017-11-06T12:46:51.011Z] 12:46:51     INFO - GECKO(3199) |   0x0c348012a060: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
[task 2017-11-06T12:46:51.011Z] 12:46:51     INFO - GECKO(3199) | Shadow byte legend (one shadow byte represents 8 application bytes):
[task 2017-11-06T12:46:51.012Z] 12:46:51     INFO - GECKO(3199) |   Addressable:           00
[task 2017-11-06T12:46:51.012Z] 12:46:51     INFO - GECKO(3199) |   Partially addressable: 01 02 03 04 05 06 07
[task 2017-11-06T12:46:51.013Z] 12:46:51     INFO - GECKO(3199) |   Heap left redzone:       fa
[task 2017-11-06T12:46:51.014Z] 12:46:51     INFO - GECKO(3199) |   Heap right redzone:      fb
[task 2017-11-06T12:46:51.015Z] 12:46:51     INFO - GECKO(3199) |   Freed heap region:       fd
[task 2017-11-06T12:46:51.016Z] 12:46:51     INFO - GECKO(3199) |   Stack left redzone:      f1
[task 2017-11-06T12:46:51.017Z] 12:46:51     INFO - GECKO(3199) |   Stack mid redzone:       f2
[task 2017-11-06T12:46:51.018Z] 12:46:51     INFO - GECKO(3199) |   Stack right redzone:     f3
[task 2017-11-06T12:46:51.018Z] 12:46:51     INFO - GECKO(3199) |   Stack partial redzone:   f4
[task 2017-11-06T12:46:51.018Z] 12:46:51     INFO - GECKO(3199) |   Stack after return:      f5
[task 2017-11-06T12:46:51.019Z] 12:46:51     INFO - GECKO(3199) |   Stack use after scope:   f8
[task 2017-11-06T12:46:51.020Z] 12:46:51     INFO - GECKO(3199) |   Global redzone:          f9
[task 2017-11-06T12:46:51.022Z] 12:46:51     INFO - GECKO(3199) |   Global init order:       f6
[task 2017-11-06T12:46:51.023Z] 12:46:51     INFO - GECKO(3199) |   Poisoned by user:        f7
[task 2017-11-06T12:46:51.024Z] 12:46:51     INFO - GECKO(3199) |   Container overflow:      fc
[task 2017-11-06T12:46:51.025Z] 12:46:51     INFO - GECKO(3199) |   Array cookie:            ac
[task 2017-11-06T12:46:51.026Z] 12:46:51     INFO - GECKO(3199) |   Intra object redzone:    bb
[task 2017-11-06T12:46:51.027Z] 12:46:51     INFO - GECKO(3199) |   ASan internal:           fe
[task 2017-11-06T12:46:51.027Z] 12:46:51     INFO - GECKO(3199) |   Left alloca redzone:     ca
[task 2017-11-06T12:46:51.028Z] 12:46:51     INFO - GECKO(3199) |   Right alloca redzone:    cb
[task 2017-11-06T12:46:51.028Z] 12:46:51     INFO - GECKO(3199) | ==3250==ABORTING
Group: core-security → media-core-security
Flags: needinfo?(rjesup)
Flags: needinfo?(rjesup)
Flags: needinfo?(drno)
Flags: needinfo?(docfaraday)
Rank: 5
Keywords: sec-high
Priority: -- → P1
Moving NI's, this likely has to do with the teardown of the VideoConduit racing with and update of the VideoSink
Flags: needinfo?(jib)
Flags: needinfo?(drno)
Flags: needinfo?(docfaraday)
Flags: needinfo?(dminor)
I'll investigate.
Assignee: nobody → dminor
Flags: needinfo?(dminor)
Attached patch Add mDestroyingVideoConduit (obsolete) — Splinter Review
Before AddOrUpdateSink dispatches to the main thread, it creates a RefPtr to the VideoConduit. The only situation I can think of where this would fail to keep the VideoConduit alive until the lambda runs is if the destructor has already started on the main thread.

This adds an atomic bool that is set to true when the destructor starts. This is checked after the RefPtr in AddOrUpdateSink is created. If it is true, the RefPtr will not be able to keep the VideoConduit alive. The forget() method is called on the RefPtr so that it doesn't attempt to delete the VideoConduit a second time and the method returns early.

As part of the destructor executing, it calls down into VideoSourceProxy::SetSource with a nullptr which prevents further callbacks from occurring. The VideoSourceProxy methods are protected by a critical section so that any callbacks in flight must first be completed before the VideoConduit destructor completes and none can occur afterwards. This ensures that mDestroyingVideoConduit remains valid for the duration of the AddOrUpdateSink callback.

If the destructor has already started while the RefPtr is being created, mDestroyingVideoConduit should be set and that will prevent it dispatching to the main thread. If that is not the case, the RefPtr should keep the VideoConduit alive until after the lambda executes.
Attachment #8926455 - Flags: review?(rjesup)
Comment on attachment 8926455 [details] [diff] [review]
Add mDestroyingVideoConduit

Review of attachment 8926455 [details] [diff] [review]:
-----------------------------------------------------------------

If we could be in ~WebrtcVideoConduit() on MainThread, then when the WebrtcVideoConduit::AddOrUpdateSink() runs off-main-thread, 'this' must not be guaranteed to be alive, and even trying to add a reference to 'this' before checking the atomic bool could UAF.  (for that matter, the call to AddUpdateSink can UAF.)
This is trying to create a pseudo-threadsafe-refcount without a lock on the object-to-be-locked; unless there's a single atomic test-and-add-refcount (before calling into AddUpdateSink, or if you made AddUpdateSink static perhaps) or lock some global and do some fancy footwork, this can't work).

Basically, if AddUpdateSink can be invoked by something that can't guarantee a ref being held, then we need some way to ensure AddUpdateSink() calls have been ended before the last ref to the conduit can be allowed to die.

This code was written assuming that while the webrtc code is active and might call AddOrUpdateSink that a ref was held, and that before ~WebrtcVideoConduit() is called we shut down webrtc.org.

I'd start again looking if there's any way the invariants here can be broken (in particular, that webrtc.org callbacks wouldn't be shut down before ~WebrtcVideoConduit() is called) -- perhaps it is telling webrtc.org to shut down, but a thread isn't actually synced with before it returns to the conduit code?  Document what should be holding that conduit alive there.
Attachment #8926455 - Flags: review?(rjesup) → review-
(In reply to Randell Jesup [:jesup] from comment #4)
> Comment on attachment 8926455 [details] [diff] [review]
> Add mDestroyingVideoConduit
> 
> Review of attachment 8926455 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> If we could be in ~WebrtcVideoConduit() on MainThread, then when the
> WebrtcVideoConduit::AddOrUpdateSink() runs off-main-thread, 'this' must not
> be guaranteed to be alive, and even trying to add a reference to 'this'
> before checking the atomic bool could UAF.  (for that matter, the call to
> AddUpdateSink can UAF.)
> This is trying to create a pseudo-threadsafe-refcount without a lock on the
> object-to-be-locked; unless there's a single atomic test-and-add-refcount
> (before calling into AddUpdateSink, or if you made AddUpdateSink static
> perhaps) or lock some global and do some fancy footwork, this can't work).

I'm fairly certain (at least I managed to convince myself!) that the locking in VideoSourceProxy would guarantee that either the callbacks have stopped or that the destructor had started and but not completed. Since no member variables are freed automatically until after the destructor completes, both this and the bool should be safe to access.

That said, I completely agree that it makes a lot more sense to ensure that the callbacks have stopped before the destructor starts rather than to try to recover from that situation. I think that is just a matter of calling DeleteSendStream from the main thread prior to the VideoConduit being destroyed. The locking in VideoSourceProxy should ensure that the callbacks end before DeleteSendStream returns.
IF DeleteSendStream is racing with destruction that could explain a bunch of other crashes, IIRC
Flags: needinfo?(jib)
This renames the existing VideoConduit Destroy method to DeleteStreams and calls it from Destruct_m in PeerConnectMedia. The locking done in ViEEncoder::VideoSourceProxy ensures that all callbacks have stopped prior to the call to DeleteStreams returning which fixes the problem with callbacks occurring on one thread while the destructor is in progress on another.

This results in the send and receive streams being deleted earlier during teardown than was previously the case. The code currently has checks for these to be null everywhere they are accessed so I believe this to be safe.

I tested this locally by running the unit tests as well as by repeated restarting video calls prior to closing the browser to check for shutdown crashes or hangs.
Attachment #8926455 - Attachment is obsolete: true
Attachment #8927441 - Flags: review?(rjesup)
Attachment #8927441 - Flags: review?(rjesup) → review+
Comment on attachment 8927441 [details] [diff] [review]
Add DeleteStreams to media conduits

[Security approval request comment]
How easily could an exploit be constructed based on the patch?
Not easily, you could guess from the patch that we had a shutdown problem, but you would still have to determine where it was.
Do comments in the patch, the check-in comment, or tests included in the patch paint a bulls-eye on the security problem?
No.
Which older supported branches are affected by this flaw?
All.
If not all supported branches, which bug introduced the flaw?

Do you have backports for the affected branches? If not, how different, hard to create, and risky will they be?
Easy to create.
How likely is this patch to cause regressions; how much testing does it need?
My main concern is causing shutdown hangs or crashes. I've done manual testing for those. If there are problems I missed I would expect to catch them in automation quickly.
Attachment #8927441 - Flags: sec-approval?
Sec-approval+ for checkin on November 28, two weeks into the new cycle. Please do not check in before that date.

We'll want this on other branches so branch patches should be made and nominated at that time as well.
Whiteboard: [checkin on 11/28]
Attachment #8927441 - Flags: sec-approval? → sec-approval+
Comment on attachment 8927441 [details] [diff] [review]
Add DeleteStreams to media conduits

Approval Request Comment
[Feature/Bug causing the regression]:
[User impact if declined]:
Crashes / security problems.
[Is this code covered by automated tests?]:
Yes.
[Has the fix been verified in Nightly?]:
No.
[Needs manual test from QE? If yes, steps to reproduce]: 
No.
[List of other uplifts needed for the feature/fix]:
None.
[Is the change risky?]:
No.
[Why is the change risky/not risky?]:
This causes the send and receive streams to be deleted earlier during shutdown than was previously the case, but they are currently allowed to be null anyway so this should be a safe change. There is a risk of introducing a shutdown hang by doing this, which I've tested for manually.
[String changes made/needed]:
None.
Attachment #8927441 - Flags: approval-mozilla-beta?
ESR52 uses an older release of the webrtc.org code and the attached patch does not work there - it crashes consistently on shutdown. I'm marking it wontfix, I don't think it is worth the risk and effort to try to come up with a working fix for ESR. Please reset the flag if you would like me to take a more in depth look at it.
Whiteboard: [checkin on 11/28]
Attached patch Fix gtestsSplinter Review
To fix problems like this: https://treeherder.mozilla.org/logviewer.html#?job_id=148267910&repo=mozilla-inbound&lineNumber=16463

Which I thought could be problems and tested for before landing, but with a mozconfig without debug set, so I didn't hit the assertions.
Attachment #8932607 - Flags: review?(drno)
Comment on attachment 8932607 [details] [diff] [review]
Fix gtests

Review of attachment 8932607 [details] [diff] [review]:
-----------------------------------------------------------------

LGTM
Attachment #8932607 - Flags: review?(drno) → review+
Flags: needinfo?(aryx.bugmail) → needinfo?(dminor)
Attempting to call DeleteStreams from Shutdown_m in TranseiversImpl.cc deadlocks pretty consistently even when running tests locally. This was either not a problem with the original version of this patch, or occurred at a much lower frequency. I'm trying to find a better place to call DeleteStreams().
Flags: needinfo?(dminor)
Attachment #8927441 - Flags: approval-mozilla-beta?
Changes that have landed in Firefox 59 make it impossible to test or verify a fix for Firefox 58 on Nightly. My fear is that the deadlock that I ran into when I tried to land this on Nightly is also present in 58, just less frequent. Because of this, I think a fix for 58 would be quite risky and I don't think it makes sense to continue to track this for 58.
Dan, any luck here for 59?
Flags: needinfo?(dminor)
Hi Liz, I've started looking at this again today and I'm trying a few things out. If I'm still stuck tomorrow, I'll leave a comment with what I'm seeing and see if someone else can help.
Flags: needinfo?(dminor)
The problem I'm seeing here is with test_peerConnection_basicH264Video.html. If I run it in a loop like this:

./mach mochitest --disable-e10s --debugger=gdb --repeat 100 dom/media/tests/mochitest/test_peerConnection_basicH264Video.html

it will fairly quickly end up in a deadlock. Looking at the threads in gdb, this is what I see:

Thread 1 (firefox)
-> blocked waiting on task to run on EncoderQueue in: shutdown_event_.Wait(rtc::Event::kForever);

#0  0x00007ffff7bc6510 in pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x00007fffe7ef6baa in rtc::Event::Wait(int) (this=this@entry=0x7fffbf5b0028, milliseconds=<optimized out>, milliseconds@entry=-1)
    at /home/dminor/src/firefox-signaling/media/webrtc/trunk/webrtc/base/event.cc:121
#2  0x00007fffe7f3bf2d in webrtc::ViEEncoder::Stop() (this=0x7fffbf5b0000)
    at /home/dminor/src/firefox-signaling/media/webrtc/trunk/webrtc/video/vie_encoder.cc:312
#3  0x00007fffe7f3bfe2 in webrtc::internal::VideoSendStream::StopPermanentlyAndGetRtpStates() (this=0x7fffb57be000)
    at /home/dminor/src/firefox-signaling/media/webrtc/trunk/webrtc/video/video_send_stream.cc:703
#4  0x00007fffe7f1d50f in webrtc::internal::Call::DestroyVideoSendStream(webrtc::VideoSendStream*) (this=0x7fffb4325000, send_stream=0x7fffb57be000)
    at /home/dminor/src/firefox-signaling/media/webrtc/trunk/webrtc/call/call.cc:630
#5  0x00007fffe58e58bf in mozilla::WebrtcVideoConduit::DeleteSendStream() (this=this@entry=0x7fffb4325800)
    at /home/dminor/src/firefox-signaling/media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:405
#6  0x00007fffe58e9a89 in mozilla::WebrtcVideoConduit::DeleteStreams() (this=0x7fffb4325800)
    at /home/dminor/src/firefox-signaling/media/webrtc/signaling/src/media-conduit/VideoConduit.cpp:1205
#7  0x00007fffe590f10f in mozilla::TransceiverImpl::Shutdown_m() (this=0x7fffb420a4c0)
    at /home/dminor/src/firefox-signaling/media/webrtc/signaling/src/peerconnection/TransceiverImpl.cpp:144

Thread 35 (GMPThread)
-> blocked waiting on sync dispatch to SystemGroup::EventTargetFor(mozilla::TaskCategory::Other) which based on the surrounding code appears to the be the main thread.

#0  0x00007ffff7bc6510 in pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x000055555556466f in mozilla::detail::ConditionVariableImpl::wait(mozilla::detail::MutexImpl&) (this=this@entry=0x7fffc804f0e8, lock=...)
    at /home/dminor/src/firefox-signaling/mozglue/misc/ConditionVariable_posix.cpp:118
#2  0x00007fffe4ecc91c in mozilla::CondVar::Wait(unsigned int) (this=this@entry=0x7fffc804f0c8, aInterval=aInterval@entry=4294967295)
    at /home/dminor/src/firefox-signaling/xpcom/threads/BlockingResourceBase.cpp:604
#3  0x00007fffe4f178e3 in mozilla::Monitor::Wait(unsigned int) (aInterval=4294967295, this=0x7fffc804f080)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/Monitor.h:40
#4  0x00007fffe4f178e3 in mozilla::MonitorAutoLock::Wait(unsigned int) (aInterval=4294967295, this=<synthetic pointer>)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/Monitor.h:88
#5  0x00007fffe4f178e3 in mozilla::SyncRunnable::DispatchToThread(nsIEventTarget*, bool) (this=0x7fffc804f050, aThread=<optimized out>, aForceDispatch=<optimized out>)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/SyncRunnable.h:70
#6  0x00007fffe4f17a42 in mozilla::SyncRunnable::DispatchToThread(nsIEventTarget*, nsIRunnable*, bool) (aThread=0x7fffe2a85250, aRunnable=0x7fffbf7d5b20, aForceDispatch=<optimized out>)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/SyncRunnable.h:98
#7  0x00007fffe6aaf558 in mozilla::gmp::GMPServiceCreateHelper::GetOrCreate() ()
    at /home/dminor/src/firefox-signaling/dom/media/gmp/GMPService.cpp:87


Thread 138 (EncoderQueue)
-> blocked waiting on sync dispatch to GMP thread

#0  0x00007ffff7bc6510 in pthread_cond_wait@@GLIBC_2.3.2 ()
    at ../sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x000055555556466f in mozilla::detail::ConditionVariableImpl::wait(mozilla::detail::MutexImpl&) (this=this@entry=0x7fffc6f1a1f8, lock=...)
    at /home/dminor/src/firefox-signaling/mozglue/misc/ConditionVariable_posix.cpp:118
#2  0x00007fffe4ecc91c in mozilla::CondVar::Wait(unsigned int) (this=this@entry=0x7fffc6f1a1d8, aInterval=aInterval@entry=4294967295)
    at /home/dminor/src/firefox-signaling/xpcom/threads/BlockingResourceBase.cpp:604
#3  0x00007fffe4f178e3 in mozilla::Monitor::Wait(unsigned int) (aInterval=4294967295, this=0x7fffc6f1a190)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/Monitor.h:40
#4  0x00007fffe4f178e3 in mozilla::MonitorAutoLock::Wait(unsigned int) (aInterval=4294967295, this=<synthetic pointer>)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/Monitor.h:88
#5  0x00007fffe4f178e3 in mozilla::SyncRunnable::DispatchToThread(nsIEventTarget*, bool) (this=0x7fffc6f1a160, aThread=<optimized out>, aForceDispatch=<optimized out>)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/SyncRunnable.h:70
#6  0x00007fffe4f17a42 in mozilla::SyncRunnable::DispatchToThread(nsIEventTarget*, nsIRunnable*, bool) (aThread=0x7fffda541870, aRunnable=0x7fffb40fe460, aForceDispatch=<optimized out>)
    at /home/dminor/src/firefox-signaling/obj-x86_64-pc-linux-gnu/dist/include/mozilla/SyncRunnable.h:98
#7  0x00007fffe58e64e1 in mozilla::WebrtcGmpVideoEncoder::Encode(webrtc::VideoFrame const&, webrtc::CodecSpecificInfo const*, std::vector<webrtc::FrameType, std::allocator<webrtc::FrameType> > const*) (this=0x7fffbf124000, aInputImage=..., aCodecSpecificInfo=0x0, aFrameTypes=0x7fffa03f2fb8)
    at /home/dminor/src/firefox-signaling/media/webrtc/signaling/src/media-conduit/WebrtcGmpVideoCodec.cpp:327
#8  0x00007fffe7e19efe in webrtc::VCMGenericEncoder::Encode(webrtc::VideoFrame const&, webrtc::CodecSpecificInfo const*, std::vector<webrtc::FrameType, std::allocator<webrtc::FrameType> > const&) (this=0x7fffe2a41c80, frame=..., codec_specific=codec_specific@entry=0x0, frame_types=std::vector of length 1, capacity 1 = {...})
    at /home/dminor/src/firefox-signaling/media/webrtc/trunk/webrtc/modules/video_coding/generic_encoder.cc:70
#9  0x00007fffe7e31752 in webrtc::vcm::VideoSender::AddVideoFrame(webrtc::VideoFrame const&, webrtc::CodecSpecificInfo const*) (this=0x7fffbf0b10d8, videoFrame=..., codecSpecificInfo=0x0)
    at /home/dminor/src/firefox-signaling/media/webrtc/trunk/webrtc/modules/video_coding/video_sender.cc:350
#10 0x00007fffe7f3d80b in webrtc::ViEEncoder::EncodeVideoFrame(webrtc::VideoFrame const&, long) (this=0x7fffbf0b1000, video_frame=..., time_when_posted_in_ms=102530057)

So the main thread is waiting on the EncoderQueue thread which is waiting on the GMPThread which is waiting on the main thread. This seems to happen when we are asked to encode a frame during shutdown. There is an existing moderate frequency intermittent (Bug 1375540) that has similar symptoms, but there is not enough information in the logs to say for sure whether it is the same problem.

This patch became much more problematic after the Transceivers changes landed, and there's a corresponding increase in the frequency of Bug 1375540 around the same time. I'm guessing that the Transceivers work changed the shutdown timing a bit and that has caused a pre-existing problem to occur more frequently, but without digging into Bug 1375540 some more it is hard to say for sure.

At any rate, I'm not sure how to proceed here. I was hoping someone else could have a look and see if my analysis makes sense and (hopefully) have some suggestions on what to try next. Thanks!
Flags: needinfo?(rjesup)
Flags: needinfo?(docfaraday)
Yikes, we're doing a sync dispatch every time we encode a frame?! We should really stop doing that.
Flags: needinfo?(docfaraday)
Thanks for the help. I'll give things a try and if it looks promising, file a non-sec bug to change over to async dispatch for encode and decode.
Filed Bug 1429390 to make encode dispatch async. Decode still uses a raw frame buffer so I plan to leave that sync for now.
being dealt with in bug 1429390
Flags: needinfo?(rjesup)
Even with the fixes in landed in Bug 1429390 I still see a frequent intermittent: Error: Timeout checking for stats for track: {} in local testing. The frequent deadlock problem is fixed.

I eventually hit another deadlock. The test_peerConnection_basicH264Video.html test is already subject to deadlock problems (see Bug 1375540) so it is difficult to say whether or not the patches here make things worse.

I'm clearing the tracking flag for 59. I don't feel comfortable landing these changes until we resolve the other deadlock / shutdown problems we're seeing. I'm afraid the patch here will only complicate things, if not makes things worse.
Any updates on the deadlock problems mentioned in comment 29, Dan?
This bug hasn't changed for a month now, is there another bug?
Flags: needinfo?(dminor)
I rebased and retested this morning and these changes are still problematic. I'm seeing crashes rather than deadlock now.

 0:11.94 GECKO(16921) Assertion failure: mSegment (null segment), at /home/dminor/src/firefox-signaling/ipc/glue/Shmem.cpp:289
 0:12.93 GECKO(16921) #01: mozilla::gmp::GMPPlaneImpl::Buffer() const (/home/dminor/src/firefox-signaling/dom/media/gmp/GMPVideoPlaneImpl.cpp:209)
 0:13.00 GECKO(16921) #02: FakeVideoEncoder::SendFrame(GMPVideoi420Frame*, GMPVideoFrameType, unsigned char) (/home/dminor/src/firefox-signaling/dom/media/gmp-plugin-openh264/gmp-fake-openh264.cpp:186)
 0:13.01 GECKO(16921) #03: FakeVideoEncoder::Encode_m(GMPVideoi420Frame*, GMPVideoFrameType) (/home/dminor/src/firefox-signaling/dom/media/gmp-plugin-openh264/gmp-fake-openh264.cpp:267)
 0:13.01 GECKO(16921) #04: FakeEncoderTask::Run() (/home/dminor/src/firefox-signaling/dom/media/gmp-plugin-openh264/gmp-fake-openh264.cpp:320)
 0:13.04 GECKO(16921) #05: mozilla::gmp::GMPRunnable::Run() (/home/dminor/src/firefox-signaling/dom/media/gmp/GMPPlatform.cpp:45)
 0:11.93 INFO PeerConnectionWrapper (pcLocal) ended fired for track {72452e8a-6016-4c89-8160-972531a80f83}

To me, that looks like the FakeEncoderTask is still running after the shared memory buffer has been destroyed. It is possible that the deadlock problem is still there, just less frequent than the crash. The crash did not reproduce with a debugger attached, so seems timing dependent.
Flags: needinfo?(dminor)
Dan, would you be interested in trying this again with rr?
Flags: needinfo?(dminor)
Bug 1444363 might have fixed the crash in comment 31.
I ran this for a long time this morning and it seems to be fine. I did eventually hit a crash after a thousand runs, but it was unrelated to any of the problems mentioned in this bug. I'll plan to land this after the code freeze.
Flags: needinfo?(dminor)
https://hg.mozilla.org/mozilla-central/rev/7df36a12113a
https://hg.mozilla.org/mozilla-central/rev/f67de31985d9
Group: media-core-security → core-security-release
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla62
Please request Beta and ESR60 approval on this when you get a chance.
Comment on attachment 8927441 [details] [diff] [review]
Add DeleteStreams to media conduits

Approval Request Comment
[Feature/Bug causing the regression]:
[User impact if declined]:
Crashes / security problems.
[Is this code covered by automated tests?]:
Yes.
[Has the fix been verified in Nightly?]:
Yes.
[Needs manual test from QE? If yes, steps to reproduce]: 
No.
[List of other uplifts needed for the feature/fix]:
None.
[Is the change risky?]:
Low risk.
[Why is the change risky/not risky?]:
This causes the send and receive streams to be deleted earlier during shutdown than was previously the case, but they are currently allowed to be null anyway so this should be a safe change. There is a risk of introducing a shutdown hang by doing this, which I've tested for manually.
[String changes made/needed]:
None.
Flags: needinfo?(dminor)
Attachment #8927441 - Flags: approval-mozilla-beta?
Comment on attachment 8927441 [details] [diff] [review]
Add DeleteStreams to media conduits

[Approval Request Comment]
If this is not a sec:{high,crit} bug, please state case for ESR consideration:
User impact if declined:
Crashes / security problems. 
Fix Landed on Version:
62.
Risk to taking this patch (and alternatives if risky): 
Low.
String or UUID changes made by this patch: 
None.

See https://wiki.mozilla.org/Release_Management/ESR_Landing_Process for more info.
Attachment #8927441 - Flags: approval-mozilla-esr60?
Comment on attachment 8927441 [details] [diff] [review]
Add DeleteStreams to media conduits

Fixes a sec-high, approved for 61.0b4.
Attachment #8927441 - Flags: approval-mozilla-beta? → approval-mozilla-beta+
Comment on attachment 8927441 [details] [diff] [review]
Add DeleteStreams to media conduits

sec-high fix for 60.1esr
Attachment #8927441 - Flags: approval-mozilla-esr60? → approval-mozilla-esr60+
Whiteboard: [adv-main61+][adv-esr60.1+]
Flags: qe-verify-
Whiteboard: [adv-main61+][adv-esr60.1+] → [adv-main61+][adv-esr60.1+][post-critsmash-triage]
Depends on: 1460653
Group: core-security-release
You need to log in before you can comment on or make changes to this bug.