Invoking StateChanged (ResolvedDeclarations) takes about 3 minutes (locking the VBA Editor for this time)

[RadioEngineer]

Hello,

Thank you very much indeed for having created and for supporting this fantastic free tool -- I am very grateful to you and all who participated and so generously donated their time and expertise to the creation and maintenance of this tool. I feel a little awkward needing to point that in my case there seems to be a problem with the tool and that I may need your help (and thus detract your attention from whatever more useful and important you might be doing).

Also, I am not sure whether this is the right forum for asking such questions or reporting such [potential] problems, but I was not able to find any other forum -- please advise if there is a more suitable one and I will remove my post from here.

MY PROBLEM: every time Rubberduck invokes StateChanged (ResolvedDeclarations) it takes about 3 minutes (150-200 seconds) to finish, during which time the VBA Editor remains locked (entirely unresponsive). Having to wait 3 minutes at the start is not that bad, but when this happens every time I perform code indent with Rubberduck (i.e. every two or three minutes of coding) it may become annoying. (Why? Because working for 2 or 3 minutes and then waiting for another 2 or 3 minutes seems like not very productive work.) Here is an extract from the Rubberduck log to illustrate the issue -- note the time between the second and third lines (please see the entire log attached):

2019-08-23 10:29:48.8844;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Resolved user declaration in 12ms.;
2019-08-23 10:29:50.3867;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (15) is invoking StateChanged (ResolvedDeclarations);
2019-08-23 10:32:48.1903;DEBUG-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Reform_Planet_Reports' state is changing to 'ResolvingReferences' (thread 5);
2019-08-23 10:32:48.1903;DEBUG-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Compare_Worksheets' state is changing to 'ResolvingReferences' (thread 5);

MY QUESTIONS:
(1) Is there a way how to disable automatic invoking of StateChanged (ResolvedDeclarations) after code indenting with Rubberduck? (I was not able to find this in Rubberduck settings, and also I have already cleared the checkbox for "Run Inspections Automatically on Successful Parse" in the Code Inspection Settings).

(2) Is there anything to prevent the VBA Editor from becoming locked (entirely unresponsive) for this long time (stupid question, I know, but perhaps I am missing something obvious)?

Or, is it that I am doing something completely wrong? (I suppose difficult to say without any further information from my end -- but if there is anything that I could provide please advise).

Once again, apologies if this is not the right forum for such questions and problems. And many thanks indeed for the excellent tool -- at long last VBA is on the brink of entering the 21st century!

Kind regards,
Radio Engineer.

P.S. I use VBA extensively in my job and in my hobbies. Rubberduck in general (and its indent function specifically in this case) are of great use and help to me.

RubberduckLog.txt

[Vogel612]

Hey, thanks for the kind words.

Here's the timeline for the parsing runs you attached. The first run is the initial parse. All modules are parsed here.

Notably, Inspections are not run here, which means the initial parsing clocks in at about 220 seconds, roughly three and a half minutes (10:25:57 -> 10:29:38)

2019-08-23 10:25:57.4501;DEBUG-2.4.1.4627;Rubberduck.Parsing.VBA.ParseCoordinator;Parsing run started. (thread 10).;
2019-08-23 10:25:57.4501;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (1) is invoking StateChanged (Started);
2019-08-23 10:25:59.0815;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (2) is invoking StateChanged (LoadingReference);
2019-08-23 10:26:00.9244;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Loaded and unloaded referenced libraries in 1598ms.;
2019-08-23 10:26:01.3786;DEBUG-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Module_Plamens_Autosave' state is changing to 'Parsing' (thread 5);
2019-08-23 10:26:23.2759;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Parsed user modules in 21230ms.;
2019-08-23 10:26:23.2929;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (4) is invoking StateChanged (Parsed);
2019-08-23 10:26:23.8735;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (5) is invoking StateChanged (ResolvingDeclarations);
2019-08-23 10:26:25.6503;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Resolved user declaration in 1581ms.;
2019-08-23 10:26:25.8339;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (6) is invoking StateChanged (ResolvedDeclarations);
2019-08-23 10:29:36.3431;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Resolved references in 26505ms.;
2019-08-23 10:29:36.3900;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Determined module to module references in 48ms.;
2019-08-23 10:29:36.9057;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (8) is invoking StateChanged (Ready);
2019-08-23 10:29:38.1558;DEBUG-2.4.1.4627;Rubberduck.Parsing.VBA.ParseCoordinator;Parsing run finished after 220.7076563s. (thread 10).;

A whole five seconds later, the next parsing run is triggered after indenting the current Module ('Reform_Planet_Reports').

2019-08-23 10:29:46.7315;DEBUG-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;Module 'Reform_Planet_Reports' state is changing to 'Started' (thread 5);
2019-08-23 10:29:46.7315;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (10) is invoking StateChanged (LoadingReference);
2019-08-23 10:29:47.3557;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Loaded and unloaded referenced libraries in 232ms.;
2019-08-23 10:29:48.3874;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Parsed user modules in 278ms.;
2019-08-23 10:29:48.3874;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (13) is invoking StateChanged (Parsed);
2019-08-23 10:29:48.8844;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Resolved user declaration in 12ms.;
2019-08-23 10:29:50.3867;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (15) is invoking StateChanged (ResolvedDeclarations);
2019-08-23 10:32:59.8724;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Resolved references in 9277ms.;
2019-08-23 10:32:59.9037;DEBUG-2.4.1.4627;Rubberduck.Parsing.Common.ParsingStageTimer;Determined module to module references in 31ms.;
2019-08-23 10:33:00.3256;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (17) is invoking StateChanged (Ready);
2019-08-23 10:33:00.3256;INFO-2.4.1.4627;Rubberduck.Parsing.VBA.RubberduckParserState;RubberduckParserState (17) is invoking StateChanged (Ready);
2019-08-23 10:33:01.2163;DEBUG-2.4.1.4627;Rubberduck.Parsing.VBA.ParseCoordinator;Parsing run finished after 197.0868891s. (thread 5).;

Interestingly here, the parsing of the changed module is significantly faster (what with only parsing a single module), but resolving references takes about the same time.

This parsing run clocks in at 197 seconds, yet the constituent stages of parsing can not account for roughly 170 of these seconds, which is ... deeply worrying.

Bottom line: We kinda really need to find out where parsing is bleeding unaccounted time to have a chance to adress this...

[MDoerner]

I see that you use the stable last release. Could you try the current prerelease, or one from the last two months?

I recall observing this and analyzing it under a profiler. I think some (partial) fix has been implemented at some point after the last stable release.

[MDoerner]

@Vogel612 The stages do not contain the invokation of the event handlers for the state changed events. I think the problem here was/is in the CE refresh.

[MDoerner]

I did some digging. The freeze mentioned here has already been observed in issue #4905 and the main sources should have been fixed in the PRs #4918 and #4914.

The main source was that the CE refresh reloaded settings over and over from file because of a bug in the code for loading the settings. This bug prevented the intended caching to happen.

Unfortunately, there has not been a stable release since the fix.

[RadioEngineer]

Hello MDoerner and Vogel612,

Many thanks for the fast response. As advised, I will now try installing the latest availabl release and report on this.

Thanks,
Radio Engineer

[RadioEngineer]

Hello MDoerner and Vogel612,

THE ISSUE IS NOW RESOLVED FOR ME -- as advised by MDoerner I installed the latest release available at this time (which was Rubberduck v2.4.1.4869-pre) and the problem seems to have disappeared.

This was truely great response from you both -- thank you very much indeed for your help and time. Thanks to MDoerner for suggesting to use the latest release, and to Vogel612 for helping with the initial analysis (and for even editing my first post to make it more readable -- I will remember now to use "..." for inserting code, rather than the "backquote" which I had used originally).

Kind regards,
Radio Engineer