1311062 - Crash in nvdahelperremote.dll@0xff2f

Status: RESOLVED WORKSFORME

(Core :: Disability Access APIs, defect, P1)

Description

[Marco Zehe (:MarcoZ)]

This bug was filed from the Socorro interface and is 
report bp-76b846cd-6f37-40b0-8e60-5f26a2161018.
=============================================================

This crash isn't actually ours, but in a NVDA library that interacts with Firefox. This is a new startup crash I now get everytime I start Firefox with E10S on. Starting in the 2016-10-18 Nightly build, after bug 1308397 has been fixed.

Jamie, I'm using NVDA version next-13643,b38d31ee.

I remember seeing this signature while battling bug 1308397, too, occasionally, but now it seems that I get a perma-failure. NI'ing Jamie for urgent advice.

Comment 1

[James Teh [:Jamie]]

I can't reproduce this. I tried starting with both a blank page and a home page (just google.com) and neither caused a crash. I'm going to need a proper minidump for this crash to debug it.

That said, the stack looks really odd. It goes from a call to free_impl (in memory/build/replace_malloc.c). The line it's on (201) is a call to je_free. But we never see that call: it somehow apparently ends up calling something in nvdaHelperRemote. That doesn't make any sense. We do hook some Windows functions, but nothing related to memory allocation.

Comment 2

[Marco Zehe (:MarcoZ)]

More info:

1. This crash seems to specifically tied to either Gmail in general or the Mozilla/Google Apps instance of it. If I make sure a different tab is in the foreground when I launch Firefox with E10S on, I get no crash. Only if I then switch tabs to the Gmail tab and it starts loading, it'll tear down the whole browser, not just the tab.

2. A report from this instance is:
bp-7bf5d4a2-a32c-40d4-bba9-610d52161019

Note that this crashes in a different location, in the VBufBackend, and the stack actually looks more reasonable, too.

Jamie, this is now with NVDA version next-13655,b35ca30f.

And I specifically give permission to share the minidump from this report with Jamie. It's also got my e-mail address and a comment from me in there.

Comment 3

[James Teh [:Jamie]]

I still can't reproduce this even with Gmail as a restored tab. This stack definitely looks a lot more realistic, though. I should be able to debug it with a minidump.

Comment 4

[James Teh [:Jamie]]

I realised Marco is using 64 bit Firefox and I'm not, so I tried a 64 bit nightly, but I still can't reproduce it. :(

Debugging notes:

I took a look at the minidumps. Here's the relevant stuff from one of them:

----
 # Child-SP          RetAddr           Call Site
00 000000ce`03bfd270 00007ffb`b481ce33 VBufBackend_gecko_ia2!std::_Tree_unchecked_const_iterator<std::_Tree_val<std::_Tree_simple_types<std::pair<VBufStorage_fieldNode_t * __ptr64 const,VBufStorage_buffer_t * __ptr64> > >,std::_Iterator_base0>::operator++(void)+0x37 [c:\program files (x86)\microsoft visual studio 14.0\vc\include\xtree @ 62]
01 000000ce`03bfd2b0 00007ffb`b4841d47 VBufBackend_gecko_ia2!std::_Tree_const_iterator<std::_Tree_val<std::_Tree_simple_types<std::pair<std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > const ,std::basic_string<wchar_t,std::char_traits<wchar_t>,std::allocator<wchar_t> > > > > >::operator++(void)+0x13 [c:\program files (x86)\microsoft visual studio 14.0\vc\include\xtree @ 274]
02 000000ce`03bfd2e0 00007ffb`b886ff30 VBufBackend_gecko_ia2!GeckoVBufBackend_t::renderThread_winEventProcHook(struct HWINEVENTHOOK__ * hookID = 0x00000000`000404d1, unsigned long eventID = 0x800a, struct HWND__ * hwnd = 0x00000000`00470138, long objectID = 0n-4, long childID = 0n-16777621, unsigned long threadID = 0x1718, unsigned long time = 0x179e348d)+0x107 [c:\projects\nvda\build\x86_64\vbufbackends\gecko_ia2\gecko_ia2.cpp @ 933]
03 000000ce`03bfd370 00007ffb`b88620fa nvdaHelperRemote!inProcess_winEventCallback(struct HWINEVENTHOOK__ * hookID = 0x00000000`000404d1, unsigned long eventID = 0x800a, struct HWND__ * hwnd = 0x00000000`00470138, long objectID = 0n-4, long childID = 0n-16777740, unsigned long threadID = 0x1718, unsigned long time = 0x179e348d)+0xd0 [c:\projects\nvda\build\x86_64\remote\inprocess.cpp @ 156]
04 000000ce`03bfd3f0 00007ffb`c35d32ef nvdaHelperRemote!inproc_winEventCallback(struct HWINEVENTHOOK__ * hookID = 0x00000000`000404d1, unsigned long eventID = 0x800a, struct HWND__ * hwnd = 0x00000000`00470138, long objectID = 0n-4, long childID = 0n-16777740, unsigned long threadID = 0x1718, unsigned long time = 0x179e348d)+0x48a [c:\projects\nvda\build\x86_64\remote\injection.cpp @ 76]
05 000000ce`03bfd550 00007ffb`c41389d4 user32!_ClientCallWinEventProc+0x3f
06 000000ce`03bfd5c0 00007ffb`c10b1644 ntdll!KiUserCallbackDispatcherContinue
07 000000ce`03bfd648 00007ffb`c35d35ac win32u!NtUserNotifyWinEvent+0x14
08 000000ce`03bfd650 00007ffb`885c2b11 user32!NotifyWinEvent+0x3c
09 000000ce`03bfd680 00007ffb`8860625f xul!mozilla::a11y::AccessibleWrap::FireWinEvent(class mozilla::a11y::Accessible * aTarget = 0x00000000`00000000, unsigned int aEventType = 6)+0x65 [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\src\accessible\windows\msaa\accessiblewrap.cpp @ 1242]
0a (Inline Function) --------`-------- xul!mozilla::a11y::ProxyStateChangeEvent+0xe [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\src\accessible\windows\msaa\platform.cpp @ 102]
----

The relevant line in our code is:

933             for(VBufBackendSet_t::iterator i=runningBackends.begin();i!=runningBackends.end();++i) {

So, it seems this somehow crashes in the STL. I'm confused by the fact that the iterator seems to be a const_iterator in a tree dealing with strings and not an iterator of VBufBackend_t* as it should be.

The second dump is mostly useless. Even though it doesn't complain about any missing symbols, the only frames we get useful symbols for are these:

----
01 00000078`eb3fd650 00000078`eb3fd690 nvdaHelperRemote!inProcess_winEventCallback(struct HWINEVENTHOOK__ * hookID = 0x00000000`007b0613, unsigned long eventID = 0x8002, struct HWND__ * hwnd = 0x00000000`001305e2, long objectID = 0n-4, long childID = 0n-16777506, unsigned long threadID = 0xc2c, unsigned long time = 0x14ed9d8f)+0xd0 [c:\projects\nvda\build\x86_64\remote\inprocess.cpp @ 156]
...
0f (Inline Function) --------`-------- mozglue!malloc_mutex_unlock+0x11 [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\src\memory\mozjemalloc\jemalloc.c @ 1702]
10 (Inline Function) --------`-------- mozglue!arena_dalloc+0xc8 [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\src\memory\mozjemalloc\jemalloc.c @ 4746]
11 (Inline Function) --------`-------- mozglue!je_free+0xdb [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\src\memory\mozjemalloc\jemalloc.c @ 6485]
12 00000078`eb3fd6c0 00000078`00000c2c mozglue!free_impl(void * ptr = 0x00000000`00000000)+0x101 [c:\builds\moz2_slave\m-cen-w64-ntly-000000000000000\build\src\memory\build\replace_malloc.c @ 201]
----

The relevant line of our code closes a block that begins with this:

for(winEventHookRegistry_t::iterator i=hookProcs.begin();i!=hookProcs.end();++i) {

This probably suggests that it crashes when the iterator goes out of scope. Again, crashing in the STL.

Comment 5

[James Teh [:Jamie]]

One thing I'm suspicious of is the new NVDA SendMessageCallback code we implemented for e10s. We're crossing dll boundaries here and there can be weirdness when you cross dll boundaries with C++ calls where both dlls have a static CRT. I would expect this to crash more obviously than this (and not here), but it's not impossible.

Marco, can you please try with an NVDA master build? Master doesn't have the SendMessageCallback stuff in it. This means you'll see problems with initial document loads and editable text fields will be unusable, but I'd be interested to know whether the crash goes away. Of course, this isn't full proof that this is the problem, as certain code paths won't get touched that normally would, but it's a start.

Comment 6

[Marco Zehe (:MarcoZ)]

I just tried this with a recent NVDA Master build, and I was able to start Firefox with the Gmail tab in the foreground five times without crashing. Only once did I get a crash. Unfortunately, our crash reporter didn't get invoked. Instead, I got this "Windows has detected that Nightly no longer works and needs to close it" dialog. That was also fairly quickly after starting Nightly.

I was also able to start Nightly with my IRCCloud tab in the foreground, and then switch to the Gmail tab without crashing. Twice.

So Jamie may be onto something here.

Comment 7

[James Teh [:Jamie]]

I've prepared an NVDA try build with the SendMessageCallback code which ensures we don't cross dll boundaries with C++ calls:
https://ci.appveyor.com/api/buildjobs/d3drrdywf8wxrh9f/artifacts/output%2Fnvda_snapshot_try-vbufPostMessage-13657%2Ce29fe6f1.exe
Unfortunately, it doesn't fix the problem. From IRC:

MarcoZ
Still crashes. :-(
But not every time. This is maddening!
Jamie: This one so far crashed for me 4 out of 6 times. And if I know the Gmail tab is in the foreground when I start Nightly, and am quick enough to press Ctrl+Tab, I can then avoid the crash, too. Heck I can then even switch to the Gmail tab without causing a crash again. This is really really weird.

So I'm stumped for now. We haven't changed anything in terms of the way we use the STL. It might be interesting to see crash dumps for this try build as well, but I suspect they'll be equivalently unenlightening.

Comment 8

[Marco Zehe (:MarcoZ)]

Jamie sent me another try build, with all kinds of debug messages and such on, and I reproduced a crash with that build, too. The report is:
bp-de90edd9-c6e6-4cb6-9dfd-e0b9c2161020

Unfortunately, the stack looks even differently screwed than the first, and nothing remotely like the second.
The try build is here: https://ci.appveyor.com/project/NVAccess/nvda/build/try-nextNhDebug-13658,65a31e78/artifact
The page also contains a link to a zip with the symbols I think. NVDA itself did not crash, so did not create a local dump I could fetch.

David or Aaron, could either of you get this dump to Jamie, please? Thanks!

Comment 9

[Marco Zehe (:MarcoZ)]

Umm, that link is: https://ci.appveyor.com/project/NVAccess/nvda/build/try-nextNhDebug-13658,65a31e78/artifacts

Comment 10

[(No longer employed by Mozilla) Aaron Klotz]

Done.

Comment 11

[James Teh [:Jamie]]

Thanks for the dump. It was quite enlightening... eventually. :)

I've hopefully fixed this now. Please try this next build with the change integrated:
https://ci.appveyor.com/api/buildjobs/wqn92338cwwrrsx1/artifacts/output%2Fnvda_snapshot_try-nextGecko64Crash-13660%2Cca91d9c2.exe

Comment 12

[Marco Zehe (:MarcoZ)]

I was so far unable to reproduce the crash again. I did get one crash in a different situation, and unfortunately our crash reporter didn't come up, but I was instead thrown into the Windows standard dialog for Closing or Debugging the application, but that was, as I said, in a different situation and probably a different crash.

I suggest to close this either INVALID or WORKSFORME as soon as the commit in the NVDA project gets approved and landed on Next.

If you're interested, here's the commit: https://github.com/nvaccess/nvda/commit/44c1d71454fc44b397a8bdb8c85a28ba75d87a66

Comment 13

[James Teh [:Jamie]]

Fix merged to NVDA next in commit 7a72aae. Assuming there aren't any problems with this, it should graduate to master in 2 weeks or so. For reference, the pull request is here:
https://github.com/nvaccess/nvda/pull/6497

Marco, I'll leave it up to you as to whether to close this as invalid or worksforme. :)

Comment 14

[Marco Zehe (:MarcoZ)]

Darn, I just got another startup crash. And this time, Crash Reporter also came up. Report is:
bp-90684913-73ce-4618-95cc-d14f82161031

NVDA version next-13681,f1bec5bd.

David, Aaron, could either of you get that minidump to Jamie for analysis?

Comment 15

[James Teh [:Jamie]]

Marco, it'd probably be useful to have an NVDA build with all debugging enabled so we get more info about stuff which is potentially hard to spot otherwise. Here's a current next build with all debugging enabled:
https://ci.appveyor.com/project/NVAccess/nvda/build/try-nextNhDebug-13689/artifacts

Comment 16

[Marco Zehe (:MarcoZ)]

Jamie, that link gives me an "Access denied or Build not found" error message.

Comment 17

[James Teh [:Jamie]]

Blerg. Sorry. Try this link:
https://ci.appveyor.com/api/buildjobs/a7t6c9h9axm6bxwm/artifacts/output%2Fnvda_snapshot_try-nextNhDebug-13689%2C8614748d.exe

Comment 18

[James Teh [:Jamie]]

And here's a link to the artifacts page in case someone wants the symbols:
https://ci.appveyor.com/project/NVAccess/nvda/build/try-nextNhDebug-13689,8614748d/artifacts

Comment 19

[Marco Zehe (:MarcoZ)]

Got the build, thanks Jamie!

(Removing David from NI since he's on PTO this week.)

Comment 20

[(No longer employed by Mozilla) Aaron Klotz]

Done.

Comment 21

[Marco Zehe (:MarcoZ)]

After today's update of Nightly, attempting to reproduce the bug with the debug-checks build failed. Will try again tomorrow.

Comment 22

[alexander :surkov (:asurkov)]

(In reply to Marco Zehe (:MarcoZ) from comment #21)
> After today's update of Nightly, attempting to reproduce the bug with the
> debug-checks build failed. Will try again tomorrow.

any luck?

Comment 23

[Marco Zehe (:MarcoZ)]

No, this crash has disappeared. Closing WFM.