Rubberduck: Stuck After Clicking on Pending

[carlossierra311]

I just upgraded to the latest version and opened the project I've been working on. After hitting the Pending button to trigger the initial scan, "Loading references" is shown on the button and nothing else happens. Nothing loads on Test Explorer, Code Inspections, Todo Explorer, etc.

Here is the log (trace level). Please let me know if I can provide any other information:

2017-01-19 19:37:17.2184;INFO-2.0.11.2453;Rubberduck.App;Rubberduck version 2.0.11.2453 loading:
    Operating System: Microsoft Windows NT 10.0.14393.0 x64
    Host Product: Microsoft Office 2016 x86
    Host Version: 16.0.7571.2109
    Host Executable: EXCEL.EXE;
2017-01-19 19:37:23.2404;DEBUG-2.0.11.2453;Rubberduck.UI.Command.MenuItems.ParentMenus.ParentMenuItemBase;(3672032) Executing click handler for menu item 'S&ettings', hash code 41234998;
2017-01-19 19:37:25.9404;DEBUG-2.0.11.2453;Rubberduck.Common.Hotkeys.Hotkey;Hotkey (C) not registered.;
2017-01-19 19:37:28.4643;DEBUG-2.0.11.2453;Rubberduck.UI.Command.MenuItems.CommandBars.AppCommandBarBase;(18663102) Executing click handler for commandbar item 'Pending', hash code 15358085;
2017-01-19 19:37:28.6865;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'ThisWorkbook' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7140;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja1' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7245;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Toolbar' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7370;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Instructions' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7370;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'cToolRanges' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7615;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja2' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7745;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Test_cToolRanges' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7860;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Test_ssDataTools' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7981;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'cBuffer' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.7981;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Test_cBuffer' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8231;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Test_cOptimizer' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8341;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja4' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8456;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'cBufferRanges' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8456;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Test_cBufferRanges' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8706;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja5' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8817;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja6' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8922;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja7' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.8922;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja3' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.9147;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja8' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.9272;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'ssDeveloperTools' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.9272;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'ssDataTools' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.9507;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'ssFileTools' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:28.9632;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'cOptimizer' state is changing to 'Pending' (thread 11);
2017-01-19 19:37:29.0093;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'VBA'.;
2017-01-19 19:37:29.0093;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'VBA'.;
2017-01-19 19:37:29.0308;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'Excel'.;
2017-01-19 19:37:29.0383;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'Excel'.;
2017-01-19 19:37:29.0523;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'MSForms'.;
2017-01-19 19:37:29.0523;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'MSForms'.;
2017-01-19 19:37:29.0778;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'Scripting'.;
2017-01-19 19:37:29.0853;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'Scripting'.;
2017-01-19 19:37:29.1233;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'VBIDE'.;
2017-01-19 19:37:29.1308;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'VBIDE'.;
2017-01-19 19:37:29.1824;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'Office'.;
2017-01-19 19:37:29.1824;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'Office'.;
2017-01-19 19:37:29.2749;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'stdole'.;
2017-01-19 19:37:29.2944;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'stdole'.;

[retailcoder]

This has to be a silent failure in the COM collector.. which I believe was fixed this week (@Comintern?). Does it consistently stall on stdole?

[comintern]

Stdole.dll would have worked in that release. Do you have any other libraries loaded other than Microsoft Scripting Runtime?

[carlossierra311]

Yes, it seems like it's always stuck on stdole. Here are my loaded libraries for that project.

[carlossierra311]

By the way, this seems to be happening only for projects that include RubberDuck test modules (I managed to reproduce it with two different files, with different levels of complexity). Other projects (even large ones) are parsed correctly, but they don't include RubberDuck tests.

[carlossierra311]

I take back my comment on always being stuck on stdole. And the libraries referenced by this other project are the same than the ones shown above, with the exception of Microsoft Forms 2.0 (which is missing on this one).

This is the log that was produced when I reproduced it with the second (smaller) project:

2017-01-19 20:28:05.2491;INFO-2.0.11.2453;Rubberduck.App;Rubberduck version 2.0.11.2453 loading: Operating System: Microsoft Windows NT 10.0.14393.0 x64 Host Product: Microsoft Office 2016 x86 Host Version: 16.0.7571.2109 Host Executable: EXCEL.EXE; 2017-01-19 20:28:10.2098;DEBUG-2.0.11.2453;Rubberduck.UI.Command.MenuItems.CommandBars.AppCommandBarBase;(33750194) Executing click handler for commandbar item 'Pending', hash code 51700524; 2017-01-19 20:28:10.3499;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'ThisWorkbook' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.3629;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja6' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.3629;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja2' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.3789;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Utilities' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.3789;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'IndicatorCalculation' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.3944;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'IndicatorData' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.3944;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'HistoryData' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.4119;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Constants' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.4119;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'IndicatorChart' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.4274;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'TestHistoryData' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.4274;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'TestIndicatorData' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.4430;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Hoja1' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.4430;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'TestIndicatorChart' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.4590;DEBUG-2.0.11.2453;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Common' state is changing to 'Pending' (thread 11); 2017-01-19 20:28:10.5010;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'VBA'.; 2017-01-19 20:28:10.5010;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'VBA'.; 2017-01-19 20:28:10.5215;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'Excel'.; 2017-01-19 20:28:10.5215;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'Excel'.; 2017-01-19 20:28:10.5430;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'stdole'.; 2017-01-19 20:28:10.5530;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'stdole'.; 2017-01-19 20:28:10.5690;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'Office'.; 2017-01-19 20:28:10.5850;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'Office'.; 2017-01-19 20:28:10.6001;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'VBIDE'.; 2017-01-19 20:28:10.6131;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'VBIDE'.; 2017-01-19 20:28:10.6291;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;Loading referenced type 'Scripting'.; 2017-01-19 20:28:10.6501;TRACE-2.0.11.2453;Rubberduck.Parsing.VBA.ParseCoordinator;COM reflecting reference 'Scripting'.;

[retailcoder]

Hmm, that does ring a bell. You can probably work around the issue by removing the reference to the RD type library, and converting the AssertClass instance to late-binding.

Declare it As Object and use CreateObject to set it in a ModuleInitialize method; tests will still work. You can also set the default to late-binding in test settings.

[carlossierra311]

Removing the RD reference fixed the parsing problem. But tests still won't run. Here is the message I'm getting after parsing ends and I hit the Run all tests button:

2017-01-19 20:52:57.7868;DEBUG-2.0.11.2453;Rubberduck.Common.Hotkeys.Hotkey;Hotkey (C) not registered.; 2017-01-19 20:52:59.3018;ERROR-2.0.11.2453;Rubberduck.UI.UnitTesting.TestExplorerViewModel;System.Runtime.InteropServices.COMException (0x800A03EC): Lo sentimos, no hemos encontrado D:\Dropbox\Optimización.xlsx. ¿Puede ser que lo haya movido, eliminado o le hayas cambiado el nombre? at Microsoft.Office.Interop.Excel._Application.Run(Object Macro, Object Arg1, Object Arg2, Object Arg3, Object Arg4, Object Arg5, Object Arg6, Object Arg7, Object Arg8, Object Arg9, Object Arg10, Object Arg11, Object Arg12, Object Arg13, Object Arg14, Object Arg15, Object Arg16, Object Arg17, Object Arg18, Object Arg19, Object Arg20, Object Arg21, Object Arg22, Object Arg23, Object Arg24, Object Arg25, Object Arg26, Object Arg27, Object Arg28, Object Arg29, Object Arg30) at Rubberduck.VBEditor.Application.ExcelApp.Run(QualifiedMemberName qualifiedMemberName) in c:\Users\Mathieu\Documents\GitHub\Rubberduck\Rubberduck.VBEEditor\Application\ExcelApp.cs:line 13 at Rubberduck.UnitTesting.TestEngine.Run(IEnumerable1 members) in c:\Users\Mathieu\Documents\GitHub\Rubberduck\RetailCoder.VBE\UnitTesting\TestEngine.cs:line 111
at Rubberduck.UnitTesting.TestEngine.Run(IEnumerable1 tests) in c:\Users\Mathieu\Documents\GitHub\Rubberduck\RetailCoder.VBE\UnitTesting\TestEngine.cs:line 74 at Rubberduck.UI.Command.RunAllTestsCommand.RunTests() in c:\Users\Mathieu\Documents\GitHub\Rubberduck\RetailCoder.VBE\UI\Command\RunAllTestsCommand.cs:line 80 at Rubberduck.UI.Command.RunAllTestsCommand.ExecuteImpl(Object parameter) in c:\Users\Mathieu\Documents\GitHub\Rubberduck\RetailCoder.VBE\UI\Command\RunAllTestsCommand.cs:line 44 at Rubberduck.UI.Command.CommandBase.Execute(Object parameter) in c:\Users\Mathieu\Documents\GitHub\Rubberduck\RetailCoder.VBE\UI\Command\CommandBase.cs:line 54;

My file is called _Optimización de Reabastecimientos.xlsm_, but I have no references to _D:\Dropbox\Optimización.xlsx_. Finally, for your convenience, this is the translated message that references this:

We are sorry, we couldn't find D:\Dropbox\Optimización.xlsx. ¿Could it be that you moved, deleted or renamed it?

And here is the full log file:
RubberduckLog.txt

[carlossierra311]

By the way, this is how my test module headers look like:

'@TestModule
... some variables declared here
' late binding used to create the Assert object, so that a reference to the RubberDuck
' library isn't required when using the application in other computers.
Private Assert As Object

'@ModuleInitialize
Public Sub ModuleInitialize()
    Set Assert = CreateObject("Rubberduck.AssertClass")
    ... the variables declared above are initialized here
End Sub

[retailcoder]

Hmm that's a different issue - seems the Application.Run call "works" but somehow gets confused with the file to run the call for... are the two files opened? How does it pick up D:\Dropbox\Optimización.xlsx? BTW your late-bound test module looks good (could set the reference to Nothing on ModuleCleanup though)

[comintern]

The Application.Run issue should be fixed as of commit b2f1679a. That one missed version 2.0.11 by 2 days. See #2492.

[carlossierra311]

@retailcoder I have only one file open at the time of each test. I really don't know why would it pick up that file path. My file is located under:

D:\Dropbox\SimpleSols\Desarrollo\Prototipos\ReplenishmentOptimizer

And the file name does contain "Optimización", but as shown above, is a longer, composite name, with spaces and with a different extension.

And yes, setting references to nothing is also part of the header (but thanks for the pointer!):

'@ModuleCleanup
Public Sub ModuleCleanup()
     ... other variables set to nothing
    Set Assert = Nothing
End Sub

[carlossierra311]

Thanks @comintern. I guess I'll have to wait for next release then?

[comintern]

I could probably upload a current build somewhere if you want to test it.

[retailcoder]

Ok so I'm closing this issue then, but feel free to reopen it if the current build still stalls 😄

If you want you can also follow the project's Maintenance and Features backlogs, and see what issues have been merged since the last release, what's in progress, etc.

[carlossierra311]

@comintern sure, I'll test it. Let me know where to get it...

[comintern]

OK, you can get the pre-pre-release of 2.0.11 and a half at https://dl.dropboxusercontent.com/u/44108390/Rubberduck.Setup.2.0.12.0.exe

[carlossierra311]

I have two questions for you:

1. The solution you provided for the stall is a permanent suggestion, or is there a fix on the way to allow us to use early binding?

2. The pre-pre-release allowed me to run the tests, but is generating additional problems. Should I open separate issues for those (knowing that they were produced on an unofficial release?

Thanks

[retailcoder]

@carlossierra311 thanks for your help and support here! We're currently loading the type libraries of all references, to discover the exposed COM types; when the Rubberduck.tlb type library is referenced, we happen to be loading at runtime, from Rubberduck.dll, the types exposed in that very same library - it seems this sometimes poses a problem that causes the COM collector to, well, essentially deadlock.

So to answer point 1, it's indeed a temporary solution - by not referencing the Rubberduck type library and using late-binding, Rubberduck will not load its own type library. The downside is that it can't resolve Rubberduck types (as it can't resolve any late-bound type... for now) - the real solution will definitely be implemented at some point (maybe not 2.0.12 though): we'll skip loading Rubberduck.tlb types with the COM collector, and simply use .NET reflection to generate the same metadata.

As for point 2, if you have feedback on the current build, it's absolutely invaluable and if you report these issues early, we can work to fix them before 2.0.12 is even released! :smile:

[carlossierra311]

Thanks @retailcoder. I'll open the other issues then...

[Vogel612]

Actually @retailcoder I wonder whether we should expose the Rubberduck.tlb data we reference in a separate dll. That should also solve the deadlocking problem, might be a little more complicated in the installer though 🤔

[retailcoder]

@Vogel612 I thought of doing that... but then it's quite complicated. Pulling the exposed members with reflection is much simpler and safer I think.