1770162 - [CTW] Assertion in nsITimer::SetDelay when MSAA ids released during XPCOM shutdown

Status: RESOLVED FIXED

(Core :: Disability Access APIs, defect)

Description

[James Teh [:Jamie]]

I'm seeing this whenever I run certain mochitests with a debug build on Windows:

 0:17.43 GECKO(25016) [Parent 10364, Main Thread] ###!!! ASSERTION: nsITimer->SetDelay() called when the one-shot timer is not set up.: 'Error', file C:/Users/jamie/src/gecko/xpcom/threads/nsTimerImpl.cpp:511
 0:18.20 GECKO(25016) #01: NS_DebugBreak (C:\Users\jamie\src\gecko\xpcom\base\nsDebugImpl.cpp:496)
 0:18.20 GECKO(25016) #02: nsTimerImpl::SetDelay (C:\Users\jamie\src\gecko\xpcom\threads\nsTimerImpl.cpp:509)
 0:18.20 GECKO(25016) #03: mozilla::a11y::MsaaIdGenerator::ReleaseID (C:\Users\jamie\src\gecko\accessible\windows\msaa\MsaaIdGenerator.cpp:115)
 0:18.20 GECKO(25016) #04: mozilla::a11y::MsaaAccessible::~MsaaAccessible (C:\Users\jamie\src\gecko\accessible\windows\msaa\MsaaAccessible.cpp:94)
Initializing stack-fixing for the first stack frame, this may take a while...
 0:33.94 GECKO(25016) #05: mozilla::a11y::ia2AccessibleHypertext::`vector deleting destructor' [C:\Users\jamie\src\gecko\obj\dist\bin\xul.dll + 0x63e6661]
 0:33.94 GECKO(25016) #06: mozilla::a11y::ia2AccessibleHypertext::Release [C:\Users\jamie\src\gecko\obj\dist\bin\xul.dll + 0x63e660d]
 0:33.94 GECKO(25016) #07: mozilla::a11y::HyperTextAccessibleWrap::~HyperTextAccessibleWrap (C:\Users\jamie\src\gecko\accessible\windows\msaa\HyperTextAccessibleWrap.h:28)
 0:33.94 GECKO(25016) #08: SnowWhiteKiller::MaybeKillObject (C:\Users\jamie\src\gecko\xpcom\base\nsCycleCollector.cpp:2421)
 0:33.94 GECKO(25016) #09: SnowWhiteKiller::~SnowWhiteKiller (C:\Users\jamie\src\gecko\xpcom\base\nsCycleCollector.cpp:2406)
 0:33.94 GECKO(25016) #10: nsCycleCollector::FreeSnowWhite (C:\Users\jamie\src\gecko\xpcom\base\nsCycleCollector.cpp:2593)
 0:33.94 GECKO(25016) #11: nsCycleCollector::Shutdown (C:\Users\jamie\src\gecko\xpcom\base\nsCycleCollector.cpp:3645)
 0:33.94 GECKO(25016) #12: nsCycleCollector_shutdown (C:\Users\jamie\src\gecko\xpcom\base\nsCycleCollector.cpp:3963)
 0:33.94 GECKO(25016) #13: mozilla::ShutdownXPCOM (C:\Users\jamie\src\gecko\xpcom\build\XPCOMInit.cpp:716)
 0:33.94 GECKO(25016) #14: ScopedXPCOMStartup::~ScopedXPCOMStartup (C:\Users\jamie\src\gecko\toolkit\xre\nsAppRunner.cpp:2050)
 0:33.94 GECKO(25016) #15: XREMain::XRE_main (C:\Users\jamie\src\gecko\toolkit\xre\nsAppRunner.cpp:5954)
 0:33.94 GECKO(25016) #16: XRE_main (C:\Users\jamie\src\gecko\toolkit\xre\nsAppRunner.cpp:5992)
 0:33.94 GECKO(25016) #17: NS_internal_main (C:\Users\jamie\src\gecko\browser\app\nsBrowserApp.cpp:397)
 0:33.94 GECKO(25016) #18: wmain (C:\Users\jamie\src\gecko\toolkit\xre\nsWindowsWMain.cpp:167)
 0:33.94 GECKO(25016) #19: __scrt_common_main_seh (d:\agent\_work\4\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl:288)
 0:33.94 GECKO(25016) #20: BaseThreadInitThunk [C:\Windows\System32\KERNEL32.DLL + 0x17034]
 0:33.95 GECKO(25016) #21: RtlUserThreadStart [C:\Windows\SYSTEM32\ntdll.dll + 0x52651]

This happens because a LocalAccessible is deleted during XPCOM shutdown. MsaaIdGenerator::ReleaseID uses a timer, but timers don't work once XPCOM starts to shut down, hence the assertion.

The first thing I questioned is why we're deleting LocalAccessibles during XPCOM shutdown. They should be cleaned up by nsAccessibilityService shutdown, which happens before the final cycle collection. I spent quite a while looking for a leak, but in the end, I discovered this seemed to be happening even with LocalAccessibles that have a ref count of 1 (as low as it gets before deletion) when they are shut down. I guess the cycle collector never (sometimes?) doesn't delete objects immediately on their last release. I had this confirmed by :mccr8 on Matrix:

The cycle collector keeps raw pointers to cycle collected objects (sometimes), so we can't immediately delete them. Instead, we periodically run this "FreeSnowWhite()" code from the cycle collector to actually run the destructors. It happens pretty frequently, but if the last release is immediately during shutdown I can see that it might not happen until we actually start a CC.

So, the fix here is to not use the timer if the acc service is shut down.

Comment 1

[James Teh [:Jamie]]

Attachment: Bug 1770162: Fix MsaaIdGenerator timer assertion during shutdown.

There can be LocalAccessibles which don't die until the final cycle collection during XPCOM shutdown.
MsaaIdGenerator::ReleaseID (called during deletion of a LocalAccessible) uses a timer when the cache is enabled, but timers can't be used after XPCOM shutdown.
This was causing an assertion.
In addition, because MsaaIdGenerator is a static instance, the timer could be deleted after XPCOM shutdown, causing a warning.
To fix this:

1. If accessibility is shut down, just release ids immediately.
2. Clean up any remaining ids and the timer on XPCOM shutdown.

A better solution would be to create and terminate MsaaIdGenerator during a11y startup and shutdown, but this is a bit tricky while we still have the non-cache code paths.
Once we don't need the non-cache code, MsaaIdGenerator will become a lot simpler, so this refactor will be easier then.

Comment 2

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/4c1c287f15e1
Fix MsaaIdGenerator timer assertion during shutdown. r=morgan

Comment 3

[bszekely]

https://hg.mozilla.org/mozilla-central/rev/4c1c287f15e1