1861805 - Intermittent Assertion failure: aPtr.mMutationCount == mMutationCount, at /builds/worker/workspace/obj-build/dist/include/mozilla/HashTable.h:2137 | single tracking bug

Status: RESOLVED FIXED

(Core :: Audio/Video, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=434148275&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Ks1Wl3vvQgiy9XjfEwlNXQ/runs/0/artifacts/public/logs/live_backing.log

---

[task 2023-10-28T08:10:56.986Z] 08:10:56     INFO - TEST-START | dom/media/test/test_mediarecorder_record_gum_video_timeslice_mixed.html
[task 2023-10-28T08:10:57.104Z] 08:10:57     INFO - GECKO(3688) | Assertion failure: aPtr.mMutationCount == mMutationCount, at /builds/worker/workspace/obj-build/dist/include/mozilla/HashTable.h:2137
[task 2023-10-28T08:10:57.110Z] 08:10:57     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2023-10-28T08:11:20.699Z] 08:11:20     INFO - GECKO(3688) | #01: mozilla::MediaTrackGraphImpl::GetInstance(mozilla::MediaTrackGraph::GraphDriverType, unsigned long long, int, void const*, nsISerialEventTarget*) [dom/media/MediaTrackGraph.cpp:3381]
[task 2023-10-28T08:11:20.699Z] 08:11:20     INFO - GECKO(3688) | #02: mozilla::GetUserMediaStreamTask::PrepareDOMStream() [dom/media/MediaManager.cpp:0]
[task 2023-10-28T08:11:20.699Z] 08:11:20     INFO - GECKO(3688) | #03: mozilla::detail::RunnableMethodImpl<mozilla::GetUserMediaStreamTask*, void (mozilla::GetUserMediaStreamTask::*)(), true, (mozilla::RunnableKind)0, >::Run() [xpcom/threads/nsThreadUtils.h:1213]
[task 2023-10-28T08:11:20.700Z] 08:11:20     INFO - GECKO(3688) | #04: mozilla::RunnableTask::Run() [xpcom/threads/TaskController.cpp:550]
[task 2023-10-28T08:11:20.700Z] 08:11:20     INFO - GECKO(3688) | #05: mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:0]
[task 2023-10-28T08:11:20.701Z] 08:11:20     INFO - GECKO(3688) | #06: mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) [xpcom/threads/TaskController.cpp:0]
[task 2023-10-28T08:11:20.701Z] 08:11:20     INFO - GECKO(3688) | #07: mozilla::TaskController::ProcessPendingMTTask(bool) [xpcom/threads/TaskController.cpp:485]
[task 2023-10-28T08:11:20.701Z] 08:11:20     INFO - GECKO(3688) | #08: mozilla::detail::RunnableFunction<mozilla::TaskController::TaskController()::$_0>::Run() [xpcom/threads/nsThreadUtils.h:549]
[task 2023-10-28T08:11:20.701Z] 08:11:20     INFO - GECKO(3688) | #09: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1202]
[task 2023-10-28T08:11:20.702Z] 08:11:20     INFO - GECKO(3688) | #10: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:480]
[task 2023-10-28T08:11:20.702Z] 08:11:20     INFO - GECKO(3688) | #11: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:85]
[task 2023-10-28T08:11:20.702Z] 08:11:20     INFO - GECKO(3688) | #12: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:346]
[task 2023-10-28T08:11:20.702Z] 08:11:20     INFO - GECKO(3688) | #13: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:150]
[task 2023-10-28T08:11:20.703Z] 08:11:20     INFO - GECKO(3688) | #14: nsAppShell::Run() [widget/cocoa/nsAppShell.mm:870]
[task 2023-10-28T08:11:20.703Z] 08:11:20     INFO - GECKO(3688) | #15: XRE_RunAppShell() [toolkit/xre/nsEmbedFunctions.cpp:721]
[task 2023-10-28T08:11:20.703Z] 08:11:20     INFO - GECKO(3688) | #16: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:235]
[task 2023-10-28T08:11:20.704Z] 08:11:20     INFO - GECKO(3688) | #17: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:346]
[task 2023-10-28T08:11:20.704Z] 08:11:20     INFO - GECKO(3688) | #18: XRE_InitChildProcess(int, char**, XREChildData const*) [toolkit/xre/nsEmbedFunctions.cpp:0]
[task 2023-10-28T08:11:20.704Z] 08:11:20     INFO - GECKO(3688) | #19: main [ipc/app/MozillaRuntimeMain.cpp:90]
[task 2023-10-28T08:11:20.704Z] 08:11:20     INFO - GECKO(3688) | [Parent 3688, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2EBB2C3056569DF5.48A635A94EDA33D1: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
[task 2023-10-28T08:11:20.705Z] 08:11:20     INFO - GECKO(3688) | [Parent 3688, IPC I/O Parent] WARNING: [1.1]: Ignoring message 'EVENT_MESSAGE' to unknown peer 2EBB2C3056569DF5.48A635A94EDA33D1: file /builds/worker/checkouts/gecko/ipc/glue/NodeController.cpp:344
<...>

Comment 1

[Iulian Moraru]

Hi Karl! Can you please take a look at this and at Bug 1861495, I think they might be caused by the recent changes from Bug 1860954,
Thank you!

Comment 2

[Intermittent Failures Robot]

1 failures in 3657 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1861805&startday=2023-10-23&endday=2023-10-29&tree=all

Comment 3

[Karl Tomlinson (:karlt)]

https://treeherder.mozilla.org/jobs?repo=try&revision=c612636844fb5c96ad36fa051f2220e051107a59&selectedTaskRun=dIcaQXtoTAKd01rE_qoghw.0 has logging to identify the problem stack.

AddShutdownBlocker() is implemented in JS and so allows GC to occur.

Sometimes GC can trigger synchronous finalization of C++ objects.

Thread 0 MainThread (crashed)
 0  XUL!mozilla::MediaTrackGraphImpl::RemoveTrack(mozilla::MediaTrack*) [MediaTrackGraph.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 3658 + 0x0]
     rax = 0x000000010d0df6b5    rdx = 0x0000000000000000
     rcx = 0x0000000110adaa38    rbx = 0x000000011d209e00
     rsi = 0x00000000000120a8    rdi = 0x00007fff96301ca8
     rbp = 0x00007ffeede18c10    rsp = 0x00007ffeede18ba0
      r8 = 0x00000000000130a8     r9 = 0x0000000000000000
     r10 = 0x00007fff96301cc8    r11 = 0x00007fff96301cc0
     r12 = 0x00000000000000d9    r13 = 0x0000000000000000
     r14 = 0x000000011d03fdc0    r15 = 0x000000011d0da960
     rip = 0x0000000105ab1071
    Found by: given as instruction pointer in context
 1  XUL!mozilla::MediaTrack::Destroy() [MediaTrackGraph.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 2297 + 0xa]
     rbx = 0x000000011d03fdc0    rbp = 0x00007ffeede18c50
     rsp = 0x00007ffeede18c20    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011d209e00
     r15 = 0x000000011d0da960    rip = 0x0000000105ab0b2c
    Found by: call frame info
 2  XUL!mozilla::SharedDummyTrack::~SharedDummyTrack() [MediaTrackGraph.h:c612636844fb5c96ad36fa051f2220e051107a59 : 818 + 0x5]
     rbx = 0x000000011d28c1a0    rbp = 0x00007ffeede18c70
     rsp = 0x00007ffeede18c60    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x0000000000000000
     r15 = 0x0000000000000095    rip = 0x000000010580eb78
    Found by: call frame info
 3  XUL!mozilla::SharedDummyTrack::~SharedDummyTrack() [MediaTrackGraph.h:c612636844fb5c96ad36fa051f2220e051107a59 : 818]
    Found by: inlining
 4  XUL!mozilla::SharedDummyTrack::Release() [MediaTrackGraph.h:c612636844fb5c96ad36fa051f2220e051107a59 : 811 + 0x7]
     rbx = 0x000000011d28c1a0    rbp = 0x00007ffeede18c90
     rsp = 0x00007ffeede18c80    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x0000000000000000
     r15 = 0x0000000000000095    rip = 0x000000010580eb14
    Found by: call frame info
 5  XUL!mozilla::RefPtrTraits<mozilla::SharedDummyTrack>::Release(mozilla::SharedDummyTrack*) [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 54]
    Found by: inlining
 6  XUL!RefPtr<mozilla::SharedDummyTrack>::ConstRemovingRefPtrTraits<mozilla::SharedDummyTrack>::Release(mozilla::SharedDummyTrack*) [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 420]
    Found by: inlining
 7  XUL!RefPtr<mozilla::SharedDummyTrack>::~RefPtr() [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 85]
    Found by: inlining
 8  XUL!RefPtr<mozilla::SharedDummyTrack>::~RefPtr() [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 83]
    Found by: inlining
 9  XUL!mozilla::MediaEncoder::~MediaEncoder() [MediaEncoder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 482 + 0x10]
     rbx = 0x000000011d243e00    rbp = 0x00007ffeede18cc0
     rsp = 0x00007ffeede18ca0    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x0000000000000000
     r15 = 0x0000000000000095    rip = 0x0000000105b3b7db
    Found by: call frame info
10  XUL!mozilla::MediaEncoder::Release() [MediaEncoder.h:c612636844fb5c96ad36fa051f2220e051107a59 : 114 + 0x1a]
     rbx = 0x0000000000000000    rbp = 0x00007ffeede18ce0
     rsp = 0x00007ffeede18cd0    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011d243e00
     r15 = 0x0000000000000095    rip = 0x0000000105ac76b1
    Found by: call frame info
11  XUL!mozilla::RefPtrTraits<mozilla::MediaEncoder>::Release(mozilla::MediaEncoder*) [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 54]
    Found by: inlining
12  XUL!RefPtr<mozilla::MediaEncoder>::ConstRemovingRefPtrTraits<mozilla::MediaEncoder>::Release(mozilla::MediaEncoder*) [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 420]
    Found by: inlining
13  XUL!RefPtr<mozilla::MediaEncoder>::~RefPtr() [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 85]
    Found by: inlining
14  XUL!RefPtr<mozilla::MediaEncoder>::~RefPtr() [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 83]
    Found by: inlining
15  XUL!mozilla::dom::MediaRecorder::Session::~Session() [MediaRecorder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 798 + 0xd]
     rbx = 0x000000011d20f920    rbp = 0x00007ffeede18d10
     rsp = 0x00007ffeede18cf0    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011d089e20
     r15 = 0x0000000000000095    rip = 0x0000000105acca55
    Found by: call frame info
16  XUL!mozilla::dom::MediaRecorder::Session::~Session() [MediaRecorder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 793]
    Found by: inlining
17  XUL!mozilla::dom::MediaRecorder::Session::~Session() [MediaRecorder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 793 + 0x4]
     rbx = 0x000000011d20f920    rbp = 0x00007ffeede18d30
     rsp = 0x00007ffeede18d20    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011d20f920
     r15 = 0x0000000000000095    rip = 0x0000000105ac37de
    Found by: call frame info
18  XUL!mozilla::dom::MediaRecorder::Session::Release() [MediaRecorder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 572]
    Found by: inlining
19  XUL!mozilla::RefPtrTraits<mozilla::dom::MediaRecorder::Session>::Release(mozilla::dom::MediaRecorder::Session*) [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 54]
    Found by: inlining
20  XUL!RefPtr<mozilla::dom::MediaRecorder::Session>::ConstRemovingRefPtrTraits<mozilla::dom::MediaRecorder::Session>::Release(mozilla::dom::MediaRecorder::Session*) [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 420]
    Found by: inlining
21  XUL!RefPtr<mozilla::dom::MediaRecorder::Session>::~RefPtr() [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 85]
    Found by: inlining
22  XUL!RefPtr<mozilla::dom::MediaRecorder::Session>::~RefPtr() [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 83]
    Found by: inlining
23  XUL!mozilla::dom::MediaRecorder::Session::InitEncoder(unsigned char, int, mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator>)::Blocker::~Blocker() [MediaRecorder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 828]
    Found by: inlining
24  XUL!mozilla::dom::MediaRecorder::Session::InitEncoder(unsigned char, int, mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator>)::Blocker::~Blocker() [MediaRecorder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 828]
    Found by: inlining
25  XUL!mozilla::dom::MediaRecorder::Session::InitEncoder(unsigned char, int, mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator>)::Blocker::~Blocker() [MediaRecorder.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 828 + 0x57]
     rbx = 0x000000011c7fe460    rbp = 0x00007ffeede18d50
     rsp = 0x00007ffeede18d40    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011d20f920
     r15 = 0x0000000000000095    rip = 0x0000000105acdd62
    Found by: call frame info
26  XUL!mozilla::media::ShutdownBlocker::Release() [MediaUtils.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 39 + 0x8]
     rbx = 0x0000000000000000    rbp = 0x00007ffeede18d70
     rsp = 0x00007ffeede18d60    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011c7fe460
     r15 = 0x0000000000000095    rip = 0x0000000105e9221c
    Found by: call frame info
27  XUL!mozilla::RefPtrTraits<nsISupports>::Release(nsISupports*) [RefPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 54]
    Found by: inlining
28  XUL!nsCOMPtr<nsISupports>::~nsCOMPtr() [nsCOMPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 344]
    Found by: inlining
29  XUL!nsCOMPtr<nsISupports>::~nsCOMPtr() [nsCOMPtr.h:c612636844fb5c96ad36fa051f2220e051107a59 : 341]
    Found by: inlining
30  XUL!mozilla::SegmentedVector<nsCOMPtr<nsISupports>, (unsigned long)4096, mozilla::MallocAllocPolicy>::SegmentImpl<(unsigned long)509>::~SegmentImpl() [SegmentedVector.h:c612636844fb5c96ad36fa051f2220e051107a59 : 78 + 0x1d]
     rbx = 0x000000011d029000    rbp = 0x00007ffeede18da0
     rsp = 0x00007ffeede18d80    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011d0294c0
     r15 = 0x0000000000000095    rip = 0x0000000102328a1d
    Found by: call frame info
31  XUL!mozilla::SegmentedVector<nsCOMPtr<nsISupports>, (unsigned long)4096, mozilla::MallocAllocPolicy>::SegmentImpl<(unsigned long)509>::~SegmentImpl() [SegmentedVector.h:c612636844fb5c96ad36fa051f2220e051107a59 : 76]
    Found by: inlining
32  XUL!mozilla::SegmentedVector<nsCOMPtr<nsISupports>, (unsigned long)4096, mozilla::MallocAllocPolicy>::PopLastN(unsigned int) [SegmentedVector.h:c612636844fb5c96ad36fa051f2220e051107a59 : 246 + 0x7]
     rbx = 0x00000000000000d9    rbp = 0x00007ffeede18de0
     rsp = 0x00007ffeede18db0    r12 = 0x00000000000000d9
     r13 = 0x0000000000000000    r14 = 0x000000011bdd9ba0
     r15 = 0x000000011d029000    rip = 0x0000000102328834
    Found by: call frame info
33  XUL!mozilla::dom::DeferredFinalizerImpl<nsISupports>::DeferredFinalize(unsigned int, void*) [BindingUtils.h:c612636844fb5c96ad36fa051f2220e051107a59 : 2803 + 0x7]
     rbx = 0x00000000ffffffff    rbp = 0x00007ffeede18e10
     rsp = 0x00007ffeede18df0    r12 = 0x000000011d22b580
     r13 = 0x0000000000000000    r14 = 0x000000011bdd9ba0
     r15 = 0x00000000000000d9    rip = 0x0000000102312473
    Found by: call frame info
34  XUL!mozilla::IncrementalFinalizeRunnable::ReleaseNow(bool) [CycleCollectedJSRuntime.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 1679 + 0xa]
     rbx = 0x000000011d22b5c8    rbp = 0x00007ffeede18e70
     rsp = 0x00007ffeede18e20    r12 = 0x000000011d22b580
     r13 = 0x0000000000000000    r14 = 0x0000000000000000
     r15 = 0x0000000000000000    rip = 0x0000000102312b4b
    Found by: call frame info
35  XUL!mozilla::CycleCollectedJSRuntime::FinalizeDeferredThings(mozilla::CycleCollectedJSContext::DeferredFinalizeType) [CycleCollectedJSRuntime.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 1733 + 0x6]
     rbx = 0x0000000110e4c600    rbp = 0x00007ffeede18eb0
     rsp = 0x00007ffeede18e80    r12 = 0x000000011352e100
     r13 = 0x0000000000000000    r14 = 0x0000000000000000
     r15 = 0x0000000000000008    rip = 0x0000000102313076
    Found by: call frame info
36  XUL!mozilla::CycleCollectedJSRuntime::OnGC(JSContext*, JSGCStatus, JS::GCReason) [CycleCollectedJSRuntime.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 1831 + 0xa]
     rbx = 0x0000000000000001    rbp = 0x00007ffeede18f00
     rsp = 0x00007ffeede18ec0    r12 = 0x000000011352e100
     r13 = 0x0000000000000000    r14 = 0x0000000110e4c600
     r15 = 0x0000000000000008    rip = 0x000000010231101d
    Found by: call frame info
37  XUL!js::gc::GCRuntime::maybeCallGCCallback(JSGCStatus, JS::GCReason) [GC.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 4132 + 0xd]
     rbx = 0x0000000113523728    rbp = 0x00007ffeede18f70
     rsp = 0x00007ffeede18f10    r12 = 0x000000010de6b098
     r13 = 0x0000000000000000    r14 = 0x0000000000000001
     r15 = 0x0000000000000008    rip = 0x000000010963da94
    Found by: call frame info
38  XUL!js::gc::AutoCallGCCallbacks::~AutoCallGCCallbacks() [GC.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 4105]
    Found by: inlining
39  XUL!js::gc::AutoCallGCCallbacks::~AutoCallGCCallbacks() [GC.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 4105]
    Found by: inlining
40  XUL!js::gc::GCRuntime::gcCycle(bool, js::SliceBudget const&, JS::GCReason) [GC.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 4222 + 0x12]
     rbx = 0x0000000000000001    rbp = 0x00007ffeede19060
     rsp = 0x00007ffeede18f80    r12 = 0x000000010de6b098
     r13 = 0x0000000000000008    r14 = 0x0000000113523728
     r15 = 0x00000000006ae487    rip = 0x000000010963e955
    Found by: call frame info
41  XUL!js::gc::GCRuntime::collect(bool, js::SliceBudget const&, JS::GCReason) [GC.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 4407 + 0x16]
     rbx = 0x0000000000000008    rbp = 0x00007ffeede19120
     rsp = 0x00007ffeede19070    r12 = 0x0000000000000008
     r13 = 0x000000010de6b098    r14 = 0x0000000113523728
     r15 = 0x000000011352e100    rip = 0x0000000109640084
    Found by: call frame info
42  XUL!js::gc::GCRuntime::gcSlice(JS::GCReason, js::SliceBudget const&) [GC.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 4507]
    Found by: inlining
43  XUL!js::gc::GCRuntime::gcIfRequestedImpl(bool) [GC.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 4683 + 0x37]
     rbx = 0x0000000113523728    rbp = 0x00007ffeede19190
     rsp = 0x00007ffeede19130    r12 = 0x0000000000000000
     r13 = 0x000000010de6b098    r14 = 0x000000000000000f
     r15 = 0x000000010de6b098    rip = 0x0000000109629e9b
    Found by: call frame info
44  XUL!js::gc::GCRuntime::gcIfRequested() [GCRuntime.h:c612636844fb5c96ad36fa051f2220e051107a59 : 327]
    Found by: inlining
45  XUL!HandleInterrupt(JSContext*, bool) [Runtime.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 390]
    Found by: inlining
46  XUL!JSContext::handleInterrupt() [Runtime.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 483 + 0x27]
     rbx = 0x000000011352e100    rbp = 0x00007ffeede19440
     rsp = 0x00007ffeede191a0    r12 = 0x0000000000000000
     r13 = 0x000000010de6b098    r14 = 0x000033425213f030
     r15 = 0x000000010de6b098    rip = 0x00000001090de213
    Found by: call frame info
47  XUL!js::Interpret(JSContext*, js::RunState&) [Interpreter.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 1985 + 0xb]
     rbx = 0x0000000000000021    rbp = 0x00007ffeede198c0
     rsp = 0x00007ffeede19450    r12 = 0xfff9800000000000
     r13 = 0x000000010de6b098    r14 = 0x000033425213f030
     r15 = 0x000000010dbad790    rip = 0x0000000108d44246
    Found by: call frame info
48  XUL!js::RunScript(JSContext*, js::RunState&) [Interpreter.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 444 + 0xa]
     rbx = 0x000000011352e100    rbp = 0x00007ffeede19920
     rsp = 0x00007ffeede198d0    r12 = 0x000000010de6b098
     r13 = 0x0000000000000000    r14 = 0x00007ffeede19960
     r15 = 0x000001c7e68234a0    rip = 0x0000000108d3c1da
    Found by: call frame info
49  XUL!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 598 + 0x7]
     rbx = 0x000000011352e100    rbp = 0x00007ffeede199c0
     rsp = 0x00007ffeede19930    r12 = 0x00007ffeede19940
     r13 = 0x0000238cea8ccac0    r14 = 0x00007ffeede19a68
     r15 = 0x0000000113507c00    rip = 0x0000000108d3ceb8
    Found by: call frame info
50  XUL!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [Interpreter.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 665 + 0xd]
     rbx = 0x00007ffeede19a68    rbp = 0x00007ffeede19a20
     rsp = 0x00007ffeede199d0    r12 = 0x00007ffeede19cd0
     r13 = 0x0000238cea8c88c8    r14 = 0x0000000000000000
     r15 = 0x000000011352e100    rip = 0x0000000108d3e4db
    Found by: call frame info
51  XUL!JS_CallFunctionValue(JSContext*, JS::Handle<JSObject*>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [CallAndConstruct.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 55 + 0x22]
     rbx = 0x00007ffeede19c90    rbp = 0x00007ffeede19ba0
     rsp = 0x00007ffeede19a30    r12 = 0x0000000000000004
     r13 = 0x0000000000000004    r14 = 0x00007ffeede19b10
     r15 = 0x00007ffeede19b00    rip = 0x0000000108e82f1d
    Found by: call frame info
52  XUL!nsXPCWrappedJS::CallMethod(unsigned short, nsXPTMethodInfo const*, nsXPTCMiniVariant*) [XPCWrappedJSClass.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 918 + 0x2e]
     rbx = 0x00007ffeede19d30    rbp = 0x00007ffeede19fc0
     rsp = 0x00007ffeede19bb0    r12 = 0x00007ffeede19d00
     r13 = 0x00007ffeede1a000    r14 = 0x000000010b412778
     r15 = 0x000000011352e100    rip = 0x0000000103015d47
    Found by: call frame info
53  XUL!PrepareAndDispatch [xptcstubs_x86_64_darwin.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 117 + 0x28]
     rbx = 0x000000011d22ffc0    rbp = 0x00007ffeede1a0a0
     rsp = 0x00007ffeede19fd0    r12 = 0x0000000000000005
     r13 = 0x00007ffeede1a130    r14 = 0x0000000000000005
     r15 = 0x0000000000000000    rip = 0x0000000102476e95
    Found by: call frame info
54  XUL!SharedStub + 0x5a
     rbx = 0x000000011d0aca00    rbp = 0x00007ffeede1a120
     rsp = 0x00007ffeede1a0b0    r12 = 0x000000011c752dd8
     r13 = 0x000000010b3da898    r14 = 0x00007ffeede1a158
     r15 = 0x000000011c752dc0    rip = 0x0000000102475bbb
    Found by: call frame info
55  0x11d22ffbf
     rbx = 0x000000011d0aca00    rbp = 0x00007ffeede1a120
     rsp = 0x00007ffeede1a0b8    r12 = 0x000000011c752dd8
     r13 = 0x000000010b3da898    r14 = 0x00007ffeede1a158
     r15 = 0x000000011c752dc0    rip = 0x000000011d22ffc0
    Found by: call frame info
56  XUL!mozilla::MediaTrackGraphImpl::AddShutdownBlocker() [MediaTrackGraph.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 1760 + 0x12]
     rbp = 0x00007ffeede1a1a0    rsp = 0x00007ffeede1a130
     rip = 0x0000000105aae168
    Found by: previous frame's frame pointer
57  XUL!mozilla::MediaTrackGraphImpl::MediaTrackGraphImpl(mozilla::MediaTrackGraph::GraphDriverType, mozilla::MediaTrackGraph::GraphRunType, unsigned long long, int, unsigned int, void const*, nsISerialEventTarget*) [MediaTrackGraph.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 3277 + 0x7]
     rbx = 0x000000011d0aca00    rbp = 0x00007ffeede1a210
     rsp = 0x00007ffeede1a1b0    r12 = 0x000000010b3f1cc0
     r13 = 0x0000000000000000    r14 = 0x000000011d0acb00
     r15 = 0x000000011d0aca10    rip = 0x0000000105ab6651
    Found by: call frame info
58  XUL!mozilla::MediaTrackGraphImpl::MediaTrackGraphImpl(mozilla::MediaTrackGraph::GraphDriverType, mozilla::MediaTrackGraph::GraphRunType, unsigned long long, int, unsigned int, void const*, nsISerialEventTarget*) [MediaTrackGraph.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 3274]
    Found by: inlining
59  XUL!mozilla::MediaTrackGraphImpl::GetInstance(mozilla::MediaTrackGraph::GraphDriverType, unsigned long long, int, void const*, nsISerialEventTarget*) [MediaTrackGraph.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 3411 + 0x30]
     rbx = 0x0000000000000002    rbp = 0x00007ffeede1a300
     rsp = 0x00007ffeede1a220    r12 = 0x0000000000000001
     r13 = 0x000000011bdfcd60    r14 = 0x000000011d249348
     r15 = 0x000000011d0aca00    rip = 0x0000000105ab7208
    Found by: call frame info
60  XUL!mozilla::GetUserMediaStreamTask::PrepareDOMStream() [MediaManager.cpp:c612636844fb5c96ad36fa051f2220e051107a59 : 1507 + 0x8]
     rbx = 0x000000011d2c2ee8    rbp = 0x00007ffeede1a7b0
     rsp = 0x00007ffeede1a310    r12 = 0xaaaaaaaaaaaaaaaa
     r13 = 0x0000000110eadbc0    r14 = 0x00007ffeede1a868
     r15 = 0x000000011d2c2700    rip = 0x00000001059a297f
    Found by: call frame info

Comment 4

[Karl Tomlinson (:karlt)]

There are multiple options for addressing this, but I have some questions:

I doubt C++ callers are usually considering that any method on an XPIDL interface might cause unrelated C++ objects to be deleted.
C++ callers need to go to special effort to deal with this when a nested event loop might be run. They do not expect the same effort is necessary for all XPIDL methods and they should not need to care whether the interface is implemented in C++ or JS.
If the JIT benefits from assuming no side effects, then presumably C++ would also benefit from assurance of no side effects.

I can see the appeal of finalizing in low memory situations, but, as there are so many situations where we don't finalize synchronously, is synchronous finalization in the other situations worth the cost?
(I understand the need for the DESTROY_RUNTIME special case and almost everything should be shut down by then.)

I'm not certain which GCReason is involved here (HandleInterrupt() is on the stack), but should NO_REASON be considered an InternalGCReason()?
Currently it is not.

Comment 5

[Karl Tomlinson (:karlt)]

Oh, the GCReason here is probably not NO_REASON.

Comment 6

[Karl Tomlinson (:karlt)]

The stack in comment 3 challenges my understanding of when C++ code can have run-to-completion expectations, so I'm trying to understand what precise circumstances are the danger cases in which to be aware that those expectations are incorrect.

In my mind, if destroying an object will have side-effects, then it is not garbage. I'm not too familiar with spidermonkey GC but I assume that it can GC at any point mid-code-execution because GC has no side effects. Conversely, I'd expect CC and arbitrary C++ object finalizers to run as a dedicated task so as not to break run-to-completion expectations of C++ callers.

What is the factor here that means that this code should be aware of side-effects because run-to-completion is not provided?

Is it because an XPIDL method is called?

Or is this special because the objects involved are modified by destructors?

Comment 7

[Andrew McCreight [:mccr8]]

I have a few semi-unrelated points here that hopefully answer some of your questions.

1. In general, yes you do need to be aware that random non-trivial methods can end up running JS and running the GC. We have to deal with this in DOM code all over the place. We have a few mechanisms, like the GC rooting analysis and MOZ_CAN_RUN_SCRIPT which try to detect some of the bad things that can happen.
2. I think part of the issue is that it is kind of weird that the async shutdown blocker is implemented in JS. It certainly doesn't match my intuition for what would be implemented in JS. I think we've idly discussed rewriting it in C++ but I don't think anything has actually happened.
3. How is ShutdownBlocker::Release() calling MediaRecorder::Session::InitEncoder()? That is weird to me.
4. AddRefing this, like MediaTrackGraphImpl::MediaTrackGraphImpl() does in AddShutdownBlock, is a bad idea in general, because the object has a refcount of zero by default so if you end up releasing it, it'll get destroyed. That being said, it seems like mSelfRef will avoid that issue. There are also possible issues with calling virtual methods in the presence of subclasses because the vtable will still be for MediaTrackGraphImpl(), but most of the time that shouldn't be a problem for refcounting.

Anyways, despite all of what I just said, looking at bug 1619229 it does appear that we have an expectation that these finalizers don't run synchronously, and it does appear that we have a bug in this code. According to the stack, CycleCollectedJSRuntime::FinalizeDeferredThings() is on line 1733, which from the chunk of code at the start of the method. In other words, we are not synchronously finalizing objects from the current GC, we are doing it for objects from the prior GC that we didn't get around to finalizing yet. I guess I overlooked that when I was fixing bug 1619229. I'll file a new bug blocking this one and try to remember how this all works so I can write a patch. There's lots of odd cases, as you can see.

Comment 8

[Karl Tomlinson (:karlt)]

(In reply to Andrew McCreight [:mccr8] from comment #7)

Thank you for looking carefully and for all the comments. I'll put in a few replies in an attempt to clarify some things.

2. I think part of the issue is that it is kind of weird that the async shutdown blocker is implemented in JS. It certainly doesn't match my intuition for what would be implemented in JS. I think we've idly discussed rewriting it in C++ but I don't think anything has actually happened.

That might be a factor here, so I guess a key philosophical question is whether the implementation language should be a factor? If it should be then perhaps we'd like MOZ_CAN_RUN_SCRIPT on all interfaces that might be implemented by JS. That depends on whether GC side-effects are considered like nested-event-loop side-effects.

3. How is ShutdownBlocker::Release() calling MediaRecorder::Session::InitEncoder()? That is weird to me.

Yes, that would be weird, but it is not actually InitEncoder() but a quirk of the naming of the nested Blocker class.

The "weird" concept relates to perhaps an expectation that methods that might be called from destructors fall into a different category, perhaps a category that might be called mid-code-execution.

4. AddRefing this, like MediaTrackGraphImpl::MediaTrackGraphImpl() does in AddShutdownBlock, is a bad idea in general, because the object has a refcount of zero by default so if you end up releasing it, it'll get destroyed. That being said, it seems like mSelfRef will avoid that issue. There are also possible issues with calling virtual methods in the presence of subclasses because the vtable will still be for MediaTrackGraphImpl(), but most of the time that shouldn't be a problem for refcounting.

Sound advice, thanks. The mSelfRef works out there, yes, and there are no subclasses (even though not marked final). Ownership is instead controlled by the number of tracks on the graph. As there are initially zero tracks, it is as fragile in the presence of side-effects as Gecko's standard ref-counted objects. This is somewhat mitigated usually by delay of destruction to another task.

Anyways, despite all of what I just said, looking at bug 1619229 it does appear that we have an expectation that these finalizers don't run synchronously, and it does appear that we have a bug in this code. According to the stack, CycleCollectedJSRuntime::FinalizeDeferredThings() is on line 1733, which from the chunk of code at the start of the method. In other words, we are not synchronously finalizing objects from the current GC, we are doing it for objects from the prior GC that we didn't get around to finalizing yet.

Ah, pleased you spotted that. Thanks!