"Find Step Definition Usages" command fails for the first time

gasparnagy commented 7 months ago

Used Visual Studio

Visual Studio 2022

Are the latest Visual Studio updates installed?

Yes

Content of reqnroll.json (if present)

No response

Issue Description

when a Reqnroll solution is first loaded, the context menu items for 'Find Step Definition Usages' and this new one 'Find Unused Step Definitions' (#8) fail. The output shows:

Info: OnActivityStarted: Starting Visual Studio Extension...
Info: CreateProjectScope: Initializing project: ReqnrollExampleProject
Info: OnSettingsInitialized: Project settings initialized: .NETCoreApp,Version=v8.0,Reqnroll:1.0.0
Warning: GetStepDefinitionsAsync: Unable to get step definitions from project 'ReqnrollExampleProject', usages will not be found for this project.
Info: FindUsagesInProjectsAsync: Found 0 usages in 0 feature files

Subsequent invocations do work properly.

Steps to Reproduce

Open Reqnroll project
Open step def class
Invoke 'Find Step Definition Usages'

Link to a project repository that reproduces the issue

No response

clrudolphi commented 6 months ago

@gasparnagy I'd like to help with this one. My first thought was to follow the tracing, then thought about increasing the log-level to Verbose. That appears to be driven by an Environment variable (REQNROLLVS_DEBUG). I'd like to set that in the Debug options for the extension. But I'm having a problem getting F5 debugging to work (... can't launch a class library...). Can't find anything relevant on the internet or SO. Any suggestions on how to configure VS2022 to properly launch the Experimental instance via the F5 debugging experience?

gasparnagy commented 6 months ago

In such cases, you can still just set the env var in windows and run the exp instance (maybe it also works if you set the env var in a shell and invoke devenv /rootsuffix Exp. And then you can attach to the process.

I usually run the exp instance, open the project that I want to test, but I make sure that no feature file should be opened. Then I attach to the process from the normal VS, by choosing in the menu: "Debug / Attach to process..." In that long list I find "devenv.exe" (the one that belongs to the exp instance - you see the title anyway) and click "Attach".

For just using the F5 you should should configure a debug profile for the "Reqnroll.VisualStudio.Package" project:

Make "Reqnroll.VisualStudio.Package" as startup project
Open project properties, select "Debug"
Click "Open debug launch profiles UI" (the same can be done from the debug button dropdown)
There is an empty profile you see, that you should delete (left up corner button)
Click on new profile button (left up corner), select "Executable"
For the "Executable" text box, set the path to devenv, e.g. C:\Program Files\Microsoft Visual Studio\2022\Community\Common7\IDE\devenv.exe
For the "Command line arguments" set /rootsuffix Exp
You can set environment variables as well

clrudolphi commented 6 months ago

@gasparnagy Thanks for the pointers on how to get the Env variable set. Got that working now.

I am using a simple example Calculator feature file and step definition class. No other projects or external assemblies. When I start the Experimental instance of VS and then open the example solution, and then first open the feature file and then the Step Definitions file, then the Find Usages command works first time without error.

If, when (from a fresh start) I first open the Step Definitions file (leaving the feature file unopened), then I get the error. I've attached debug traces from each run. I don't see anything in here that points to a root source. Does anything stand out to you? Trace_of_FindUsages_OpenedFeatureFileFirst.txt Trace_of_FindUsages_OpenedStepDefCodeFileFirst.txt

The only other thing I've noticed is that I have sometimes seen an exception (GetDefaultNamespace: Exception) thrown during the processing of the Command. Partial debug trace is below. That exception did NOT show up in the example traces attached (above); that might have something to do with the second RnRTestProject which I removed from the solution in order to simplify the situation.

ReqnrollVs: Verbose: PreExec:Find Step Definition Usages ReqnrollVs: Error: GetDefaultNamespace:Exception VsUtils.GetOutputFileName: System.Threading.ThreadAbortException: Thread was being aborted. at System.Diagnostics.Debugger.CustomNotification(ICustomDebuggerNotification data) at System.Diagnostics.Debugger.NotifyOfCrossThreadDependencySlow() at System.Diagnostics.Debugger.NotifyOfCrossThreadDependency() at Microsoft.VisualStudio.Threading.JoinableTaskContext.get_NoMessagePumpSynchronizationContext() at Microsoft.VisualStudio.Threading.JoinableTaskContext.OnJoinableTaskStarted(JoinableTask task) at Microsoft.VisualStudio.Threading.JoinableTask..ctor(JoinableTaskFactory owner, Boolean synchronouslyBlocking, String parentToken, JoinableTaskCreationOptions creationOptions, Delegate initialDelegate) at Microsoft.VisualStudio.Threading.JoinableTaskFactory.RunAsync[T](Func1 asyncMethod, Boolean synchronouslyBlocking, String parentToken, JoinableTaskCreationOptions creationOptions) at Microsoft.VisualStudio.Threading.JoinableTaskFactory.Run[T](Func1 asyncMethod, JoinableTaskCreationOptions creationOptions) at Reqnroll.VisualStudio.VsUtils.GetOutputFileName(Project project) in C:\Users\clrud\source\repos\Reqnroll.VisualStudio\Reqnroll.VisualStudio.Package\VsUtils.cs:line 172 VsUtils.GetOutputAssemblyPath: System.Threading.ThreadAbortException: Thread was being aborted. at Reqnroll.VisualStudio.VsUtils.GetOutputFileName(Project project) in C:\Users\clrud\source\repos\Reqnroll.VisualStudio\Reqnroll.VisualStudio.Package\VsUtils.cs:line 174 at Reqnroll.VisualStudio.VsUtils.GetOutputAssemblyPath(Project project) in C:\Users\clrud\source\repos\Reqnroll.VisualStudio\Reqnroll.VisualStudio.Package\VsUtils.cs:line 204 ReqnrollVs: Verbose: GetPackageReferences:Exception VsUtils.GetPlatformTargetName: System.Threading.ThreadAbortException: Thread was being aborted. at EnvDTE.Configuration.get_Properties() at Reqnroll.VisualStudio.VsUtils.GetPlatformTargetName(Project project) in C:\Users\clrud\source\repos\Reqnroll.VisualStudio\Reqnroll.VisualStudio.Package\VsUtils.cs:line 154 VsUtils.GetTargetFrameworkMoniker: System.Threading.ThreadAbortException: Thread was being aborted. at System.Diagnostics.Debugger.CustomNotification(ICustomDebuggerNotification data) at System.Diagnostics.Debugger.NotifyOfCrossThreadDependencySlow() at System.Diagnostics.Debugger.NotifyOfCrossThreadDependency() at Microsoft.VisualStudio.Threading.JoinableTaskContext.get_NoMessagePumpSynchronizationContext() at Microsoft.VisualStudio.Threading.JoinableTaskContext.OnJoinableTaskStarted(JoinableTask task) at Microsoft.VisualStudio.Threading.JoinableTask..ctor(JoinableTaskFactory owner, Boolean synchronouslyBlocking, String parentToken, JoinableTaskCreationOptions creationOptions, Delegate initialDelegate) at Microsoft.VisualStudio.Threading.JoinableTaskFactory.RunAsync[T](Func1 asyncMethod, Boolean synchronouslyBlocking, String parentToken, JoinableTaskCreationOptions creationOptions) at Microsoft.VisualStudio.Threading.JoinableTaskFactory.Run[T](Func1 asyncMethod, JoinableTaskCreationOptions creationOptions) at Reqnroll.VisualStudio.VsUtils.GetTargetFrameworkMoniker(Project project) in C:\Users\clrud\source\repos\Reqnroll.VisualStudio\Reqnroll.VisualStudio.Package\VsUtils.cs:line 271 VsUtils.GetTargetFrameworkMonikers: System.Threading.ThreadAbortException: Thread was being aborted. at System.Diagnostics.Debugger.CustomNotification(ICustomDebuggerNotification data) at System.Diagnostics.Debugger.NotifyOfCrossThreadDependencySlow() at System.Diagnostics.Debugger.NotifyOfCrossThreadDependency() at Microsoft.VisualStudio.Threading.JoinableTaskContext.get_NoMessagePumpSynchronizationContext() at Microsoft.VisualStudio.Threading.JoinableTaskContext.OnJoinableTaskStarted(JoinableTask task) at Microsoft.VisualStudio.Threading.JoinableTask..ctor(JoinableTaskFactory owner, Boolean synchronouslyBlocking, String parentToken, JoinableTaskCreationOptions creationOptions, Delegate initialDelegate) at Microsoft.VisualStudio.Threading.JoinableTaskFactory.RunAsync[T](Func1 asyncMethod, Boolean synchronouslyBlocking, String parentToken, JoinableTaskCreationOptions creationOptions) at Microsoft.VisualStudio.Threading.JoinableTaskFactory.Run[T](Func1 asyncMethod, JoinableTaskCreationOptions creationOptions) at Reqnroll.VisualStudio.VsUtils.GetTargetFrameworkMonikers(Project project) in C:\Users\clrud\source\repos\Reqnroll.VisualStudio\Reqnroll.VisualStudio.Package\VsUtils.cs:line 284

gasparnagy commented 6 months ago

I have checked this but could not find anything really. It seemed to me that something "happens" that causes the popup window to close. My guess was that it might be related to the logging to the output window pane. I quickly tried to comment out the complete ActivateInternal and SafeWrite methods of the VsDeveroomOutputPaneServices class and then the popup remains open, but it displays wrong results, like if it would not have waited for the binding registry to be created.

I have to go now, but maybe based on that you can find something:

you can figure out which parts of the VsDeveroomOutputPaneServices cause the problem (maybe only the activation)
you can maybe figure out why it is not waiting for the binding registry. The BindingRegistryCache.GetLatest should wait for the completion, but apparently it does not.

gasparnagy commented 6 months ago

But maybe if you find an answer for the binding registry waiting problem, the output pane will also be solved, so probably it is better to focus on that one.

clrudolphi commented 6 months ago

Findings so far:

The ReqnRoll 'ecosystem' is initialized either when a Solution is opened with a feature file open from a previous editing session or once a command has been issued (eg, edit or create a feature file, navigate to something, etc.). In the case of the "Find" commands, the PreExec gets called before the ecosystem is up and running.
I've not yet been able to identify why the call to BindingRegistryCache.GetLatest() #here doesn't return a fully populated bindingRegistry. This smells of some form of threading issue; I will need to spend time analyzing the call patterns and timings.

An interim fix may be to modify QueryStatus such that it returns Disabled until the ecosystem is initialized and the BindingRegistry is populated. I've tried that, the menu item appears on the context menu but grayed out and unselectable. A second right click and the item is then available for selection and works as desired.

On a semi-related note, for the Find Usages and Find Unused commands, we are using a heuristic to determine whether the project is a RnR project or not. Such as:

    var heuristicTest = textView.TextBuffer.CurrentSnapshot.GetText().Contains("Reqnroll") || textView.TextBuffer.CurrentSnapshot.GetText().Contains("SpecFlow");

But I note that other commands are using the Project system and its properties to determine that. Such as this code from GoToHooksCommand:

    if (projectSettings == null || !projectSettings.IsReqnrollProject || projectSettings.IsSpecFlowProject) 
       return DeveroomEditorCommandStatus.Disabled;
(And, BTW, isn't that a bug in that GoToHooks logic? Should there be a ! before projectSettings.IsSpecFlowProject? Otherwise ti would seem that the GoToHooks command will be disabled for SpecFlow projects.

So what do you think of the interim fix idea?

gasparnagy commented 6 months ago

An interim fix may be to modify QueryStatus such that it returns Disabled until the ecosystem is initialized and the BindingRegistry is populated.

This is a good idea. I remember now that earlier it was always enabled, but if the binding registry was not ready, it showed an message popup, that it is loading and please wait & retry. Disabling it has the disadvantage that users will not know why it is disabled and that it is worth retrying.

But I note that other commands are using the Project system and its properties to determine that.

The other commands are all for the feature file, that is why they are different. The heuristic is added so that the Reqnroll menu items don't disturb the production projects. But I have no idea why we are not checking the projectSettings as well. Maybe we should.

Should there be a ! before projectSettings.IsSpecFlowProject?

We do not have information about hooks for SpecFlow projects, so there this feature is not available.

gasparnagy commented 6 months ago

I have found it, this is how it looked like before the waiting has been implemented. https://github.com/specsolutions/deveroom-visualstudio/blob/master/Deveroom.VisualStudio/Editor/Commands/FindStepDefinitionCommand.cs#L64

gasparnagy commented 6 months ago

So maybe we should just revert to the old style. It is not a disaster if the user needs to click a few more times in this special case.

Just put a comment above it saying that se needed it because of the waiting problem.

clrudolphi commented 6 months ago

"revert to old style" meaning to pop up an error message indicating that the project isn't ready?

gasparnagy commented 6 months ago

Fixed by #14

reqnroll / Reqnroll.VisualStudio