1884266 - Intermittent SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/gfx/layers/apz/src/Axis.cpp:434:42 in GetVelocity | single tracking bug

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2024-03-07T22:20:56.153Z] 22:20:56     INFO - GECKO(4292) |   Thread T62 'WRScene~ilder#2' (tid=4404, running) created by thread T32 at:
[task 2024-03-07T22:20:56.153Z] 22:20:56     INFO - GECKO(4292) |     #0 pthread_create /builds/worker/fetches/llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:1020:3 (firefox-bin+0xc591b) (BuildId: d2b75d427690b9fb285212fcde2d3e0c673109e8)
[task 2024-03-07T22:20:56.153Z] 22:20:56     INFO - GECKO(4292) |     #1 std::sys::unix::thread::Thread::new::h4aaa3d1a13426c25 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/sys/unix/thread.rs:87:19 (libxul.so+0xba81d14) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.153Z] 22:20:56     INFO - GECKO(4292) |     #2 std::thread::Builder::spawn_unchecked_::h3a8fc7cf2ba335b9 /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:567:30 (libxul.so+0xc08e113) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.154Z] 22:20:56     INFO - GECKO(4292) |     #3 std::thread::Builder::spawn_unchecked::ha49b70fc53d89d8e /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:457:32 (libxul.so+0xc08e113)
[task 2024-03-07T22:20:56.154Z] 22:20:56     INFO - GECKO(4292) |     #4 std::thread::Builder::spawn::h2ff7186793e51f9a /builds/worker/fetches/rustc/lib/rustlib/src/rust/library/std/src/thread/mod.rs:389:18 (libxul.so+0xc08e113)
[task 2024-03-07T22:20:56.154Z] 22:20:56     INFO - GECKO(4292) |     #5 webrender::renderer::init::create_webrender_instance::h5cd8e7ec40fb6e4e /builds/worker/checkouts/gecko/gfx/wr/webrender/src/renderer/init.rs:586:60 (libxul.so+0xc08e113)
[task 2024-03-07T22:20:56.155Z] 22:20:56     INFO - GECKO(4292) |     #6 wr_window_new /builds/worker/checkouts/gecko/gfx/webrender_bindings/src/bindings.rs:1703:36 (libxul.so+0xc3f0620) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.155Z] 22:20:56     INFO - GECKO(4292) |     #7 mozilla::wr::NewRenderer::Run(mozilla::wr::RenderThread&, mozilla::wr::WrWindowId) /builds/worker/checkouts/gecko/gfx/webrender_bindings/WebRenderAPI.cpp:134:10 (libxul.so+0x47530d5) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.156Z] 22:20:56     INFO - GECKO(4292) |     #8 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:715:11 (libxul.so+0x47328fd) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.157Z] 22:20:56     INFO - GECKO(4292) |     #9 operator()<StoreCopyPassByConstLRef<mozilla::wr::WrWindowId> &, StoreCopyPassByRRef<mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> > > &> /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1085:18 (libxul.so+0x473fd0d) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.158Z] 22:20:56     INFO - GECKO(4292) |     #10 __invoke_impl<void, (lambda at /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1084:9), StoreCopyPassByConstLRef<mozilla::wr::WrWindowId> &, StoreCopyPassByRRef<mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> > > &> /builds/worker/fetches/sysroot-x86_64-linux-gnu/usr/lib/gcc/x86_64-linux-gnu/8/../../../../include/c++/8/bits/invoke.h:60:14 (libxul.so+0x473fd0d)
[task 2024-03-07T22:20:56.159Z] 22:20:56     INFO - GECKO(4292) |     #11 __invoke<(lambda at /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1084:9), StoreCopyPassByConstLRef<mozilla::wr::WrWindowId> &, StoreCopyPassByRRef<mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> > > &> /builds/worker/fetches/sysroot-x86_64-linux-gnu/usr/lib/gcc/x86_64-linux-gnu/8/../../../../include/c++/8/bits/invoke.h:95:14 (libxul.so+0x473fd0d)
[task 2024-03-07T22:20:56.159Z] 22:20:56     INFO - GECKO(4292) |     #12 __apply_impl<(lambda at /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1084:9), std::tuple<StoreCopyPassByConstLRef<mozilla::wr::WrWindowId>, StoreCopyPassByRRef<mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> > > > &, 0UL, 1UL> /builds/worker/fetches/sysroot-x86_64-linux-gnu/usr/lib/gcc/x86_64-linux-gnu/8/../../../../include/c++/8/tuple:1678:14 (libxul.so+0x473fd0d)
[task 2024-03-07T22:20:56.160Z] 22:20:56     INFO - GECKO(4292) |     #13 apply<(lambda at /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:1084:9), std::tuple<StoreCopyPassByConstLRef<mozilla::wr::WrWindowId>, StoreCopyPassByRRef<mozilla::UniquePtr<mozilla::wr::RendererEvent, mozilla::DefaultDelete<mozilla::wr::RendererEvent> > > > &> /builds/worker/fetches/sysroot-x86_64-linux-gnu/usr/lib/gcc/x86_64-linux-gnu/8/../../../../include/c++/8/tuple:1687:14 (libxul.so+0x473fd0d)
[task 2024-03-07T22:20:56.161Z] 22:20:56     INFO - GECKO(4292) |     #14 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:1083:12 (libxul.so+0x473fd0d)
[task 2024-03-07T22:20:56.162Z] 22:20:56     INFO - GECKO(4292) |     #15 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:1134:13 (libxul.so+0x473fd0d)
[task 2024-03-07T22:20:56.163Z] 22:20:56     INFO - GECKO(4292) |     #16 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1193:16 (libxul.so+0x31f627e) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.163Z] 22:20:56     INFO - GECKO(4292) |     #17 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:480:10 (libxul.so+0x31fc814) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.164Z] 22:20:56     INFO - GECKO(4292) |     #18 mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:330:5 (libxul.so+0x3d310b9) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.164Z] 22:20:56     INFO - GECKO(4292) |     #19 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:370:10 (libxul.so+0x3ca56d8) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.165Z] 22:20:56     INFO - GECKO(4292) |     #20 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:363:3 (libxul.so+0x3ca56d8)
[task 2024-03-07T22:20:56.165Z] 22:20:56     INFO - GECKO(4292) |     #21 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:345:3 (libxul.so+0x3ca56d8)
[task 2024-03-07T22:20:56.166Z] 22:20:56     INFO - GECKO(4292) |     #22 nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:370:10 (libxul.so+0x31f1b03) (BuildId: 4067c22d2c2cf95abafea0ee3d15fbe6a7a3c06f)
[task 2024-03-07T22:20:56.166Z] 22:20:56     INFO - GECKO(4292) |     #23 _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5 (libnspr4.so+0x4ba79) (BuildId: c8e4840a4898d6a419fcf3fa72ee8662925d12d9)
[task 2024-03-07T22:20:56.167Z] 22:20:56     INFO - GECKO(4292) | SUMMARY: ThreadSanitizer: data race /builds/worker/checkouts/gecko/gfx/layers/apz/src/Axis.cpp:434:42 in GetVelocity
[task 2024-03-07T22:20:56.167Z] 22:20:56     INFO - GECKO(4292) | ==================
[task 2024-03-07T22:20:56.168Z] 22:20:56     INFO - GECKO(4292) | Exiting due to channel error.
[task 2024-03-07T22:20:56.168Z] 22:20:56     INFO - GECKO(4292) | Exiting due to channel error.
[task 2024-03-07T22:20:56.169Z] 22:20:56     INFO - GECKO(4292) | Exiting due to channel error.
[task 2024-03-07T22:20:56.169Z] 22:20:56     INFO - GECKO(4292) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: CompositorBridgeChild receives IPC close with reason=AbnormalShutdown (t=73.0768) Exiting due to channel error.
[task 2024-03-07T22:20:56.170Z] 22:20:56     INFO - GECKO(4292) | Exiting due to channel error.
[task 2024-03-07T22:20:56.170Z] 22:20:56     INFO - GECKO(4292) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: CompositorBridgeChild receives IPC close with reason=AbnormalShutdown (t=84.3809) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: CompositorBridgeChild receives IPC close with reason=AbnormalShutdown (t=75.0443) Exiting due to channel error.
[task 2024-03-07T22:20:57.113Z] 22:20:57     INFO - GECKO(4292) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: CompositorBridgeChild receives IPC close with reason=AbnormalShutdown (t=3.16946)
[task 2024-03-07T22:20:57.114Z] 22:20:57     INFO - TEST-INFO | Main app process: killed by SIGIOT
[task 2024-03-07T22:20:57.114Z] 22:20:57     INFO - Buffered messages logged at 22:19:59
[task 2024-03-07T22:20:57.115Z] 22:20:57     INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_group_checkerboarding.html | Starting subtest helper_checkerboard_apzforcedisabled.html 
[task 2024-03-07T22:20:57.115Z] 22:20:57     INFO - Buffered messages logged at 22:20:00
[task 2024-03-07T22:20:57.116Z] 22:20:57     INFO - TEST-PASS | gfx/layers/apz/test/mochitest/test_group_checkerboarding.html | helper_checkerboard_apzforcedisabled.html | expected at least one nonempty paint 

Comment 1

[Andrew McCreight [:mccr8]]

This looks like a race on Axis::mAxisLocked

Comment 2

[Tyson Smith [:tsmith]]

Attachment: tsan.txt

Full TSan log

Comment 3

[Dan Robertson (:dlrobertson)]

Marking S2/P2 for now and I've started looking into it a bit.

Comment 4

[Dan Robertson (:dlrobertson)]

Attachment: Bug 1884266 - Use a mutex to guard reading and writing to the axis lock. r=botond,hiro

Before setting or reading from the variable indicating a scrolling axis
is locked, acquire a lock.

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/6addfc580ede
Use a mutex to guard reading and writing to the axis lock. r=botond

Comment 6

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/6addfc580ede

Comment 7

[Ryan VanderMeulen [:RyanVM]]

Please nominate this for ESR115 uplift when you get a chance.

Comment 8

[Dan Robertson (:dlrobertson)]

Attachment: Bug 1884266 - Use a mutex to guard reading and writing to the axis lock.

Before setting or reading from the variable indicating a scrolling axis
is locked, acquire a lock.

Original Revision: https://phabricator.services.mozilla.com/D210965

Comment 9

[Phabricator Automation]

esr115 Uplift Approval Request

• User impact if declined: Potential data race
• Code covered by automated testing: yes
• Fix verified in Nightly: no
• Needs manual QE test: no
• Steps to reproduce for manual QE testing: Intermittent try failure
• Risk associated with taking this patch: Low
• Explanation of risk level: Adds a mutex to the axis lock state.
• String changes made/needed: No
• Is Android affected?: no

Comment 10

[Pulsebot]

https://hg.mozilla.org/releases/mozilla-esr115/rev/28cfe580588e