rubberduck-vba / Rubberduck

Every programmer needs a rubberduck. COM add-in for the VBA & VB6 IDE (VBE).
https://rubberduckvba.com
GNU General Public License v3.0
1.91k stars 299 forks source link

Exceptions on exiting #3614

Closed bclothier closed 5 years ago

bclothier commented 6 years ago

NOTE: This issue is meant to be an aggregation of other issues, to bring up to the date the current state of the persistent problem of getting a clean exit consistently everywhere. Apparently it is reported to occur on some machines, but not all.However, for those machines where it do happens, it seems to be fairly consistent. It is important to note that the issue may have had multiple causes and though we've made significant progress in reducing them. In fact, the current version of Rudderduck is much better behaved compared to previous versions where it was more apparent and crashed hard. Nonetheless we are still dealing with a silent zombie on the shutdown.

Problem

Whenever the following are true:

1) VBA host was opened 2) Rubberduck was loaded and has DockWindows attached. In testing, we used Code Explorer docked and visible.

Then whenever the user closes the application -- it does not matter how the user closes, whether the VBA window was closed previously, or not -- then application will zombify silently. There is no There was a problem and Windows is trying to find a solution. Rather the application is left hidden and must be then killed via the task manager.

Errors look similar to this:

Exception thrown at 0x75CABB49 (ole32.dll) in MSACCESS.EXE: 0xC0000005: Access violation reading location 0x0ACCFC34. occurred

image

or

NOTE: See next section for comments; this may be atypical. NOTE 2: It's likely that KernelBase.dll is noise because this is exception handling. This should be ignored.

Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000). occurred

image

What has been already tried

We already created a MCVE to demonstrate and while the numbers of errors aren't the same, they are similar enough to be possibly helpful. The slimmed version can be found here.

This is NOT host-specific. Though the above examples were from Access, reports has been made for Excel and Word and likely other hosts and errors are originating from the DLLs that are loaded by those hosts.

At one point, we tried explicitly releasing the objects, as documented here. But in the end we commented out the code because it was actually doing more damage than help. Further research indicates that we should not wantonly call Marshal.RelaseComObject, especially for objects we don't own.

However, @MDoerner did investigate the possibility of adding Marshal.ReleaseComObject to the CommandBarControls which are in use on the toolbars and in the menus since we do create those. Those did not help eliminate the errors but did not increase it, either.

As alluded already, in the earlier build, we did a massive refactor where we wrap all objects in an abstraction, which was meant to implement the Release, but even without that, we at least ensure that all our access go through the abstraction so that we have a well-defined points where we instantiate and where we destroy the references to COM objects we do not own.

We also tried to implement IDisposable, as documented here but this did not help and actually caused problems.

We did fix a very subtle bug with correctly unregistering the event sinks used with this and that.

In previous versions, whenever we had a debugger attached and Native mode is enabled, the program would have broke into the dissembly and waited on our response. However with the current version (2.1.1), the error does show up but only briefly; after few seconds, the debugger abruptly stops. We think it's because the .NET part has already shutdown, but we are getting access violation long after. If we change the debugger mode to Native exclusively, we are able to make the program break indefinitely, allowing us to inspect the stack trace.

@bclothier also had installed a hotfix which was totally unrelated to the issue but did share same symptoms to see whether it would rule out the possibility of a defective Windows DLL outside the usercode. This did change the errors on the shutdown, causing it to error in KernelBase.dll rather than ole.dll but did not ultimately fix it. Also, this was limited to Windows 7 and the error has been reported on other operating systems. That said, it was determined that the same error occurred even in Excel as well.

Additional details

You can review the other issues in this project to get more background or specific subsets that may or may not be relevant to the issue at hand.

References

Listed are links that we've already read in attempt to help us understand and implement any fixes.

https://msdn.microsoft.com/en-us/library/office/aa159887%28v=office.11%29.aspx?f=255&MSPPError=-2147217396

https://blogs.msdn.microsoft.com/visualstudio/2010/03/01/marshal-releasecomobject-considered-dangerous/

https://blogs.msdn.microsoft.com/cbrumme/2003/04/16/releasecomobject/

https://blogs.msdn.microsoft.com/oldnewthing/20100813-00/?p=13153

MDoerner commented 6 years ago

Let me add my observetions on Excel.

On my system (Excel 2013 x86, Windows 10), Excel seems to shut down properly, but in reallity it does not. Under the debugger, I get multiple exception on shutdown, but Excel chooses to shutdown with code 0 anyway. Moreover, there are still reports by other users of getting the recovery message on shutdown.

What the VS2017 debugger is telling me

On shutdown, I observe two distinct kinds of exceptions while running under the VS2017 debugger in mixed-mode with break on exception crossing the unmanaged/managed boundary set.

Winforms interop exceptions

The first kind of execptions are received via Winforms.

Exception thrown: 'System.Runtime.InteropServices.ExternalException' in System.Windows.Forms.dll
An exception of type 'System.Runtime.InteropServices.ExternalException' occurred in System.Windows.Forms.dll and wasn't handled before a managed/native boundary
External exception

winformsexception

There are six of these identical exceptions, which should be the same number as that of our dockable windows. The exceptions happen after our add-in shutdown code has finished and before the dockable windows actually receive a WM_DESTROY.

Access violations after everything is gone

The second kind of exceptions I observe are around 29 access violations, on which the mixed-mode debugger cannot stop.

Exception thrown at 0x71FD60D2 (clr.dll) in excel.exe: 0xC0000005: Access violation reading location 0x1A22CDAC.
The Common Language Runtime cannot stop at this exception. Common causes include: incorrect COM interop marshalling and memory corruption. To investigate further use native-only debugging.

There are five distinct memory addresses in the numerous exceptions, if I counted correctly.

These access violations happen right after our last DockableToolwindowPresenter has been finalized. (The finalizer only exists for debugging purposes.) At this point, the vbe7.dll, the vbeiu.dll and the VBE7INTL.DLL have already been unloaded for a while.

MDoerner commented 6 years ago

After having to reclone the repository, the error reporting changed somewhat. In particular, I can break on the first of the access violation. This yields the following stack trace:

accessviolation

Please note that my previous post and this one are based on running with the changes from PR #3615 present.

bclothier commented 6 years ago

Following up on @MDoerner 's PR which was cloned to my machine (Windows 7 64-bit, 32-bit Office 2010), I am able to exit cleanly from Excel and Word, but ~not from Access~ with Access, I get an error:

Unhandled exception thrown: read access violation.
**this** was 0xFDEA704. occurred

and debug output similar to this:

The thread 0x37e4 has exited with code 0 (0x0).
The thread 0x2d20 has exited with code 0 (0x0).
The thread 0x3094 has exited with code 0 (0x0).
The thread 0x23e8 has exited with code 0 (0x0).
The thread 0x1c24 has exited with code 0 (0x0).
The thread 0x34f8 has exited with code 0 (0x0).
The thread 0x37f8 has exited with code 0 (0x0).
The thread 0x2470 has exited with code 0 (0x0).
The thread 0x267c has exited with code 0 (0x0).
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 1837274
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 2033548
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 1771580
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 854380
DockableWindowHost release called.
DockableWindowHost release called.
SubclassingWindow.ReleaseHandle called for hWnd 1967994
DockableWindowHost release called.
SubclassingWindow.ReleaseHandle called for hWnd 2360470
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
App calling Hooks.Detach.
Removed handler for: CommandBar '&Run All Tests' (tag: Custom Popup 73671955::RubberduckMenu_UnitTests::RunAllTestsCommandMenuItem, hashcode:22112358)
Removed handler for: CommandBar '&Test Explorer' (tag: Custom Popup 73671955::RubberduckMenu_UnitTests::TestExplorerCommandMenuItem, hashcode:17370009)
Removed handler for: CommandBar 'Test M&odule' (tag: Custom Popup 73671955::RubberduckMenu_UnitTests::AddTestModuleCommandMenuItem, hashcode:64793495)
Removed handler for: CommandBar 'Test &Method' (tag: Custom Popup 73671955::RubberduckMenu_UnitTests::AddTestMethodCommandMenuItem, hashcode:46270551)
Removed handler for: CommandBar 'Test Method (&Expected Error)' (tag: Custom Popup 73671955::RubberduckMenu_UnitTests::AddTestMethodExpectedErrorCommandMenuItem, hashcode:13781782)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 73671955::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:56927182)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 73671955::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:42582590)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 73671955::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:47698992)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 73671955::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:26637750)
Removed handler for: CommandBar 'Regex &Assistant' (tag: Custom Popup 73671955::ToolsMenu::RegexAssistantCommandMenuItem, hashcode:9847515)
Removed handler for: CommandBar 'To&Do Items' (tag: Custom Popup 73671955::ToolsMenu::ToDoExplorerCommandMenuItem, hashcode:45833411)
Removed handler for: CommandBar 'Code Metrics' (tag: Custom Popup 73671955::ToolsMenu::CodeMetricsCommandMenuItem, hashcode:42375303)
Removed handler for: CommandBar 'Export Active Project...' (tag: Custom Popup 73671955::ToolsMenu::ExportAllCommandMenuItem, hashcode:21518778)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:38413159)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:10174118)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:46181392)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:34957427)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:44694577)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:66706877)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:49705306)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:12979352)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:24458203)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 73671955::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:18797239)
Removed handler for: CommandBar '&Code Explorer' (tag: Custom Popup 73671955::RubberduckMenu_Navigate::CodeExplorerCommandMenuItem, hashcode:63490983)
Removed handler for: CommandBar 'Rege&x Search/Replace' (tag: Custom Popup 73671955::RubberduckMenu_Navigate::RegexSearchReplaceCommandMenuItem, hashcode:34547936)
Removed handler for: CommandBar 'Find &symbol...' (tag: Custom Popup 73671955::RubberduckMenu_Navigate::FindSymbolCommandMenuItem, hashcode:42495969)
Removed handler for: CommandBar '&Find all references...' (tag: Custom Popup 73671955::RubberduckMenu_Navigate::FindAllReferencesCommandMenuItem, hashcode:46919403)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Custom Popup 73671955::RubberduckMenu_Navigate::FindAllImplementationsCommandMenuItem, hashcode:19621447)
Removed handler for: CommandBar 'Refresh' (tag: Menu Bar::RubberduckMenu::RefreshCommandMenuItem, hashcode:1930001)
Removed handler for: CommandBar '&About...' (tag: Menu Bar::RubberduckMenu::AboutCommandMenuItem, hashcode:50824398)
Removed handler for: CommandBar 'S&ettings' (tag: Menu Bar::RubberduckMenu::SettingsCommandMenuItem, hashcode:65299478)
Removed handler for: CommandBar 'Code &Inspections' (tag: Menu Bar::RubberduckMenu::InspectionResultsCommandMenuItem, hashcode:59451280)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:21489686)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:59189449)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:50090360)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:65217919)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:8650938)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:10749578)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:30787377)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:48160062)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:62942996)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 73672049::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:29616056)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 73672049::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:54766399)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 73672049::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:23135548)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 73672049::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:6893340)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 73672049::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:62040066)
Removed handler for: CommandBar 'Find &symbol...' (tag: Code Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:29637338)
Removed handler for: CommandBar '&Find all references...' (tag: Code Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:65409451)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Code Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:51814150)
Removed handler for: CommandBar '&Rename' (tag: MSForms::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:63674173)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:36196647)
Removed handler for: CommandBar '&Rename' (tag: MSForms Control::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:57334375)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms Control::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:46247333)
Removed handler for: CommandBar '&Rename' (tag: Project Window::RubberduckMenu::ProjectExplorerRefactorRenameCommandMenuItem, hashcode:13572818)
Removed handler for: CommandBar 'Find &symbol...' (tag: Project Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:55046503)
Removed handler for: CommandBar '&Find all references...' (tag: Project Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:25656486)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Project Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:29581782)
Removed handler for: CommandBar 'Ready' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReparseCommandMenuItem, hashcode:38551324)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ShowParserErrorsCommandMenuItem, hashcode:35649520)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextSelectionLabelMenuItem, hashcode:13014940)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextDescriptionLabelMenuItem, hashcode:50025604)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReferenceCounterLabelMenuItem, hashcode:52410227)
Removed handler for: CommandBar 'Serialize' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.SerializeDeclarationsCommandMenuItem, hashcode:11417598)
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\powrprof.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\powrprof.dll'
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0x0000071A: The remote procedure call was canceled, or if a call time-out was specified, the call timed out.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\vm3dum.dll'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Office\Office14\DBGHELP.DLL'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d9.dll'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d8thk.dll'
The thread 0x310c has exited with code 0 (0x0).
SubclassingWindow.ReleaseHandle called for hWnd 2622226
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Office\Office14\MSOSTYLE.DLL'
The thread 0x30d8 has exited with code 0 (0x0).
The thread 0x2370 has exited with code 0 (0x0).
The thread 0x35d0 has exited with code 0 (0x0).
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Common Files\microsoft shared\VBA\VBA7\VBE7.DLL'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Common Files\microsoft shared\VBA\VBA7\1033\VBE7INTL.DLL'
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\powrprof.dll'. Symbols loaded.
The thread 0x3200 has exited with code 0 (0x0).
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\powrprof.dll'
The thread 0x30d0 has exited with code 1 (0x1).
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\linkinfo.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\ntshrui.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\srvcli.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\slc.dll'. Cannot find or open the PDB file.
The thread 0x30b4 has exited with code 0 (0x0).
'MSACCESS.EXE' (Win32): Unloaded 'C:\PROGRA~2\COMMON~1\MICROS~1\OFFICE14\Cultures\OFFICE.ODF'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Common Files\microsoft shared\OFFICE14\RICHED20.DLL'
DockableToolwindowPresenter finalized.
Exception thrown at 0x76C3BB49 (ole32.dll) in MSACCESS.EXE: 0xC0000005: Access violation reading location 0x0A0FF214.

With the stack trace as given: image

NOTE: Earlier I was getting exceptions in KernelBase.dll but I think this is just noise because it's in a procedure named ExceptionHandler@16. I changed my debug options to ignore the KernelBase.dll which changed the listing in the call stack and hopefully trim unwanted noise.

However, after detaching the debugger, Debug outputs this:

The program '[12300] MSACCESS.EXE' has exited with code 0 (0x0).

Running Access without a debugger attached, it does clean cleanly.

However, in other run, I've seen different errors where Access becomes a zombie. In this case, the output looks like this:

The thread 0x1848 has exited with code 0 (0x0).
The thread 0x2c44 has exited with code 0 (0x0).
The thread 0x30ec has exited with code 0 (0x0).
The thread 0x128c has exited with code 0 (0x0).
The thread 0x36a4 has exited with code 0 (0x0).
Exception thrown at 0x74E0C54F in MSACCESS.EXE: Microsoft C++ exception: CExceptionJet at memory location 0x0015EC80.

Exception thrown at 0x74E0C54F in MSACCESS.EXE: Microsoft C++ exception: CExceptionHandler at memory location 0x0015F140.

DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 265312
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 2623566
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 265306
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 265316
DockableWindowHost release called.
DockableWindowHost release called.
SubclassingWindow.ReleaseHandle called for hWnd 265322
DockableWindowHost release called.
SubclassingWindow.ReleaseHandle called for hWnd 265338
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
App calling Hooks.Detach.
Removed handler for: CommandBar '&Run All Tests' (tag: Custom Popup 75302899::RubberduckMenu_UnitTests::RunAllTestsCommandMenuItem, hashcode:22112358)
Removed handler for: CommandBar '&Test Explorer' (tag: Custom Popup 75302899::RubberduckMenu_UnitTests::TestExplorerCommandMenuItem, hashcode:17370009)
Removed handler for: CommandBar 'Test M&odule' (tag: Custom Popup 75302899::RubberduckMenu_UnitTests::AddTestModuleCommandMenuItem, hashcode:64793495)
Removed handler for: CommandBar 'Test &Method' (tag: Custom Popup 75302899::RubberduckMenu_UnitTests::AddTestMethodCommandMenuItem, hashcode:46270551)
Removed handler for: CommandBar 'Test Method (&Expected Error)' (tag: Custom Popup 75302899::RubberduckMenu_UnitTests::AddTestMethodExpectedErrorCommandMenuItem, hashcode:13781782)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 75302899::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:56927182)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 75302899::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:42582590)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 75302899::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:47698992)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 75302899::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:26637750)
Removed handler for: CommandBar 'Regex &Assistant' (tag: Custom Popup 75302899::ToolsMenu::RegexAssistantCommandMenuItem, hashcode:9847515)
Removed handler for: CommandBar 'To&Do Items' (tag: Custom Popup 75302899::ToolsMenu::ToDoExplorerCommandMenuItem, hashcode:45833411)
Removed handler for: CommandBar 'Code Metrics' (tag: Custom Popup 75302899::ToolsMenu::CodeMetricsCommandMenuItem, hashcode:42375303)
Removed handler for: CommandBar 'Export Active Project...' (tag: Custom Popup 75302899::ToolsMenu::ExportAllCommandMenuItem, hashcode:21518778)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:38413159)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:10174118)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:46181392)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:34957427)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:44694577)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:66706877)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:49705306)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:12979352)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:24458203)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 75302899::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:18797239)
Removed handler for: CommandBar '&Code Explorer' (tag: Custom Popup 75302899::RubberduckMenu_Navigate::CodeExplorerCommandMenuItem, hashcode:63490983)
Removed handler for: CommandBar 'Rege&x Search/Replace' (tag: Custom Popup 75302899::RubberduckMenu_Navigate::RegexSearchReplaceCommandMenuItem, hashcode:34547936)
Removed handler for: CommandBar 'Find &symbol...' (tag: Custom Popup 75302899::RubberduckMenu_Navigate::FindSymbolCommandMenuItem, hashcode:42495969)
Removed handler for: CommandBar '&Find all references...' (tag: Custom Popup 75302899::RubberduckMenu_Navigate::FindAllReferencesCommandMenuItem, hashcode:46919403)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Custom Popup 75302899::RubberduckMenu_Navigate::FindAllImplementationsCommandMenuItem, hashcode:19621447)
Removed handler for: CommandBar 'Refresh' (tag: Menu Bar::RubberduckMenu::RefreshCommandMenuItem, hashcode:1930001)
Removed handler for: CommandBar '&About...' (tag: Menu Bar::RubberduckMenu::AboutCommandMenuItem, hashcode:50824398)
Removed handler for: CommandBar 'S&ettings' (tag: Menu Bar::RubberduckMenu::SettingsCommandMenuItem, hashcode:65299478)
Removed handler for: CommandBar 'Code &Inspections' (tag: Menu Bar::RubberduckMenu::InspectionResultsCommandMenuItem, hashcode:59451280)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:21489686)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:59189449)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:50090360)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:65217919)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:8650938)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:10749578)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:30787377)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:48160062)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:62942996)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 75302993::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:29616056)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 75302993::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:54766399)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 75302993::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:23135548)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 75302993::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:6893340)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 75302993::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:62040066)
Removed handler for: CommandBar 'Find &symbol...' (tag: Code Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:29637338)
Removed handler for: CommandBar '&Find all references...' (tag: Code Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:65409451)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Code Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:51814150)
Removed handler for: CommandBar '&Rename' (tag: MSForms::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:63674173)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:36196647)
Removed handler for: CommandBar '&Rename' (tag: MSForms Control::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:57334375)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms Control::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:46247333)
Removed handler for: CommandBar '&Rename' (tag: Project Window::RubberduckMenu::ProjectExplorerRefactorRenameCommandMenuItem, hashcode:13572818)
Removed handler for: CommandBar 'Find &symbol...' (tag: Project Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:55046503)
Removed handler for: CommandBar '&Find all references...' (tag: Project Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:25656486)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Project Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:29581782)
Removed handler for: CommandBar 'Ready' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReparseCommandMenuItem, hashcode:38551324)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ShowParserErrorsCommandMenuItem, hashcode:35649520)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextSelectionLabelMenuItem, hashcode:4178072)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextDescriptionLabelMenuItem, hashcode:37602652)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReferenceCounterLabelMenuItem, hashcode:52410227)
Removed handler for: CommandBar 'Serialize' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.SerializeDeclarationsCommandMenuItem, hashcode:11417598)
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\powrprof.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\powrprof.dll'
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0x0000071A: The remote procedure call was canceled, or if a call time-out was specified, the call timed out.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\vm3dum.dll'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Office\Office14\DBGHELP.DLL'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d9.dll'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d8thk.dll'
The thread 0x1ccc has exited with code 0 (0x0).
SubclassingWindow.ReleaseHandle called for hWnd 1640752
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\linkinfo.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\ntshrui.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\srvcli.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\slc.dll'. Cannot find or open the PDB file.
The thread 0x23b0 has exited with code 0 (0x0).
The thread 0x2318 has exited with code 0 (0x0).
The thread 0x2614 has exited with code 0 (0x0).
The thread 0x20b0 has exited with code 0 (0x0).
The thread 0x4dc has exited with code 0 (0x0).
The thread 0x3728 has exited with code 0 (0x0).
The thread 0x33a4 has exited with code 0 (0x0).
The thread 0x2778 has exited with code 0 (0x0).

Note that the threads has shutdown before the hooks on events were destroyed. This suggest a race condition.

WaynePhillipsEA commented 6 years ago

RubberDuckLog_2_1_0_2382.txt

Hi all, I'm going to start from a purely COM perspective. I haven't yet looked at RD source code.

This is a work-in-progress log of the Rubberduck loading process, from a COM point of view. This is achieved by providing a proxy IDTExtensibility2 interface to the managed DLL, which basically tracks every COM interaction that it possibly can, by wrapping all COM objects internally that are passed to and from Rubberduck. Initial it starts at the IDTExtensibility2 interface, but should track everything from there. You'll need to view the log with a fixed-width font.

Current restrictions:

1) Return/output values from the member calls are not yet logged. I just ran out of time for now, and this will be done by end of next week. 2) Event sinks (IConnectionPointContainer interface) are not yet tracked.

Interpreting the log:

Every line of the log essentially represents the start of a COM call, or sometimes the return of a COM call.

If a call returns immediately (most do), then you will see "... HRESULT" at the end of the same line, indicating the result status of the call. If a call does not return immediately, the EXIT point of the call will be on a separate line, with only the "HRESULT" listed on it. You can match split entry/exit calls using the CALLID value (or there is the pipe/indentations used as a visual indicator).

The OBJECTPTR is the 'this' COM object pointer of the call. Useful for tracking objects across calls. This will be more useful once output values are also logged.

The STACKPTR can be ignored.

Initial observations

This log is generated just from starting Access, opening the VBE, and closing the host after Rubberduck has finished loading.

I appreciate the log is big, and raw and a lot of the data is just noise, but I'm sure there are things you can already take from this if you look carefully.

In particular, at the moment it is clear that not all COM references are being released by the end of the OnDisconnection notification. You can see this by finding the OnDisconnection call, and then AFTER that call, you see all the command bars being released. That's bad, because VBA is not expecting you to hold these COM references after the OnDisconnection notification. Basically, you need to release absolutely every COM reference that you ultimately obtained from the VBE object in the OnConnection stage (which includes command bars, of course).

Further down, near the end of the list, you will see notices of "ERROR: PREVIOUS COM CALL ON THIS THREAD DID NOT RETURN". These happen after some Release() calls, and this indicates that the Release call was started, but must have faulted, as it never returned, and the exception got caught and VBE resumed the cleanup process anyway. This is very bad, and most likely caused by all the objects being released AFTER the OnDisconnection notification.

On the plus side, my wrappers can detect illegal accesses on fully released COM objects, and none were detected.

bclothier commented 6 years ago

@WaynePhillipsEA Just to confirm, was that done against the current release of Rudderduck? @MDoerner put out a PR #3615 yesterday which adds the code to release the COM objects that we do create.

Your log seems to confirm that we're on the right track. In earlier version, we were ReleaseComObject'ing everything but that made things worse because we were probably releasing what we didn't own too far early. This time, we are now selecting only the CommandBarControl, since we do create them so therefore it's ours to release and the .NET runtime seems to take care of the rest that we didn't create directly.

Regarding the last comment, "On the plus side, my wrappers can detect illegal accesses on fully released COM objects, and none were detected." -- what should we make of @MDoerner's statement that we got several access violations long after the vbe7.dll has been unloaded from the host? Furthermore, in spite of having had those access violations, we seem to be now able to exit cleanly more consistently with his PR. It's not 100%, as per my logs described in the previous post, so we're still dealing with a race condition somewhere.

WaynePhillipsEA commented 6 years ago

Yes, v2.1.0.2382. If someone can compile the newer one for me, I will retest it when I get chance. I don't use git.

You should be releasing ALL com references, not just for objects that you create. At the disconnection stage you have to hand back every reference you took from the VBE COM object, and it's children. If you don't do this explicitly, you're relying on the garbage collector to do it for you, which is wrong because it won't necessarily happen BEFORE you return from the OnDisconnection notification. After the OnDisconnection notification, VBE is shutting down and so ANY unexpected Release calls coming from the managed side garbage collector can and often will fail/crash.

Let's ensure this issue is fully fixed first by me testing the new version. If there are still objects being released after OnDisconnection, they can certainly be attributing to later crashes elsewhere, e.g. if the stack has become corrupt due to them.

bclothier commented 6 years ago

RubberduckLog Shutdown.txt

Testing with the latest PR #3615 from @MDoerner (based on this pre-release, I get this:

Unhandled exception thrown: read access violation.
**this** was 0xDA5A704. occurred

or

Unhandled exception at 0x76C3BB49 (ole32.dll) in MSACCESS.EXE: 0xC0000005: Access violation reading location 0x0DE82D3C. occurred

with the debug log (derived from first error but both generate very similar output. Note that VBE7 was already unloaded when we encounter the fatal exception:

The thread 0x230c has exited with code 0 (0x0).
The thread 0x26c0 has exited with code 0 (0x0).
The thread 0x4028 has exited with code 0 (0x0).
The thread 0x1c88 has exited with code 0 (0x0).
The thread 0x4870 has exited with code 0 (0x0).
The thread 0x4900 has exited with code 0 (0x0).
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 265514
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 985496
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 1905170
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 2559698
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 1378582
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 5702926
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
App calling Hooks.Detach.
Removed handler for: CommandBar '&Run All Tests' (tag: Custom Popup 273808540::RubberduckMenu_UnitTests::RunAllTestsCommandMenuItem, hashcode:41771788)
Removed handler for: CommandBar '&Test Explorer' (tag: Custom Popup 273808540::RubberduckMenu_UnitTests::TestExplorerCommandMenuItem, hashcode:41924012)
Removed handler for: CommandBar 'Test M&odule' (tag: Custom Popup 273808540::RubberduckMenu_UnitTests::AddTestModuleCommandMenuItem, hashcode:40401777)
Removed handler for: CommandBar 'Test &Method' (tag: Custom Popup 273808540::RubberduckMenu_UnitTests::AddTestMethodCommandMenuItem, hashcode:28071674)
Removed handler for: CommandBar 'Test Method (&Expected Error)' (tag: Custom Popup 273808540::RubberduckMenu_UnitTests::AddTestMethodExpectedErrorCommandMenuItem, hashcode:51318482)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 273808540::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:59213161)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 273808540::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:63156409)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 273808540::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:31536769)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 273808540::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:15395467)
Removed handler for: CommandBar 'Regex &Assistant' (tag: Custom Popup 273808540::ToolsMenu::RegexAssistantCommandMenuItem, hashcode:36044558)
Removed handler for: CommandBar 'To&Do Items' (tag: Custom Popup 273808540::ToolsMenu::ToDoExplorerCommandMenuItem, hashcode:63657274)
Removed handler for: CommandBar 'Code Metrics' (tag: Custom Popup 273808540::ToolsMenu::CodeMetricsCommandMenuItem, hashcode:14529570)
Removed handler for: CommandBar 'Export Active Project...' (tag: Custom Popup 273808540::ToolsMenu::ExportAllCommandMenuItem, hashcode:55965566)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:4341481)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:39073330)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:4263198)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:30299850)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:20864077)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:53558972)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:9774771)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:38368787)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:16115657)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 273808540::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:10823190)
Removed handler for: CommandBar '&Code Explorer' (tag: Custom Popup 273808540::RubberduckMenu_Navigate::CodeExplorerCommandMenuItem, hashcode:12268704)
Removed handler for: CommandBar 'Rege&x Search/Replace' (tag: Custom Popup 273808540::RubberduckMenu_Navigate::RegexSearchReplaceCommandMenuItem, hashcode:43309474)
Removed handler for: CommandBar 'Find &symbol...' (tag: Custom Popup 273808540::RubberduckMenu_Navigate::FindSymbolCommandMenuItem, hashcode:54240947)
Removed handler for: CommandBar '&Find all references...' (tag: Custom Popup 273808540::RubberduckMenu_Navigate::FindAllReferencesCommandMenuItem, hashcode:18406476)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Custom Popup 273808540::RubberduckMenu_Navigate::FindAllImplementationsCommandMenuItem, hashcode:31440558)
Removed handler for: CommandBar 'Refresh' (tag: Menu Bar::RubberduckMenu::RefreshCommandMenuItem, hashcode:56854006)
Removed handler for: CommandBar '&About...' (tag: Menu Bar::RubberduckMenu::AboutCommandMenuItem, hashcode:63817793)
Removed handler for: CommandBar 'S&ettings' (tag: Menu Bar::RubberduckMenu::SettingsCommandMenuItem, hashcode:36917027)
Removed handler for: CommandBar 'Code &Inspections' (tag: Menu Bar::RubberduckMenu::InspectionResultsCommandMenuItem, hashcode:33928053)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:12872293)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:48741777)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:21064410)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:32166651)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:55134036)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:26444277)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:28495625)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:55361963)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:36022812)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 273808633::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:55769855)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 273808633::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:37489233)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 273808633::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:1858778)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 273808633::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:16729007)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 273808633::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:16343335)
Removed handler for: CommandBar 'Find &symbol...' (tag: Code Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:36671901)
Removed handler for: CommandBar '&Find all references...' (tag: Code Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:61611653)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Code Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:17633966)
Removed handler for: CommandBar '&Rename' (tag: MSForms::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:24487969)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:19065136)
Removed handler for: CommandBar '&Rename' (tag: MSForms Control::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:37368498)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms Control::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:772170)
Removed handler for: CommandBar '&Rename' (tag: Project Window::RubberduckMenu::ProjectExplorerRefactorRenameCommandMenuItem, hashcode:6949536)
Removed handler for: CommandBar 'Find &symbol...' (tag: Project Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:62545829)
Removed handler for: CommandBar '&Find all references...' (tag: Project Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:26041554)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Project Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:33047401)
Removed handler for: CommandBar 'Ready' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReparseCommandMenuItem, hashcode:25774132)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ShowParserErrorsCommandMenuItem, hashcode:7329937)
Removed handler for: CommandBar 'L20C17 | Database.Module1.Process (procedure)' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextSelectionLabelMenuItem, hashcode:1012336)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextDescriptionLabelMenuItem, hashcode:9111029)
Removed handler for: CommandBar '0 references' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReferenceCounterLabelMenuItem, hashcode:65969435)
Removed handler for: CommandBar 'Serialize' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.SerializeDeclarationsCommandMenuItem, hashcode:30640599)
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\powrprof.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\powrprof.dll'
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0x0000071A: The remote procedure call was canceled, or if a call time-out was specified, the call timed out.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\vm3dum.dll'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Office\Office14\DBGHELP.DLL'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d9.dll'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d8thk.dll'
The thread 0x3510 has exited with code 0 (0x0).
SubclassingWindow.ReleaseHandle called for hWnd 920700
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in MSACCESS.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
The thread 0x41d8 has exited with code 0 (0x0).
The thread 0x2c9c has exited with code 0 (0x0).
The thread 0x17ec has exited with code 0 (0x0).
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Office\Office14\MSOSTYLE.DLL'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Common Files\microsoft shared\VBA\VBA7\VBE7.DLL'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Common Files\microsoft shared\VBA\VBA7\1033\VBE7INTL.DLL'
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\powrprof.dll'. Symbols loaded.
The thread 0x46e0 has exited with code 0 (0x0).
'MSACCESS.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\powrprof.dll'
The thread 0x2284 has exited with code 1 (0x1).
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\linkinfo.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\ntshrui.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\srvcli.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\slc.dll'. Cannot find or open the PDB file.
The thread 0x3590 has exited with code 0 (0x0).
'MSACCESS.EXE' (Win32): Unloaded 'C:\PROGRA~2\COMMON~1\MICROS~1\OFFICE14\Cultures\OFFICE.ODF'
'MSACCESS.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Common Files\microsoft shared\OFFICE14\RICHED20.DLL'
Exception thrown at 0x76C3BB4C (ole32.dll) in MSACCESS.EXE: 0xC0000005: Access violation reading location 0x0DA5A70C.
Unhandled exception thrown: read access violation.
**this** was 0xDA5A704.

We are also getting good logging, but no indication of missing a release. With the current version, we consistently get a zombie Access. However, Excel apparently seem to exit cleanly. The Excel's debug log is given:

DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 658058
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 1312944
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 658046
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 2623372
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 1575928
DockableWindowHost removed event handler.
SubclassingWindow.ReleaseHandle called for hWnd 919866
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
DockableWindowHost release called.
App calling Hooks.Detach.
Removed handler for: CommandBar '&Run All Tests' (tag: Custom Popup 307004959::RubberduckMenu_UnitTests::RunAllTestsCommandMenuItem, hashcode:41771788)
Removed handler for: CommandBar '&Test Explorer' (tag: Custom Popup 307004959::RubberduckMenu_UnitTests::TestExplorerCommandMenuItem, hashcode:41924012)
Removed handler for: CommandBar 'Test M&odule' (tag: Custom Popup 307004959::RubberduckMenu_UnitTests::AddTestModuleCommandMenuItem, hashcode:40401777)
Removed handler for: CommandBar 'Test &Method' (tag: Custom Popup 307004959::RubberduckMenu_UnitTests::AddTestMethodCommandMenuItem, hashcode:28071674)
Removed handler for: CommandBar 'Test Method (&Expected Error)' (tag: Custom Popup 307004959::RubberduckMenu_UnitTests::AddTestMethodExpectedErrorCommandMenuItem, hashcode:51318482)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 307004959::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:59213161)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 307004959::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:63156409)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 307004959::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:31536769)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 307004959::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:15395467)
Removed handler for: CommandBar 'Regex &Assistant' (tag: Custom Popup 307004959::ToolsMenu::RegexAssistantCommandMenuItem, hashcode:36044558)
Removed handler for: CommandBar 'To&Do Items' (tag: Custom Popup 307004959::ToolsMenu::ToDoExplorerCommandMenuItem, hashcode:63657274)
Removed handler for: CommandBar 'Code Metrics' (tag: Custom Popup 307004959::ToolsMenu::CodeMetricsCommandMenuItem, hashcode:14529570)
Removed handler for: CommandBar 'Export Active Project...' (tag: Custom Popup 307004959::ToolsMenu::ExportAllCommandMenuItem, hashcode:55965566)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:4341481)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:39073330)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:4263198)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:30299850)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:20864077)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:53558972)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:9774771)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:38368787)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:16115657)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 307004959::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:10823190)
Removed handler for: CommandBar '&Code Explorer' (tag: Custom Popup 307004959::RubberduckMenu_Navigate::CodeExplorerCommandMenuItem, hashcode:12268704)
Removed handler for: CommandBar 'Rege&x Search/Replace' (tag: Custom Popup 307004959::RubberduckMenu_Navigate::RegexSearchReplaceCommandMenuItem, hashcode:43309474)
Removed handler for: CommandBar 'Find &symbol...' (tag: Custom Popup 307004959::RubberduckMenu_Navigate::FindSymbolCommandMenuItem, hashcode:54240947)
Removed handler for: CommandBar '&Find all references...' (tag: Custom Popup 307004959::RubberduckMenu_Navigate::FindAllReferencesCommandMenuItem, hashcode:18406476)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Custom Popup 307004959::RubberduckMenu_Navigate::FindAllImplementationsCommandMenuItem, hashcode:31440558)
Removed handler for: CommandBar 'Refresh' (tag: Menu Bar::RubberduckMenu::RefreshCommandMenuItem, hashcode:56854006)
Removed handler for: CommandBar '&About...' (tag: Menu Bar::RubberduckMenu::AboutCommandMenuItem, hashcode:63817793)
Removed handler for: CommandBar 'S&ettings' (tag: Menu Bar::RubberduckMenu::SettingsCommandMenuItem, hashcode:36917027)
Removed handler for: CommandBar 'Code &Inspections' (tag: Menu Bar::RubberduckMenu::InspectionResultsCommandMenuItem, hashcode:33928053)
Removed handler for: CommandBar '&Rename' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::CodePaneRefactorRenameCommandMenuItem, hashcode:12872293)
Removed handler for: CommandBar 'Extract &Method' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorExtractMethodCommandMenuItem, hashcode:48741777)
Removed handler for: CommandBar 'Re&order Parameters' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorReorderParametersCommandMenuItem, hashcode:21064410)
Removed handler for: CommandBar 'Remo&ve Parameters' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorRemoveParametersCommandMenuItem, hashcode:32166651)
Removed handler for: CommandBar 'Introduce &Parameter' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorIntroduceParameterCommandMenuItem, hashcode:55134036)
Removed handler for: CommandBar 'Introduce &Field' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorIntroduceFieldCommandMenuItem, hashcode:26444277)
Removed handler for: CommandBar '&Encapsulate Field' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorEncapsulateFieldCommandMenuItem, hashcode:28495625)
Removed handler for: CommandBar 'Move Closer To &Usage' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorMoveCloserToUsageCommandMenuItem, hashcode:55361963)
Removed handler for: CommandBar 'E&xtract Interface' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorExtractInterfaceCommandMenuItem, hashcode:36022812)
Removed handler for: CommandBar '&Implement Interface' (tag: Custom Popup 307005053::RubberduckMenu_Refactor::RefactorImplementInterfaceCommandMenuItem, hashcode:55769855)
Removed handler for: CommandBar 'Current &Procedure' (tag: Custom Popup 307005053::SmartIndenterMenu::IndentCurrentProcedureCommandMenuItem, hashcode:37489233)
Removed handler for: CommandBar 'Current &Module' (tag: Custom Popup 307005053::SmartIndenterMenu::IndentCurrentModuleCommandMenuItem, hashcode:1858778)
Removed handler for: CommandBar 'Current Project' (tag: Custom Popup 307005053::SmartIndenterMenu::IndentCurrentProjectCommandMenuItem, hashcode:16729007)
Removed handler for: CommandBar '&Add '@NoIndent' (tag: Custom Popup 307005053::SmartIndenterMenu::NoIndentAnnotationCommandMenuItem, hashcode:16343335)
Removed handler for: CommandBar 'Find &symbol...' (tag: Code Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:36671901)
Removed handler for: CommandBar '&Find all references...' (tag: Code Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:61611653)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Code Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:17633966)
Removed handler for: CommandBar '&Rename' (tag: MSForms::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:24487969)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:19065136)
Removed handler for: CommandBar '&Rename' (tag: MSForms Control::RubberduckMenu::FormDesignerRefactorRenameCommandMenuItem, hashcode:37368498)
Removed handler for: CommandBar '&Find all references...' (tag: MSForms Control::RubberduckMenu::FormDesignerFindAllReferencesCommandMenuItem, hashcode:772170)
Removed handler for: CommandBar '&Rename' (tag: Project Window::RubberduckMenu::ProjectExplorerRefactorRenameCommandMenuItem, hashcode:6949536)
Removed handler for: CommandBar 'Find &symbol...' (tag: Project Window::RubberduckMenu::FindSymbolCommandMenuItem, hashcode:62545829)
Removed handler for: CommandBar '&Find all references...' (tag: Project Window::RubberduckMenu::FindAllReferencesCommandMenuItem, hashcode:26041554)
Removed handler for: CommandBar 'Go to &implementation...' (tag: Project Window::RubberduckMenu::FindAllImplementationsCommandMenuItem, hashcode:33047401)
Removed handler for: CommandBar 'Resolving references...' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReparseCommandMenuItem, hashcode:25774132)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ShowParserErrorsCommandMenuItem, hashcode:7329937)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextSelectionLabelMenuItem, hashcode:61410719)
Removed handler for: CommandBar '' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ContextDescriptionLabelMenuItem, hashcode:15825564)
Removed handler for: CommandBar '0 references' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.ReferenceCounterLabelMenuItem, hashcode:65969435)
Removed handler for: CommandBar 'Serialize' (tag: Rubberduck.UI.Command.MenuItems.CommandBars.SerializeDeclarationsCommandMenuItem, hashcode:30640599)
'EXCEL.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\powrprof.dll'. Symbols loaded.
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\powrprof.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\vm3dum.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Office\Office14\DBGHELP.DLL'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d9.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\d3d8thk.dll'
The thread 0x309c has exited with code 0 (0x0).
SubclassingWindow.ReleaseHandle called for hWnd 855550
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80131509, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
'EXCEL.EXE' (Win32): Loaded 'C:\Windows\Microsoft.NET\Framework\v4.0.30319\diasymreader.dll'. Symbols loaded.
The thread 0x2978 has exited with code 0 (0x0).
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
DockableToolwindowPresenter finalized.
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x8013153B, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0xE0434352 (parameters: 0x80004001, 0x00000000, 0x00000000, 0x00000000, 0x720D0000).
Exception thrown at 0x74E0C54F (KernelBase.dll) in EXCEL.EXE: 0x0000071A: The remote procedure call was canceled, or if a call time-out was specified, the call timed out.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
DockableWindowHost received WM.DESTROY.
'EXCEL.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Office\Office14\MSOSTYLE.DLL'
'EXCEL.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Microsoft Visual Studio 14.0\Visual Studio Tools for Office\x86\VSTOExcelAdaptor.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\vcruntime140.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-crt-convert-l1-1-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-crt-stdio-l1-1-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-crt-heap-l1-1-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-crt-string-l1-1-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-crt-runtime-l1-1-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\ucrtbase.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-core-file-l1-2-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-core-processthreads-l1-1-1.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-core-localization-l1-2-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-core-file-l2-1-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-core-timezone-l1-1-0.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Program Files\Common Files\Microsoft Shared\Team Foundation Server\15.0\x86\TFSOfficeAdd-in.dll'
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\api-ms-win-core-synch-l1-2-0.dll'
The thread 0x3948 has exited with code 0 (0x0).
The thread 0x378 has exited with code 0 (0x0).
The thread 0x3cf0 has exited with code 0 (0x0).
'EXCEL.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\powrprof.dll'. Symbols loaded.
'EXCEL.EXE' (Win32): Unloaded 'C:\Windows\SysWOW64\powrprof.dll'
The thread 0x191c has exited with code 1 (0x1).
'EXCEL.EXE' (Win32): Unloaded 'C:\PROGRA~2\COMMON~1\MICROS~1\OFFICE14\Cultures\OFFICE.ODF'
'EXCEL.EXE' (Win32): Unloaded 'C:\Program Files (x86)\Common Files\microsoft shared\OFFICE14\RICHED20.DLL'
The thread 0x4200 has exited with code 0 (0x0).
The thread 0x1d84 has exited with code 0 (0x0).
DockableToolwindowPresenter finalized.
The thread 0x3c1c has exited with code 0 (0x0).
The thread 0x425c has exited with code 0 (0x0).
The thread 0x202c has exited with code 0 (0x0).
The thread 0x358c has exited with code 0 (0x0).
The thread 0x4964 has exited with code 0 (0x0).
The thread 0x3228 has exited with code 0 (0x0).
The thread 0x4220 has exited with code 0 (0x0).
The thread 0x30c4 has exited with code 0 (0x0).
The thread 0x3db8 has exited with code 0 (0x0).
The thread 0x285c has exited with code 0 (0x0).
The thread 0x344c has exited with code 0 (0x0).
The thread 0x31b0 has exited with code 0 (0x0).
The thread 0x1eb0 has exited with code 0 (0x0).
The thread 0x1e70 has exited with code 0 (0x0).
The thread 0x331c has exited with code 0 (0x0).
The thread 0x2144 has exited with code 0 (0x0).
The thread 0x3068 has exited with code 0 (0x0).
The thread 0x2980 has exited with code 0 (0x0).
The thread 0x1f5c has exited with code 0 (0x0).
The thread 0x22c0 has exited with code 0 (0x0).
The thread 0x2018 has exited with code 0 (0x0).
The thread 0xbb0 has exited with code 0 (0x0).
The thread 0x290c has exited with code 0 (0x0).
The thread 0x4344 has exited with code 0 (0x0).
The thread 0x3238 has exited with code 0 (0x0).
The thread 0x2b34 has exited with code 0 (0x0).
The thread 0x44b0 has exited with code 0 (0x0).
The thread 0x14b8 has exited with code 0 (0x0).
The thread 0x4a10 has exited with code 0 (0x0).
The thread 0x46d4 has exited with code 0 (0x0).
The thread 0x2048 has exited with code 0 (0x0).
The thread 0x1f0c has exited with code 0 (0x0).
The thread 0x3d68 has exited with code 0 (0x0).
The thread 0x3b78 has exited with code 0 (0x0).
The thread 0x26ac has exited with code 0 (0x0).
'EXCEL.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\netutils.dll'. Symbols loaded.
The program '[19088] EXCEL.EXE' has exited with code 0 (0x0).
bclothier commented 6 years ago

@MDoerner - Considering the log, I still think our SafeComWrapper class still need a finalizer at least in the debug mode... something like this:

~SafeComWrapper()
{
  if(!HasBeenReleased) 
  { 
    Log.Fatal("The object was not released; the last known reference count was {_rcwReferenceCount}");
  }
}

Otherwise, we have no explicit logging for failures to release. Since we are only reading a local variable in the finalizer, it should be fine?

retailcoder commented 6 years ago

@bclothier @MDoerner one assumption here, is that a new SafeComWrapper instance does not necessarily mean a new RCW is created:

    public IVBProjects Collection => new VBProjects(IsWrappingNullReference ? null : Target.Collection);

    public IReferences References => new References(IsWrappingNullReference ? null : Target.References);

    public IVBComponents VBComponents => new VBComponents(IsWrappingNullReference || Protection == ProjectProtection.Locked ? null : Target.VBComponents);

A new SafeComWrapper instance is basically created every time we invoke a getter that returns a wrapper interface.

These instances will be finalized/collected, and shouldn't release anything - I think logging a Fatal entry whenever a SafeComWrapper is finalized with !HasBeenReleased could be misleading.

Wrapping a "fresh" COM object everytime is a work-around aiming to avoid the COM exceptions we inevitably end up getting when we cache them. So if that newing-up is a problem, we're in a catch-22 situation here.

bclothier commented 6 years ago

@retailcoder AIUI, the count returned by _rcwReferenceCount should represent the count of every new we do (whether explicitly or implicitly via a getter). Those are NOT the count we would get from IUnknown::Adddref/ IUnknown::Release, because again AIUI from the documentation linked in the first post, RCW only increments the IUnknown:AddRef once, but then it keeps an internal counter every time we use the RCW, which is what we get back when we do a ReleaseComObject/FinalReleaseComObject.

bclothier commented 6 years ago

That said, @retailcoder 's comment made me think -

given this:

// assume we already have a SomeComThingy form somewhere...
var a = SomeComThingy.AnotherComThingy;
var b = SomeComThingy.AnotherComThingy;

a.Release(); // count should return 1
b.Release(); // count should return 0

That means the finalizer in the a instance would have _rcwReferenceCount at 1... which would be wrong since we did correctly release the other reference but of course, the a doesn't get to know about it. So that's not an error condition.

What would be an error condition is if we did fail to call a.Release() -- and for that to fail, the __rcwReferenceCount would be still null. Therefore, the finalizer should simply check if _rcwReferenceCount is null and the wrapping reference is not null to throw a Log.Fatal.

Maybe we should create unit tests (but using an actual COM object being wrapped in a mock SafeComWrapper)....

retailcoder commented 6 years ago

Should _rcwReferenceCount be static then?

bclothier commented 6 years ago

IDK TBH. That's why I mentioned the need to unit test that wrapper in'n'out with a simple COM object (could be something like Scripting.FileSystemObject -- it has Folder (which has SubFolders), which would be very good representation for our VBE stuff, so we can make mock wrappers wrapping various Scripting objects and test the hell out of it.

bclothier commented 6 years ago

FWIW - if we do go ahead with unit testing the SafeComWrapper it may be necessary to have its own appdomain. This may be of some help.

WaynePhillipsEA commented 6 years ago

AddinBridgeLog.txt

Attached log from v2.1.2.2594-pre

Scroll right to the bottom. Much better, but still some COM references not being released until after OnDisconnection. In particular, CommandBarControls (collection), _CommandBars (collection), the VBE object itself, and the Window object returned from CreateToolWindow.

EDIT: the AddIn object as well, from the OnConnection event, and that is also crashing, like the Window objects.

WaynePhillipsEA commented 6 years ago

All of the detected exceptions seem to occur when the GC is releasing the Window pointers (from the CreateToolWindow call), after the OnDisconnection event.

WaynePhillipsEA commented 6 years ago

I've now added logging for the following interfaces that were previously not being tracked:

IConnectionPoint, IEnumConnectionPoints, IConnectionPointContainer, IEnumConnections, IEnumVARIANT, IPicture

This now provides total COM logging now between VBE and the RD Addin. The good news is that these all look to be being released correctly before disconnection.

WaynePhillipsEA commented 6 years ago

I could also add COM tracking to the ActiveX side of things for the tool windows if we need to, although I don't think you get much (f any) control over this at the managed side anyway. But as the tracking can detect exceptions, it might be useful to see if there are any problems occurring in there.

bclothier commented 6 years ago

Stringing together to document the development and progress of this case - additional comments has been made in various PRs:

PR #3615 PR #3635 PR #3644 PR #3653

WaynePhillipsEA commented 6 years ago

DockableWindowHost.zip

I'm just going to throw this out there, as I don't use git, and I'm not a C# guy so someone will have to take this on anyway to tidy it up if you decide to use it. I won't be offended if you don't :)

As discussed in chat, it is a drop in replacement for the current _DockabaleWindowHost, without the designer.

It implements the IOle ActiveX interfaces and proxies them to the UserControl, fixing the COM release problems relating to the UserControl implementation in the process.

bclothier commented 6 years ago

Thanks, @WaynePhillipsEA ! A clarification is needed - AIUI, we have 5 dockable toolwindows which may be loaded at any time. In your comment you suggest that we do complete teardown from a IOleObject::Close, rather than from the OnDisconnect. If there are more than one instance of the toolwindow loaded, we want to defer the full teardown until the last IOleObject::Close, right?

WaynePhillipsEA commented 6 years ago

Apologies, that's not what I meant. Each instance of the DockableWindowHost will be responsible for tearing itself down, including its COM references

bclothier commented 6 years ago

That makes more sense. Thanks again!

MDoerner commented 6 years ago

One question @WaynePhillipsEA. In the code, you have conditionals checking, whether an IntPtr is null. Do you maybe want to check whether it is IntPtr.Zero, which is not the same in C#?

retailcoder commented 6 years ago

@MDoerner good catch: IntPtr is a struct, it can't be null.

bclothier commented 6 years ago

Another comment - when we implement the wrappers, I think those need to go into their own namespace/folder. Maybe follow MSFT's lead and put them in Unmanaged or Native or whatever - the SafeComWrapper implementations should be the only one consuming those wrappers. IMO.

WaynePhillipsEA commented 6 years ago

@MDoerner, you're right, 2 null comparisons by the looks of it, and both should be IntPtr.Zero. Thanks!

bclothier commented 6 years ago

Stringing new PRs:

3660

3670

WaynePhillipsEA commented 6 years ago

RD_22_BridgeLog.txt AddinBridgeLog.txt

Latest log from v2.2 attached, indicating that command bars are not being released before returning from OnDisconnection event.

bclothier commented 6 years ago

As per the request via chat, here is the call stack when it's hung:

image

Please note that the hanging apparently happens long after we've completed the shutdown of everything. Since it seemed to be waiting on something, I thought I'd look at other stacks....

Screenshot 1 of 2: image

Screenshot 2 of 2: image

.... A lot of waiting going on. 😄

Debug output:

Rubberduck._Extension : 2018-04-12 05:59:12.0198;INFO;Rubberduck._Extension;Rubberduck is shutting down.;

Rubberduck._Extension : 2018-04-12 05:59:12.0768;TRACE;Rubberduck._Extension;Unhooking VBENativeServices events...;

Rubberduck._Extension : 2018-04-12 05:59:12.1098;TRACE;Rubberduck._Extension;Releasing dockable hosts...;

Rubberduck._Extension : 2018-04-12 05:59:12.1859;TRACE;Rubberduck._Extension;Initiating App.Shutdown...;

App calling Hooks.Detach.
Rubberduck._Extension : 2018-04-12 05:59:12.2419;TRACE;Rubberduck._Extension;Disposing IoC container...;

Rubberduck.UI.DockableToolwindowPresenter : 2018-04-12 05:59:12.2859;TRACE;Rubberduck.UI.DockableToolwindowPresenter;Disposing DockableWindowPresenter of type Rubberduck.UI.CodeMetrics.CodeMetricsDockablePresenter.;

Rubberduck.UI.DockableToolwindowPresenter : 2018-04-12 05:59:12.3159;TRACE;Rubberduck.UI.DockableToolwindowPresenter;Disposing DockableWindowPresenter of type Rubberduck.UI.ToDoItems.ToDoExplorerDockablePresenter.;

Rubberduck.UI.DockableToolwindowPresenter : 2018-04-12 05:59:12.3459;TRACE;Rubberduck.UI.DockableToolwindowPresenter;Disposing DockableWindowPresenter of type Rubberduck.UI.CodeExplorer.CodeExplorerDockablePresenter.;

Rubberduck.UI.DockableToolwindowPresenter : 2018-04-12 05:59:12.3769;TRACE;Rubberduck.UI.DockableToolwindowPresenter;Disposing DockableWindowPresenter of type Rubberduck.UI.Inspections.InspectionResultsDockablePresenter.;

Rubberduck.UI.DockableToolwindowPresenter : 2018-04-12 05:59:12.4079;TRACE;Rubberduck.UI.DockableToolwindowPresenter;Disposing DockableWindowPresenter of type Rubberduck.UI.UnitTesting.TestExplorerDockablePresenter.;

Rubberduck.AppMenu : 2018-04-12 05:59:12.4439;DEBUG;Rubberduck.AppMenu;Starting removal of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.RubberduckParentMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.4759;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.5069;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu_UnitTests.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.5379;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu SmartIndenterMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.5679;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu ToolsMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.5979;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu_Refactor.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.6499;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu_Navigate.;

Rubberduck.AppMenu : 2018-04-12 05:59:12.7069;TRACE;Rubberduck.AppMenu;Removing parent menu of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.RubberduckParentMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:12.7359;DEBUG;Rubberduck.AppMenu;Starting removal of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.CodePaneContextParentMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.7659;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.7949;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu_Refactor.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.8249;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu SmartIndenterMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:12.8609;TRACE;Rubberduck.AppMenu;Removing parent menu of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.CodePaneContextParentMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:12.8909;DEBUG;Rubberduck.AppMenu;Starting removal of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.FormDesignerContextParentMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:12.9199;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:12.9499;TRACE;Rubberduck.AppMenu;Removing parent menu of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.FormDesignerContextParentMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:12.9799;DEBUG;Rubberduck.AppMenu;Starting removal of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.FormDesignerControlContextParentMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:13.0099;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:13.0399;TRACE;Rubberduck.AppMenu;Removing parent menu of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.FormDesignerControlContextParentMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:13.0699;DEBUG;Rubberduck.AppMenu;Starting removal of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.ProjectWindowContextParentMenu.;

Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase : 2018-04-12 05:59:13.0999;DEBUG;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;Removing menu RubberduckMenu.;

Rubberduck.AppMenu : 2018-04-12 05:59:13.1290;TRACE;Rubberduck.AppMenu;Removing parent menu of top-level menu Rubberduck.UI.Command.MenuItems.ParentMenus.ProjectWindowContextParentMenu.;

Rubberduck.UI.Command.MenuItems.CommandBars.AppCommandBarBase : 2018-04-12 05:59:13.1590;DEBUG;Rubberduck.UI.Command.MenuItems.CommandBars.AppCommandBarBase;Removing commandbar.;

SubclassingWindow.ReleaseHandle called for hWnd 1968912
Rubberduck._Extension : 2018-04-12 05:59:13.2230;TRACE;Rubberduck._Extension;Disposing COM safe...;

Rubberduck._Extension : 2018-04-12 05:59:13.2580;INFO;Rubberduck._Extension;No exceptions were thrown.;

Rubberduck._Extension : 2018-04-12 05:59:13.2880;TRACE;Rubberduck._Extension;Unregistering AppDomain handlers....;

Rubberduck._Extension : 2018-04-12 05:59:13.3170;TRACE;Rubberduck._Extension;Done. Main Shutdown completed. Toolwindows follow. Quack!;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.4730;TRACE;Rubberduck.UI._DockableWindowHost;IOleInPlaceObject::InPlaceDeactivate() called;

Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite : 2018-04-12 05:59:13.5060;TRACE;Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite;IOleInPlaceSite::OnInPlaceDeactivate() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.5520;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::DoVerb() called with iVerb OLEIVERB_DISCARDUNDOSTATE.;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.5830;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Unadvise() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.6170;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::SetClientSite() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.6470;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.6770;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down host COM references;

'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\linkinfo.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\ntshrui.dll'. Symbols loaded.
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\srvcli.dll'. Symbols loaded.
Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.7200;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down internal COM references;

The thread 0xb704 has exited with code 0 (0x0).
'MSACCESS.EXE' (Win32): Loaded 'C:\Windows\SysWOW64\slc.dll'. Cannot find or open the PDB file.
Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.8010;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... unsubclassing the host parent window;

SubclassingWindow.ReleaseHandle called for hWnd 396758
Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.8680;TRACE;Rubberduck.UI._DockableWindowHost;IOleInPlaceObject::InPlaceDeactivate() called;

Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite : 2018-04-12 05:59:13.9070;TRACE;Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite;IOleInPlaceSite::OnInPlaceDeactivate() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.9450;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::DoVerb() called with iVerb OLEIVERB_DISCARDUNDOSTATE.;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:13.9740;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Unadvise() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.0040;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::SetClientSite() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.0340;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.0950;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down host COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.1261;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down internal COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.1561;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... unsubclassing the host parent window;

SubclassingWindow.ReleaseHandle called for hWnd 396650
Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.2121;TRACE;Rubberduck.UI._DockableWindowHost;IOleInPlaceObject::InPlaceDeactivate() called;

Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite : 2018-04-12 05:59:14.2421;TRACE;Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite;IOleInPlaceSite::OnInPlaceDeactivate() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.2721;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::DoVerb() called with iVerb OLEIVERB_DISCARDUNDOSTATE.;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.3011;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Unadvise() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.3561;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::SetClientSite() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.3851;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.4141;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down host COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.4441;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down internal COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.4731;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... unsubclassing the host parent window;

SubclassingWindow.ReleaseHandle called for hWnd 396652
Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.5301;TRACE;Rubberduck.UI._DockableWindowHost;IOleInPlaceObject::InPlaceDeactivate() called;

Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite : 2018-04-12 05:59:14.5611;TRACE;Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite;IOleInPlaceSite::OnInPlaceDeactivate() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.5921;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::DoVerb() called with iVerb OLEIVERB_DISCARDUNDOSTATE.;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.6221;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Unadvise() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.6521;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::SetClientSite() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.6821;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.7111;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down host COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.7511;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down internal COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.7991;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... unsubclassing the host parent window;

SubclassingWindow.ReleaseHandle called for hWnd 462224
Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.8551;TRACE;Rubberduck.UI._DockableWindowHost;IOleInPlaceObject::InPlaceDeactivate() called;

Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite : 2018-04-12 05:59:14.8841;TRACE;Rubberduck.UI.CustomComWrappers.Wrapper_IOleClientSite;IOleInPlaceSite::OnInPlaceDeactivate() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.9131;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::DoVerb() called with iVerb OLEIVERB_DISCARDUNDOSTATE.;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.9431;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Unadvise() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:14.9751;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::SetClientSite() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:15.0081;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() called;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:15.0381;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down host COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:15.0681;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... closing down internal COM references;

Rubberduck.UI._DockableWindowHost : 2018-04-12 05:59:15.0971;TRACE;Rubberduck.UI._DockableWindowHost;IOleObject::Close() ... unsubclassing the host parent window;

SubclassingWindow.ReleaseHandle called for hWnd 1051796
The thread 0xda8 has exited with code 0 (0x0).

(note that the last message will keep outputting once every a while; likely irrevelant)

bclothier commented 5 years ago

In light of what has happened since the issue opened, I think we are in a position to close the issue after the PR #4458 which addresses the remaining issue that prevents a clean shutdown for all hosts.

PowerWeb5 commented 5 years ago

Really glad to hear it.
Thanks so much, @bclothier, @retailcoder and others who've worked on this so no longer get exceptions on Access shutdown!

retailcoder commented 5 years ago

Props to @bclothier, @MDoerner, @WaynePhillipsEA, and @comintern on this. I didn't do much there.