1723233 - Extra main thread runnables on every composite for ChromeProcessController::NotifyLayerTransforms

Reporter

Description

•

3 years ago

Profile: https://share.firefox.dev/3zKQk1I

During video playback, or any compositor-side animation, we dispatch runnables to the main thread for every composited frame. This causes extra CPU wakeups and CPU usage, and runs into event loop overhead issues such as bug 1690669.

Can we avoid ChromeProcessController::NotifyLayerTransforms runnables if the values haven't changed?

BugBot [:suhaib / :marco/ :calixte]

Updated

•

3 years ago

Keywords: regression

Hiroyuki Ikezoe (:hiro)

Comment 1

•

3 years ago

We don't send the notification unnecessary, it's triggered when a content repaint request happens and when hit testing tree gets updated.

Interestingly when my mouse cursor on youtube video element which is playing, the hit testing tree code keeps happening.

Hiroyuki Ikezoe (:hiro)

Comment 2

•

3 years ago

It looks like in my case, it's coming from the video progress indicator (the red line) at the bottom of the video, after the indicator has been disappeared I don't get further notifications any more.

Botond Ballo [:botond]

Updated

•

3 years ago

Severity: -- → S3

Priority: -- → P2

Frank Griffith Jr

Comment 3

•

3 years ago

We can stage this within our APZ Stabilization Sprint I FFXP-370

Hiroyuki Ikezoe (:hiro)

Comment 4

•

3 years ago

Hello Marc, I've heard that you might have some interests in APZ stuff, so I am CCing you on this bug (I'd hope you will be interested in this bug!)

So the runnable we want to avoid is triggered from SendSubtreeTransformsToChromeMainThread.

To avoid the call, we can simply have 'nsTArray<MatrixMessage>' in APZCTreeManager as a private member to store the previous MatrixMessages and compare it with the new one there and notify them only if it's changed. To compare the two MatrixMessages this MatrixMessage class needs operator!=, the operator should be straight forward something like this.

Thanks!

Marc Leclair [:mleclair]

Assignee

Comment 5

•

3 years ago

(In reply to Hiroyuki Ikezoe (:hiro) from comment #4)

Hello Marc, I've heard that you might have some interests in APZ stuff, so I am CCing you on this bug (I'd hope you will be interested in this bug!)

Hey! I'd be happy to take over the issue (I'll do my best that is haha)

Botond Ballo [:botond]

Updated

•

3 years ago

See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1707198

Markus Stange [:mstange]

Reporter

Updated

•

3 years ago

Whiteboard: [qf] → [qf:p3:resource]

Marc Leclair [:mleclair]

Assignee

Comment 6

•

3 years ago

Attached file Bug 1723233 - Check if messages were seen before notifying layer transforms r=hiro (deleted) — Details

Phabricator Automation

Updated

•

3 years ago

Assignee: nobody → mleclair

Status: NEW → ASSIGNED

Pulsebot

Comment 7

•

3 years ago

Pushed by mleclair@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/8ba9fccd412c Check if messages were seen before notifying layer transforms r=hiro

Iulian Moraru

Comment 8

•

3 years ago

Backed out for causing ThreadSanitizer failures on nsTArray.h.

Push with failures

It seems that the only affected platform is Linux 18.04 x64 WebRender tsan opt.
Failure log for bc failures
Failure log for wpt failures
Failure log for mda failures
Failure log for mochitest plain failures

Backout link

[task 2021-11-24T21:37:31.303Z] 21:37:31     INFO - TEST-START | browser/base/content/test/general/browser_bug724239.js
[task 2021-11-24T21:37:32.765Z] 21:37:32     INFO - GECKO(1596) | ==================
[task 2021-11-24T21:37:32.766Z] 21:37:32     INFO - GECKO(1596) | WARNING: ThreadSanitizer: data race (pid=1596)
[task 2021-11-24T21:37:32.766Z] 21:37:32     INFO - GECKO(1596) |   Read of size 4 at 0x7b4000160e00 by thread T61 (mutexes: write M54178882137212024):
[task 2021-11-24T21:37:32.766Z] 21:37:32     INFO - GECKO(1596) |     #0 Length /builds/worker/workspace/obj-build/dist/include/nsTArray.h:410:43 (libxul.so+0x232b131)
[task 2021-11-24T21:37:32.766Z] 21:37:32     INFO - GECKO(1596) |     #1 bool nsTArray_Impl<mozilla::layers::MatrixMessage, nsTArrayInfallibleAllocator>::operator==<nsTArrayInfallibleAllocator>(nsTArray_Impl<mozilla::layers::MatrixMessage, nsTArrayInfallibleAllocator> const&) const /builds/worker/workspace/obj-build/dist/include/nsTArray.h:1113:23 (libxul.so+0x232b131)
[task 2021-11-24T21:37:32.766Z] 21:37:32     INFO - GECKO(1596) |     #2 operator!= /builds/worker/workspace/obj-build/dist/include/nsTArray.h:1130:13 (libxul.so+0x22d1740)
[task 2021-11-24T21:37:32.766Z] 21:37:32     INFO - GECKO(1596) |     #3 mozilla::layers::APZCTreeManager::SendSubtreeTransformsToChromeMainThread(mozilla::layers::AsyncPanZoomController const*) /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZCTreeManager.cpp:3574:16 (libxul.so+0x22d1740)
[task 2021-11-24T21:37:32.766Z] 21:37:32     INFO - GECKO(1596) |     #4 mozilla::layers::APZCTreeManager::UpdateHitTestingTree(mozilla::layers::WebRenderScrollDataWrapper const&, bool, mozilla::layers::LayersId, unsigned int) /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZCTreeManager.cpp:697:3 (libxul.so+0x22cefed)
[task 2021-11-24T21:37:32.767Z] 21:37:32     INFO - GECKO(1596) |     #5 operator() /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:195:25 (libxul.so+0x232d764)
[task 2021-11-24T21:37:32.767Z] 21:37:32     INFO - GECKO(1596) |     #6 mozilla::detail::RunnableFunction<mozilla::layers::APZUpdater::UpdateScrollDataAndTreeState(mozilla::layers::LayersId, mozilla::layers::LayersId, mozilla::wr::Epoch const&, mozilla::layers::WebRenderScrollData&&)::$_28>::Run() /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:531:5 (libxul.so+0x232d764)
[task 2021-11-24T21:37:32.767Z] 21:37:32     INFO - GECKO(1596) |     #7 mozilla::layers::APZUpdater::ProcessQueue() /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:458:23 (libxul.so+0x22f6be5)
[task 2021-11-24T21:37:32.768Z] 21:37:32     INFO - GECKO(1596) |     #8 mozilla::layers::APZUpdater::CompleteSceneSwap(mozilla::wr::WrWindowId const&, mozilla::wr::WrPipelineInfo const&) /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:120:12 (libxul.so+0x22f647f)
[task 2021-11-24T21:37:32.769Z] 21:37:32     INFO - GECKO(1596) |     #9 apz_post_scene_swap /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:526:3 (libxul.so+0x22f8c66)
[task 2021-11-24T21:37:32.770Z] 21:37:32     INFO - GECKO(1596) |     #10 _$LT$webrender_bindings..bindings..APZCallbacks$u20$as$u20$webrender..renderer..SceneBuilderHooks$GT$::post_scene_swap::h2dba01f8254ac738 /builds/worker/checkouts/gecko/gfx/webrender_bindings/src/bindings.rs:1004:13 (libxul.so+0x900d8d4)
[task 2021-11-24T21:37:32.771Z] 21:37:32     INFO - GECKO(1596) |     #11 webrender::scene_builder_thread::SceneBuilderThread::forward_built_transactions::h4e6169ea287b82c5 /builds/worker/checkouts/gecko/gfx/wr/webrender/src/scene_builder_thread.rs:719:13 (libxul.so+0x8ed3926)
[task 2021-11-24T21:37:32.772Z] 21:37:32     INFO - GECKO(1596) |     #12 webrender::scene_builder_thread::SceneBuilderThread::run::heab014e9d3a1c4e6 /builds/worker/checkouts/gecko/gfx/wr/webrender/src/scene_builder_thread.rs:319:21 (libxul.so+0x8ed3926)
[task 2021-11-24T21:37:32.774Z] 21:37:32     INFO - GECKO(1596) |     #13 webrender::renderer::Renderer::new::_$u7b$$u7b$closure$u7d$$u7d$::h5d91946008a96b04 /builds/worker/checkouts/gecko/gfx/wr/webrender/src/renderer/mod.rs:1237:13 (libxul.so+0x8ed04f4)
[task 2021-11-24T21:37:32.775Z] 21:37:32     INFO - GECKO(1596) |     #14 std::sys_common::backtrace::__rust_begin_short_backtrace::h39b4177310499764 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:125:18 (libxul.so+0x8ed04f4)
[task 2021-11-24T21:37:32.777Z] 21:37:32     INFO - GECKO(1596) |     #15 std::thread::Builder::spawn_unchecked::_$u7b$$u7b$closure$u7d$$u7d$::_$u7b$$u7b$closure$u7d$$u7d$::hc4fab657ab4fd541 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:481:17 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.789Z] 21:37:32     INFO - GECKO(1596) |     #16 _$LT$core..panic..unwind_safe..AssertUnwindSafe$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$$LP$$RP$$GT$$GT$::call_once::hc9217e9ed816d082 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:271:9 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.790Z] 21:37:32     INFO - GECKO(1596) |     #17 std::panicking::try::do_call::h144371768aa90588 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panicking.rs:403:40 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.790Z] 21:37:32     INFO - GECKO(1596) |     #18 std::panicking::try::h2508b37eaa8bc479 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panicking.rs:367:19 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.791Z] 21:37:32     INFO - GECKO(1596) |     #19 std::panic::catch_unwind::h2802c598e16f1b46 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panic.rs:129:14 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.791Z] 21:37:32     INFO - GECKO(1596) |     #20 std::thread::Builder::spawn_unchecked::_$u7b$$u7b$closure$u7d$$u7d$::h1507728db3c37195 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:480:30 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.792Z] 21:37:32     INFO - GECKO(1596) |     #21 core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::h950df5f6dd83dae9 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/ops/function.rs:227:5 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.793Z] 21:37:32     INFO - GECKO(1596) |     #22 _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::ha3209f0862c00df4 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1636:9 (libxul.so+0x87abd76)
[task 2021-11-24T21:37:32.793Z] 21:37:32     INFO - GECKO(1596) |     #23 _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::h30bfb3fe208fc132 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1636:9 (libxul.so+0x87abd76)
[task 2021-11-24T21:37:32.794Z] 21:37:32     INFO - GECKO(1596) |     #24 std::sys::unix::thread::Thread::new::thread_start::hc9af21e46a79edc5 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/sys/unix/thread.rs:106:17 (libxul.so+0x87abd76)
[task 2021-11-24T21:37:32.794Z] 21:37:32     INFO - GECKO(1596) |   Previous write of size 4 at 0x7b4000160e00 by main thread:
[task 2021-11-24T21:37:32.795Z] 21:37:32     INFO - GECKO(1596) |     #0 ClearAndRetainStorage /builds/worker/workspace/obj-build/dist/include/nsTArray.h:1480:30 (libxul.so+0x22d1786)
[task 2021-11-24T21:37:32.795Z] 21:37:32     INFO - GECKO(1596) |     #1 AssignInternal<nsTArrayInfallibleAllocator, mozilla::layers::MatrixMessage> /builds/worker/workspace/obj-build/dist/include/nsTArray.h:2429:5 (libxul.so+0x22d1786)
[task 2021-11-24T21:37:32.796Z] 21:37:32     INFO - GECKO(1596) |     #2 Assign<nsTArrayInfallibleAllocator, nsTArrayInfallibleAllocator> /builds/worker/workspace/obj-build/dist/include/nsTArray.h:1454:12 (libxul.so+0x22d1786)
[task 2021-11-24T21:37:32.797Z] 21:37:32     INFO - GECKO(1596) |     #3 operator=<nsTArrayInfallibleAllocator> /builds/worker/workspace/obj-build/dist/include/nsTArray.h:2958:11 (libxul.so+0x22d1786)
[task 2021-11-24T21:37:32.797Z] 21:37:32     INFO - GECKO(1596) |     #4 mozilla::layers::APZCTreeManager::SendSubtreeTransformsToChromeMainThread(mozilla::layers::AsyncPanZoomController const*) /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZCTreeManager.cpp:3575:19 (libxul.so+0x22d1786)
[task 2021-11-24T21:37:32.798Z] 21:37:32     INFO - GECKO(1596) |     #5 applyImpl<mozilla::layers::APZCTreeManager, void (mozilla::layers::APZCTreeManager::*)(const mozilla::layers::AsyncPanZoomController *), StoreRefPtrPassByPtr<mozilla::layers::AsyncPanZoomController> , 0UL> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1147:12 (libxul.so+0x2332b19)
[task 2021-11-24T21:37:32.799Z] 21:37:32     INFO - GECKO(1596) |     #6 apply<mozilla::layers::APZCTreeManager, void (mozilla::layers::APZCTreeManager::*)(const mozilla::layers::AsyncPanZoomController *)> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1153:12 (libxul.so+0x2332b19)
[task 2021-11-24T21:37:32.800Z] 21:37:32     INFO - GECKO(1596) |     #7 mozilla::detail::RunnableMethodImpl<mozilla::layers::APZCTreeManager*, void (mozilla::layers::APZCTreeManager::*)(mozilla::layers::AsyncPanZoomController const*), true, (mozilla::RunnableKind)0, mozilla::layers::AsyncPanZoomController*>::Run() /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1200:13 (libxul.so+0x2332b19)
[task 2021-11-24T21:37:32.801Z] 21:37:32     INFO - GECKO(1596) |     #8 mozilla::RunnableTask::Run() /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:468:16 (libxul.so+0xf2ecf7)
[task 2021-11-24T21:37:32.801Z] 21:37:32     INFO - GECKO(1596) |     #9 mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:771:26 (libxul.so+0xf09f1d)
[task 2021-11-24T21:37:32.801Z] 21:37:32     INFO - GECKO(1596) |     #10 mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:607:15 (libxul.so+0xf085f6)
[task 2021-11-24T21:37:32.802Z] 21:37:32     INFO - GECKO(1596) |     #11 mozilla::TaskController::ProcessPendingMTTask(bool) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:391:36 (libxul.so+0xf088d2)
[task 2021-11-24T21:37:32.803Z] 21:37:32     INFO - GECKO(1596) |     #12 operator() /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:124:37 (libxul.so+0xf32a57)
[task 2021-11-24T21:37:32.804Z] 21:37:32     INFO - GECKO(1596) |     #13 mozilla::detail::RunnableFunction<mozilla::TaskController::InitializeInternal()::$_0>::Run() /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.h:531:5 (libxul.so+0xf32a57)
[task 2021-11-24T21:37:32.804Z] 21:37:32     INFO - GECKO(1596) |     #14 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1183:16 (libxul.so+0xf1c973)
[task 2021-11-24T21:37:32.805Z] 21:37:32     INFO - GECKO(1596) |     #15 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:467:10 (libxul.so+0xf236c2)
[task 2021-11-24T21:37:32.805Z] 21:37:32     INFO - GECKO(1596) |     #16 mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:85:21 (libxul.so+0x188d10d)
[task 2021-11-24T21:37:32.806Z] 21:37:32     INFO - GECKO(1596) |     #17 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:331:10 (libxul.so+0x180715c)
[task 2021-11-24T21:37:32.807Z] 21:37:32     INFO - GECKO(1596) |     #18 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:324:3 (libxul.so+0x180715c)
[task 2021-11-24T21:37:32.808Z] 21:37:32     INFO - GECKO(1596) |     #19 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:306:3 (libxul.so+0x180715c)
[task 2021-11-24T21:37:32.809Z] 21:37:32     INFO - GECKO(1596) |     #20 nsBaseAppShell::Run() /builds/worker/checkouts/gecko/widget/nsBaseAppShell.cpp:137:27 (libxul.so+0x4fabea6)
[task 2021-11-24T21:37:32.811Z] 21:37:32     INFO - GECKO(1596) |     #21 nsAppStartup::Run() /builds/worker/checkouts/gecko/toolkit/components/startup/nsAppStartup.cpp:295:30 (libxul.so+0x6e67b28)
[task 2021-11-24T21:37:32.812Z] 21:37:32     INFO - GECKO(1596) |     #22 XREMain::XRE_mainRun() /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5310:22 (libxul.so+0x6f8467f)
[task 2021-11-24T21:37:32.814Z] 21:37:32     INFO - GECKO(1596) |     #23 XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5495:8 (libxul.so+0x6f85506)
[task 2021-11-24T21:37:32.816Z] 21:37:32     INFO - GECKO(1596) |     #24 XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/nsAppRunner.cpp:5554:21 (libxul.so+0x6f85ad4)
[task 2021-11-24T21:37:32.817Z] 21:37:32     INFO - GECKO(1596) |     #25 mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:45:12 (libxul.so+0x6f90452)
[task 2021-11-24T21:37:32.819Z] 21:37:32     INFO - GECKO(1596) |     #26 do_main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:225:22 (firefox+0xcf494)
[task 2021-11-24T21:37:32.821Z] 21:37:32     INFO - GECKO(1596) |     #27 main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:395:16 (firefox+0xcf494)
[task 2021-11-24T21:37:32.823Z] 21:37:32     INFO - GECKO(1596) |   Location is heap block of size 256 at 0x7b4000160e00 allocated by thread T61:
[task 2021-11-24T21:37:32.824Z] 21:37:32     INFO - GECKO(1596) |     #0 realloc /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:688:5 (firefox+0x57e31)
[task 2021-11-24T21:37:32.826Z] 21:37:32     INFO - GECKO(1596) |     #1 moz_xrealloc /builds/worker/checkouts/gecko/memory/mozalloc/mozalloc.cpp:72:18 (firefox+0xd1481)
[task 2021-11-24T21:37:32.828Z] 21:37:32     INFO - GECKO(1596) |     #2 Realloc /builds/worker/workspace/obj-build/dist/include/nsTArray.h:259:12 (libxul.so+0xdd4cf4)
[task 2021-11-24T21:37:32.830Z] 21:37:32     INFO - GECKO(1596) |     #3 nsTArrayInfallibleAllocator::ResultTypeProxy nsTArray_base<nsTArrayInfallibleAllocator, nsTArray_RelocateUsingMemutils>::EnsureCapacity<nsTArrayInfallibleAllocator>(unsigned long, unsigned long) /builds/worker/workspace/obj-build/dist/include/nsTArray-inl.h:223:35 (libxul.so+0xdd4cf4)
[task 2021-11-24T21:37:32.831Z] 21:37:32     INFO - GECKO(1596) |     #4 AssignInternal<nsTArrayInfallibleAllocator, mozilla::layers::MatrixMessage> /builds/worker/workspace/obj-build/dist/include/nsTArray.h:2434:47 (libxul.so+0x22d17a0)
[task 2021-11-24T21:37:32.833Z] 21:37:32     INFO - GECKO(1596) |     #5 Assign<nsTArrayInfallibleAllocator, nsTArrayInfallibleAllocator> /builds/worker/workspace/obj-build/dist/include/nsTArray.h:1454:12 (libxul.so+0x22d17a0)
[task 2021-11-24T21:37:32.834Z] 21:37:32     INFO - GECKO(1596) |     #6 operator=<nsTArrayInfallibleAllocator> /builds/worker/workspace/obj-build/dist/include/nsTArray.h:2958:11 (libxul.so+0x22d17a0)
[task 2021-11-24T21:37:32.836Z] 21:37:32     INFO - GECKO(1596) |     #7 mozilla::layers::APZCTreeManager::SendSubtreeTransformsToChromeMainThread(mozilla::layers::AsyncPanZoomController const*) /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZCTreeManager.cpp:3575:19 (libxul.so+0x22d17a0)
[task 2021-11-24T21:37:32.837Z] 21:37:32     INFO - GECKO(1596) |     #8 mozilla::layers::APZCTreeManager::UpdateHitTestingTree(mozilla::layers::WebRenderScrollDataWrapper const&, bool, mozilla::layers::LayersId, unsigned int) /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZCTreeManager.cpp:697:3 (libxul.so+0x22cefed)
[task 2021-11-24T21:37:32.838Z] 21:37:32     INFO - GECKO(1596) |     #9 operator() /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:195:25 (libxul.so+0x232d764)
[task 2021-11-24T21:37:32.841Z] 21:37:32     INFO - GECKO(1596) |     #10 mozilla::detail::RunnableFunction<mozilla::layers::APZUpdater::UpdateScrollDataAndTreeState(mozilla::layers::LayersId, mozilla::layers::LayersId, mozilla::wr::Epoch const&, mozilla::layers::WebRenderScrollData&&)::$_28>::Run() /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:531:5 (libxul.so+0x232d764)
[task 2021-11-24T21:37:32.842Z] 21:37:32     INFO - GECKO(1596) |     #11 mozilla::layers::APZUpdater::ProcessQueue() /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:458:23 (libxul.so+0x22f6be5)
[task 2021-11-24T21:37:32.844Z] 21:37:32     INFO - GECKO(1596) |     #12 mozilla::layers::APZUpdater::CompleteSceneSwap(mozilla::wr::WrWindowId const&, mozilla::wr::WrPipelineInfo const&) /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:120:12 (libxul.so+0x22f647f)
[task 2021-11-24T21:37:32.845Z] 21:37:32     INFO - GECKO(1596) |     #13 apz_post_scene_swap /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:526:3 (libxul.so+0x22f8c66)
[task 2021-11-24T21:37:32.846Z] 21:37:32     INFO - GECKO(1596) |     #14 _$LT$webrender_bindings..bindings..APZCallbacks$u20$as$u20$webrender..renderer..SceneBuilderHooks$GT$::post_scene_swap::h2dba01f8254ac738 /builds/worker/checkouts/gecko/gfx/webrender_bindings/src/bindings.rs:1004:13 (libxul.so+0x900d8d4)
[task 2021-11-24T21:37:32.847Z] 21:37:32     INFO - GECKO(1596) |     #15 webrender::scene_builder_thread::SceneBuilderThread::forward_built_transactions::h4e6169ea287b82c5 /builds/worker/checkouts/gecko/gfx/wr/webrender/src/scene_builder_thread.rs:719:13 (libxul.so+0x8ed3926)
[task 2021-11-24T21:37:32.848Z] 21:37:32     INFO - GECKO(1596) |     #16 webrender::scene_builder_thread::SceneBuilderThread::run::heab014e9d3a1c4e6 /builds/worker/checkouts/gecko/gfx/wr/webrender/src/scene_builder_thread.rs:319:21 (libxul.so+0x8ed3926)
[task 2021-11-24T21:37:32.850Z] 21:37:32     INFO - GECKO(1596) |     #17 webrender::renderer::Renderer::new::_$u7b$$u7b$closure$u7d$$u7d$::h5d91946008a96b04 /builds/worker/checkouts/gecko/gfx/wr/webrender/src/renderer/mod.rs:1237:13 (libxul.so+0x8ed04f4)
[task 2021-11-24T21:37:32.851Z] 21:37:32     INFO - GECKO(1596) |     #18 std::sys_common::backtrace::__rust_begin_short_backtrace::h39b4177310499764 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/sys_common/backtrace.rs:125:18 (libxul.so+0x8ed04f4)
[task 2021-11-24T21:37:32.852Z] 21:37:32     INFO - GECKO(1596) |     #19 std::thread::Builder::spawn_unchecked::_$u7b$$u7b$closure$u7d$$u7d$::_$u7b$$u7b$closure$u7d$$u7d$::hc4fab657ab4fd541 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:481:17 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.853Z] 21:37:32     INFO - GECKO(1596) |     #20 _$LT$core..panic..unwind_safe..AssertUnwindSafe$LT$F$GT$$u20$as$u20$core..ops..function..FnOnce$LT$$LP$$RP$$GT$$GT$::call_once::hc9217e9ed816d082 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/panic/unwind_safe.rs:271:9 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.854Z] 21:37:32     INFO - GECKO(1596) |     #21 std::panicking::try::do_call::h144371768aa90588 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panicking.rs:403:40 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.855Z] 21:37:32     INFO - GECKO(1596) |     #22 std::panicking::try::h2508b37eaa8bc479 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panicking.rs:367:19 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.856Z] 21:37:32     INFO - GECKO(1596) |     #23 std::panic::catch_unwind::h2802c598e16f1b46 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/panic.rs:129:14 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.857Z] 21:37:32     INFO - GECKO(1596) |     #24 std::thread::Builder::spawn_unchecked::_$u7b$$u7b$closure$u7d$$u7d$::h1507728db3c37195 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:480:30 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.858Z] 21:37:32     INFO - GECKO(1596) |     #25 core::ops::function::FnOnce::call_once$u7b$$u7b$vtable.shim$u7d$$u7d$::h950df5f6dd83dae9 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/core/src/ops/function.rs:227:5 (libxul.so+0x8ed01ef)
[task 2021-11-24T21:37:32.859Z] 21:37:32     INFO - GECKO(1596) |     #26 _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::ha3209f0862c00df4 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1636:9 (libxul.so+0x87abd76)
[task 2021-11-24T21:37:32.860Z] 21:37:32     INFO - GECKO(1596) |     #27 _$LT$alloc..boxed..Box$LT$F$C$A$GT$$u20$as$u20$core..ops..function..FnOnce$LT$Args$GT$$GT$::call_once::h30bfb3fe208fc132 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/alloc/src/boxed.rs:1636:9 (libxul.so+0x87abd76)
[task 2021-11-24T21:37:32.861Z] 21:37:32     INFO - GECKO(1596) |     #28 std::sys::unix::thread::Thread::new::thread_start::hc9af21e46a79edc5 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/sys/unix/thread.rs:106:17 (libxul.so+0x87abd76)
[task 2021-11-24T21:37:32.862Z] 21:37:32     INFO - GECKO(1596) |   Mutex M54178882137212024 is already destroyed.
[task 2021-11-24T21:37:32.863Z] 21:37:32     INFO - GECKO(1596) |   Thread T61 'WRScene~ilder#1' (tid=1692, running) created by thread T26 at:
[task 2021-11-24T21:37:32.864Z] 21:37:32     INFO - GECKO(1596) |     #0 pthread_create /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:977:3 (firefox+0x5919d)
[task 2021-11-24T21:37:32.866Z] 21:37:32     INFO - GECKO(1596) |     #1 std::sys::unix::thread::Thread::new::h1ce904c847eb7c79 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/sys/unix/thread.rs:85:19 (libxul.so+0x87abadb)
[task 2021-11-24T21:37:32.867Z] 21:37:32     INFO - GECKO(1596) |     #2 std::thread::Builder::spawn_unchecked::h60c06a0bb1e1d59f /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:505:22 (libxul.so+0x8d31a83)
[task 2021-11-24T21:37:32.868Z] 21:37:32     INFO - GECKO(1596) |     #3 std::thread::Builder::spawn::h85dfbfc248425164 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:388:18 (libxul.so+0x8d31a83)
[task 2021-11-24T21:37:32.869Z] 21:37:32     INFO - GECKO(1596) |     #4 webrender::renderer::Renderer::new::hd8e71ef379096b57 /builds/worker/checkouts/gecko/gfx/wr/webrender/src/renderer/mod.rs:1226:9 (libxul.so+0x8d31a83)
[task 2021-11-24T21:37:32.870Z] 21:37:32     INFO - GECKO(1596) |     #5 wr_window_new /builds/worker/checkouts/gecko/gfx/webrender_bindings/src/bindings.rs:1680:36 (libxul.so+0x9012af7)
[task 2021-11-24T21:37:32.871Z] 21:37:32     INFO - GECKO(1596) |     #6 mozilla::wr::NewRenderer::Run(mozilla::wr::RenderThread&, mozilla::wr::WrWindowId) /builds/worker/checkouts/gecko/gfx/webrender_bindings/WebRenderAPI.cpp:157:10 (libxul.so+0x25bfd67)
[task 2021-11-24T21:37:32.872Z] 21:37:32     INFO - GECKO(1596) |     #7 mozilla::wr::RenderThread::RunEvent(mozilla::wr::WrWindowId, mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> >) /builds/worker/checkouts/gecko/gfx/webrender_bindings/RenderThread.cpp:438:11 (libxul.so+0x25a6cca)
[task 2021-11-24T21:37:32.873Z] 21:37:32     INFO - GECKO(1596) |     #8 applyImpl<mozilla::wr::RenderThread, void (mozilla::wr::RenderThread::*)(mozilla::wr::WrWindowId, mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> >), StoreCopyPassByConstLRef<mozilla::wr::WrWindowId>, StoreCopyPassByRRef<mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> > > , 0UL, 1UL> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1147:12 (libxul.so+0x25b20c3)
[task 2021-11-24T21:37:32.874Z] 21:37:32     INFO - GECKO(1596) |     #9 apply<mozilla::wr::RenderThread, void (mozilla::wr::RenderThread::*)(mozilla::wr::WrWindowId, mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> >)> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1153:12 (libxul.so+0x25b20c3)
[task 2021-11-24T21:37:32.875Z] 21:37:32     INFO - GECKO(1596) |     #10 mozilla::detail::RunnableMethodImpl<mozilla::wr::RenderThread*, void (mozilla::wr::RenderThread::*)(mozilla::wr::WrWindowId, mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> >), true, (mozilla::RunnableKind)0, mozilla::wr::WrWindowId, mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> >&&>::Run() /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1200:13 (libxul.so+0x25b20c3)
[task 2021-11-24T21:37:32.876Z] 21:37:32     INFO - GECKO(1596) |     #11 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1177:16 (libxul.so+0xf1cb93)
[task 2021-11-24T21:37:32.877Z] 21:37:32     INFO - GECKO(1596) |     #12 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:467:10 (libxul.so+0xf236c2)
[task 2021-11-24T21:37:32.878Z] 21:37:32     INFO - GECKO(1596) |     #13 mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:330:5 (libxul.so+0x188dd18)
[task 2021-11-24T21:37:32.880Z] 21:37:32     INFO - GECKO(1596) |     #14 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:331:10 (libxul.so+0x180715c)
[task 2021-11-24T21:37:32.881Z] 21:37:32     INFO - GECKO(1596) |     #15 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:324:3 (libxul.so+0x180715c)
[task 2021-11-24T21:37:32.881Z] 21:37:32     INFO - GECKO(1596) |     #16 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:306:3 (libxul.so+0x180715c)
[task 2021-11-24T21:37:32.882Z] 21:37:32     INFO - GECKO(1596) |     #17 nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:391:10 (libxul.so+0xf18c85)
[task 2021-11-24T21:37:32.883Z] 21:37:32     INFO - GECKO(1596) |     #18 _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5 (libnspr4.so+0x44fbd)
[task 2021-11-24T21:37:32.884Z] 21:37:32     INFO - GECKO(1596) | SUMMARY: ThreadSanitizer: data race /builds/worker/workspace/obj-build/dist/include/nsTArray.h:410:43 in Length
[task 2021-11-24T21:37:32.884Z] 21:37:32     INFO - GECKO(1596) | ==================
[task 2021-11-24T21:37:32.940Z] 21:37:32     INFO - GECKO(1596) | Exiting due to channel error.
[task 2021-11-24T21:37:32.940Z] 21:37:32     INFO - GECKO(1596) | Exiting due to channel error.
[task 2021-11-24T21:37:32.940Z] 21:37:32     INFO - GECKO(1596) | Exiting due to channel error.
[task 2021-11-24T21:37:32.941Z] 21:37:32     INFO - GECKO(1596) | Exiting due to channel error.
[task 2021-11-24T21:37:32.941Z] 21:37:32     INFO - GECKO(1596) | Exiting due to channel error.
[task 2021-11-24T21:37:32.943Z] 21:37:32     INFO - GECKO(1596) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=217.732) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=228.723) Exiting due to channel error.
[task 2021-11-24T21:37:33.994Z] 21:37:33     INFO - GECKO(1596) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=208.572)
[task 2021-11-24T21:37:33.995Z] 21:37:33     INFO - TEST-INFO | Main app process: killed by SIGIOT
[task 2021-11-24T21:37:33.995Z] 21:37:33     INFO - Buffered messages logged at 21:37:31
[task 2021-11-24T21:37:33.996Z] 21:37:33     INFO - Entering test bound test_blank
[task 2021-11-24T21:37:33.997Z] 21:37:33     INFO - Buffered messages logged at 21:37:32
[task 2021-11-24T21:37:33.998Z] 21:37:33     INFO - TEST-PASS | browser/base/content/test/general/browser_bug724239.js | about:blank wasn't added to session history -

Flags: needinfo?(mleclair)

Hiroyuki Ikezoe (:hiro)

Comment 9

•

3 years ago

Hey Marc, I am sorry, I missed that SendSubtreeTransformsToChromeMainThread gets called from different threads.

I chatted with Botond about this race, he suggested to add a scoped lock something like this;

  {                                                                             
    // Grab tree lock since we will mutate mLastMessages.                       
    RecursiveMutexAutoLock lock(mTreeLock);                                     
    if (messages != mLastMessages) {                                            
      mLastMessages = messages;                                                 
      controller->NotifyLayerTransforms(std::move(messages));                   
    }                                                                           
  }

This change should fix the thread sanitizer error.

Thanks!

Botond Ballo [:botond]

Comment 10

•

3 years ago

(In reply to Hiroyuki Ikezoe (:hiro) from comment #9)

I chatted with Botond about this race, he suggested to add a scoped lock something like this;

  {                                                                             
    // Grab tree lock since we will mutate mLastMessages.                       
    RecursiveMutexAutoLock lock(mTreeLock);                                     
    if (messages != mLastMessages) {                                            
      mLastMessages = messages;                                                 
      controller->NotifyLayerTransforms(std::move(messages));                   
    }                                                                           
  }

I don't think this quite works, as we shouldn't hold mTreeLock while calling NotifyLayerTransforms().

I think instead we need something like:

bool shouldNotify = false;
{
  RecursiveMutexAutoLock lock(mTreeLock);
  // [existing logic that loops over the tree and populates `messages`]
  if (messages != mLastMessages) {
    mLastMessages = messages;
    shouldNotify = true;
  }
}  // mTreeLock released here
if (shouldNotify) {
  controller->NotifyLayerTransforms(std::move(messages));
}

This way, the code that accesses mLastMessages is inside the lock, but the call to NotifyLayerTransforms() is not.

Botond Ballo [:botond]

Updated

•

3 years ago

See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1742893

Pulsebot

Comment 11

•

3 years ago

Pushed by mleclair@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/2321b29067e0 Check if messages were seen before notifying layer transforms r=hiro

Iulian Moraru

Comment 12

•

3 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/2321b29067e0

Status: ASSIGNED → RESOLVED

Closed: 3 years ago

status-firefox96: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → 96 Branch

Hiroyuki Ikezoe (:hiro)

Comment 13

•

3 years ago

\o/ Thank you Marc!

(I did realized the commit message was a bit messy but that's not a big deal. ;))

Flags: needinfo?(mleclair)

Ryan VanderMeulen [:RyanVM]

Updated

•

3 years ago

status-firefox94: --- → wontfix

status-firefox95: --- → wontfix

status-firefox-esr91: --- → wontfix

BMO Automation

Updated

•

3 years ago

Has Regression Range: --- → yes

Dave Hunt [:davehunt] [he/him] ⌚BST

Updated

•

3 years ago

Performance Impact: --- → P3

Keywords: perf:resource-use

Whiteboard: [qf:p3:resource]