1539185 - Intermittent SUMMARY: AddressSanitizer: heap-use-after-free z:\build\build\src\gfx\vr\VRManager.cpp:611 in mozilla::gfx::VRManager::GetDisplay(unsigned int const &)

Status: RESOLVED FIXED

(Core :: WebVR, defect, P5)

Description

[Treeherder Bug Filer]

#[markdown(off)]
Filed by: rgurzau [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=236108919&repo=mozilla-central

https://queue.taskcluster.net/v1/task/OJw0de-7TYejmHsEWh6Sag/runs/0/artifacts/public/logs/live_backing.log

https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://queue.taskcluster.net/v1/task/OJw0de-7TYejmHsEWh6Sag/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

13:25:30 INFO - mon/ipc_channel_win.cc, line 341
13:25:30 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [Child 6048, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [Child 6048, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - JavaScript error: resource://reftest/reftest.jsm, line 1558: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString]
13:25:30 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
13:25:30 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:30 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - 1553606731091 Marionette TRACE Received observer notification xpcom-will-shutdown
13:25:31 INFO - 1553606731092 Marionette INFO Stopped listening on port 2828
13:25:31 INFO - 1553606731092 Marionette DEBUG Remote service is inactive
13:25:31 INFO - [VR 7416, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - =================================================================
13:25:31 INFO - ###!!! [Child][MessageChannel] Error: (msgtype=0x9A0002,name=PVRGPU::Msg_StopVRService) Closed channel: cannot send/recv
13:25:31 ERROR - ==7040==ERROR: AddressSanitizer: heap-use-after-free on address 0x126aaf0226b8 at pc 0x7ffdb96513f5 bp 0x00b52bbfe5e0 sp 0x00b52bbfe628
13:25:31 INFO - READ of size 4 at 0x126aaf0226b8 thread T2
13:25:31 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/b
13:25:31 INFO - ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
13:25:31 INFO - uild/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - #0 0x7ffdb96513f4 in mozilla::gfx::VRManager::GetDisplay(unsigned int const &) z:\build\build\src\gfx\vr\VRManager.cpp:611
13:25:31 INFO - #1 0x7ffdb9650323 in mozilla::gfx::VRManager::Run10msTasks(void) z:\build\build\src\gfx\vr\VRManager.cpp:341
13:25:31 INFO - #2 0x7ffdb964f361 in mozilla::gfx::VRManager::RunTasks(void) z:\build\build\src\gfx\vr\VRManager.cpp:274

Comment 1

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

13:25:31 ERROR - ==7040==ERROR: AddressSanitizer: heap-use-after-free on address 0x126aaf0226b8 at pc 0x7ffdb96513f5 bp 0x00b52bbfe5e0 sp 0x00b52bbfe628
13:25:31 INFO - READ of size 4 at 0x126aaf0226b8 thread T2
13:25:31 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/b
13:25:31 INFO - ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
13:25:31 INFO - uild/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - [GPU 7040, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - [Parent 9016, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 341
13:25:31 INFO - #0 0x7ffdb96513f4 in mozilla::gfx::VRManager::GetDisplay(unsigned int const &) z:\build\build\src\gfx\vr\VRManager.cpp:611
13:25:31 INFO - #1 0x7ffdb9650323 in mozilla::gfx::VRManager::Run10msTasks(void) z:\build\build\src\gfx\vr\VRManager.cpp:341
13:25:31 INFO - #2 0x7ffdb964f361 in mozilla::gfx::VRManager::RunTasks(void) z:\build\build\src\gfx\vr\VRManager.cpp:274
13:25:31 INFO - #3 0x7ffdb6131ec4 in nsTimerImpl::Fire(int) z:\build\build\src\xpcom\threads\nsTimerImpl.cpp:559
13:25:31 INFO - #4 0x7ffdb6131455 in nsTimerEvent::Run(void) z:\build\build\src\xpcom\threads\TimerThread.cpp:260
13:25:31 INFO - #5 0x7ffdb7186a53 in ?DeferOrRunPendingTask@MessageLoop@@IEAA_N$$QEAUPendingTask@1@@Z z:\build\build\src\ipc\chromium\src\base\message_loop.cc:450
13:25:31 INFO - #6 0x7ffdb718844e in MessageLoop::DoWork(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:523
13:25:31 INFO - #7 0x7ffdb7158a21 in base::MessagePumpForUI::DoRunLoop(void) z:\build\build\src\ipc\chromium\src\base\message_pump_win.cc:203
13:25:31 INFO - #8 0x7ffdb715b049 in base::MessagePumpWin::Run(class base::MessagePump::Delegate *) z:\build\build\src\ipc\chromium\src\base\message_pump_win.h:79
13:25:31 INFO - #9 0x7ffdb71857ce in MessageLoop::RunHandler(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:308
13:25:31 INFO - #10 0x7ffdb71976f2 in base::Thread::ThreadMain(void) z:\build\build\src\ipc\chromium\src\base\thread.cc:192
13:25:31 INFO - #11 0x7ffdb715c85f in anonymous namespace'::ThreadFunc z:\build\build\src\ipc\chromium\src\base\platform_thread_win.cc:19 13:25:31 INFO - #12 0x7ffdfc07e888 in __asan::AsanThread::ThreadStart(unsigned __int64,struct __sanitizer::atomic_uintptr_t *) Z:\task_1553346333\build\src\build\build-clang\build-clang\src\llvm\projects\compiler-rt\lib\asan\asan_thread.cc:264 13:25:31 INFO - #13 0x7ffe0dad3033 (C:\Windows\System32\KERNEL32.DLL+0x180013033) 13:25:31 INFO - #14 0x7ffe08d0df21 in patched_BaseThreadInitThunk z:\build\build\src\mozglue\build\WindowsDllBlocklist.cpp:712 13:25:31 INFO - #15 0x7ffe0fe31460 (C:\Windows\SYSTEM32\ntdll.dll+0x180071460) 13:25:31 INFO - 0x126aaf0226b8 is located 8 bytes inside of 12-byte region [0x126aaf0226b0,0x126aaf0226bc) 13:25:31 INFO - freed by thread T0 here: 13:25:31 INFO - #0 0x7ffdfc0744e0 in free Z:\task_1553346333\build\src\build\build-clang\build-clang\src\llvm\projects\compiler-rt\lib\asan\asan_malloc_win.cc:53 13:25:31 INFO - #1 0x7ffdb5e6924b in nsTArray_base<struct nsTArrayFallibleAllocator,struct nsTArray_CopyWithMemutils>::ShrinkCapacity(unsigned __int64,unsigned __int64) z:\build\build\src\obj-firefox\dist\include\nsTArray-inl.h:236 13:25:31 INFO - #2 0x7ffdb964e4a2 in mozilla::gfx::VRManager::Shutdown(void) z:\build\build\src\gfx\vr\VRManager.cpp:136 13:25:31 INFO - #3 0x7ffdb965fabb in mozilla::gfx::VRGPUChild::ActorDestroy(enum mozilla::ipc::IProtocol::ActorDestroyReason) z:\build\build\src\gfx\vr\ipc\VRGPUChild.cpp:56 13:25:31 INFO - #4 0x7ffdb7577bcf in mozilla::plugins::PFunctionBrokerChild::OnChannelClose(void) z:\build\build\src\obj-firefox\ipc\ipdl\PFunctionBrokerChild.cpp:165 13:25:31 INFO - #5 0x7ffdb723329d in mozilla::ipc::MessageChannel::OnNotifyMaybeChannelError(void) z:\build\build\src\ipc\glue\MessageChannel.cpp:2594 13:25:31 INFO - #6 0x7ffdb724d563 in ?Run@?$RunnableMethodImpl@PEAVCompositorBridgeParent@layers@mozilla@@P8123@EAAXXZ$00$00$$V@detail@mozilla@@UEAA?AW4nsresult@@XZ z:\build\build\src\xpcom\threads\nsThreadUtils.h:1174 13:25:31 INFO - #7 0x7ffdb61484d0 in nsThread::ProcessNextEvent(bool,bool *) z:\build\build\src\xpcom\threads\nsThread.cpp:1180 13:25:31 INFO - #8 0x7ffdb6150368 in NS_ProcessNextEvent(class nsIThread *,bool) z:\build\build\src\xpcom\threads\nsThreadUtils.cpp:482 13:25:31 INFO - #9 0x7ffdb7237cdc in mozilla::ipc::MessagePump::Run(class base::MessagePump::Delegate *) z:\build\build\src\ipc\glue\MessagePump.cpp:110 13:25:31 INFO - #10 0x7ffdb71857ce in MessageLoop::RunHandler(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:308 13:25:31 INFO - #11 0x7ffdb7185565 in MessageLoop::Run(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:290 13:25:31 INFO - #12 0x7ffdc03cd0fa in nsBaseAppShell::Run(void) z:\build\build\src\widget\nsBaseAppShell.cpp:137 13:25:31 INFO - #13 0x7ffdc055dbc8 in nsAppShell::Run(void) z:\build\build\src\widget\windows\nsAppShell.cpp:411 13:25:31 INFO - #14 0x7ffdc4677e1d in XRE_RunAppShell(void) z:\build\build\src\toolkit\xre\nsEmbedFunctions.cpp:933 13:25:31 INFO - #15 0x7ffdb71857ce in MessageLoop::RunHandler(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:308 13:25:31 INFO - #16 0x7ffdb7185565 in MessageLoop::Run(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:290 13:25:31 INFO - #17 0x7ffdc467710e in XRE_InitChildProcess(int,char * * const,struct XREChildData const *) z:\build\build\src\toolkit\xre\nsEmbedFunctions.cpp:771 13:25:31 INFO - #18 0x7ff6b0bf21a8 (Z:\task_1553601215\build\application\firefox\firefox.exe+0x1400021a8) 13:25:31 INFO - #19 0x7ff6b0bf14f2 (Z:\task_1553601215\build\application\firefox\firefox.exe+0x1400014f2) 13:25:31 INFO - #20 0x7ff6b0cd79c7 (Z:\task_1553601215\build\application\firefox\firefox.exe+0x1400e79c7) 13:25:31 INFO - #21 0x7ffe0dad3033 (C:\Windows\System32\KERNEL32.DLL+0x180013033) 13:25:31 INFO - #22 0x7ffe0fe31460 (C:\Windows\SYSTEM32\ntdll.dll+0x180071460) 13:25:31 INFO - previously allocated by thread T2 here: 13:25:31 INFO - #0 0x7ffdfc0745d0 in malloc Z:\task_1553346333\build\src\build\build-clang\build-clang\src\llvm\projects\compiler-rt\lib\asan\asan_malloc_win.cc:69 13:25:31 INFO - #1 0x7ffe08d2e34d in moz_xmalloc z:\build\build\src\memory\mozalloc\mozalloc.cpp:68 13:25:31 INFO - #2 0x7ffdb5e6a109 in nsTArray_base<struct nsTArrayInfallibleAllocator,struct nsTArray_CopyWithMemutils>::EnsureCapacity<struct nsTArrayInfallibleAllocator>(unsigned __int64,unsigned __int64) z:\build\build\src\obj-firefox\dist\include\nsTArray-inl.h:144 13:25:31 INFO - #3 0x7ffdb96543dd in mozilla::gfx::VRManager::EnumerateVRDisplays(void) z:\build\build\src\gfx\vr\VRManager.cpp:498 13:25:31 INFO - #4 0x7ffdb9651581 in mozilla::gfx::VRManager::RefreshVRDisplays(bool) z:\build\build\src\gfx\vr\VRManager.cpp:520 13:25:31 INFO - #5 0x7ffdb96507a2 in mozilla::gfx::VRManager::Run100msTasks(void) z:\build\build\src\gfx\vr\VRManager.cpp:361 13:25:31 INFO - #6 0x7ffdb964f38b in mozilla::gfx::VRManager::RunTasks(void) z:\build\build\src\gfx\vr\VRManager.cpp:280 13:25:31 INFO - #7 0x7ffdb6131ec4 in nsTimerImpl::Fire(int) z:\build\build\src\xpcom\threads\nsTimerImpl.cpp:559 13:25:31 INFO - #8 0x7ffdb6131455 in nsTimerEvent::Run(void) z:\build\build\src\xpcom\threads\TimerThread.cpp:260 13:25:31 INFO - #9 0x7ffdb7186a53 in ?DeferOrRunPendingTask@MessageLoop@@IEAA_N$$QEAUPendingTask@1@@Z z:\build\build\src\ipc\chromium\src\base\message_loop.cc:450 13:25:31 INFO - #10 0x7ffdb718844e in MessageLoop::DoWork(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:523 13:25:31 INFO - #11 0x7ffdb7158a21 in base::MessagePumpForUI::DoRunLoop(void) z:\build\build\src\ipc\chromium\src\base\message_pump_win.cc:203 13:25:31 INFO - #12 0x7ffdb715b049 in base::MessagePumpWin::Run(class base::MessagePump::Delegate *) z:\build\build\src\ipc\chromium\src\base\message_pump_win.h:79 13:25:31 INFO - #13 0x7ffdb71857ce in MessageLoop::RunHandler(void) z:\build\build\src\ipc\chromium\src\base\message_loop.cc:308 13:25:31 INFO - #14 0x7ffdb71976f2 in base::Thread::ThreadMain(void) z:\build\build\src\ipc\chromium\src\base\thread.cc:192 13:25:31 INFO - #15 0x7ffdb715c85f inanonymous namespace'::ThreadFunc z:\build\build\src\ipc\chromium\src\base\platform_thread_win.cc:19

Comment 2

[Andrew McCreight [:mccr8]]

Looks like a shutdown race, so I'll just mark this as sec-moderate.

Comment 3

[Daosheng Mu[:daoshengmu]]

It is because we call VRManager::Shutdown() from the main thread but VR tasks are still running at the compositor thread. I
think if we post VRManager::Shutdown() to the compositor thread that will resolve this issue.

 CompositorThreadHolder::Loop()->PostTask(NewRunnableMethod(
    "VRGPUChild::ActorDestroy",
    vm, &VRManager::Shutdown));

Comment 4

[:kip (Kearwood Gilbert)]

(In reply to Daosheng Mu[:daoshengmu] from comment #3)

It is because we call VRManager::Shutdown() from the main thread but VR tasks are still running at the compositor thread. I
think if we post VRManager::Shutdown() to the compositor thread that will resolve this issue.

 CompositorThreadHolder::Loop()->PostTask(NewRunnableMethod(
    "VRGPUChild::ActorDestroy",
    vm, &VRManager::Shutdown));

I will soon be on PTO and am stretched a bit too thin to get this addressed in time.

Would you have some cycles to continue this investigation, @daosheng?

Comment 5

[Daosheng Mu[:daoshengmu]]

let me leave the ni? here, and I will check this next week.

Comment 6

[Daosheng Mu[:daoshengmu]]

It looks like we have landed our fix in Bug 1540590, can we close it and mark it as resolved? I guess we already solved, just need someone to confirm.