Closed Bug 1723233 Opened 3 years ago Closed 2 years ago

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

Categories

(Core :: Panning and Zooming, defect, P2)

Product:
Core
Component:
Panning and Zooming
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
96 Branch
Project Flags:
Performance Impact low
Tracking Flags:
Tracking Status
firefox-esr91 --- wontfix
firefox94 --- wontfix
firefox95 --- wontfix
firefox96 --- fixed

People

(Reporter: mstange, Assigned: mleclair)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: perf:resource-use, power, regression)

Attachments

(1 file)

Bug 1723233 - Check if messages were seen before notifying layer transforms r=hiro
48 bytes, text/x-phabricator-request
Details | Review

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?

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.

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.

Severity: -- → S3
Priority: -- → P2

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

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!

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

See Also: → 1707198
Whiteboard: [qf] → [qf:p3:resource]
Assignee: nobody → mleclair
Status: NEW → ASSIGNED
Pushed by mleclair@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/8ba9fccd412c
Check if messages were seen before notifying layer transforms r=hiro

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)

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!

(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.

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

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

Status: ASSIGNED → RESOLVED
Closed: 2 years ago
status-firefox96: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 96 Branch

\o/ Thank you Marc!

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

Flags: needinfo?(mleclair)
Has Regression Range: --- → yes
Performance Impact: --- → P3
Keywords: perf:resource-use
Whiteboard: [qf:p3:resource]
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: