From ee1a2edf450dbe48231927f9eb7a52455ded4dfe Mon Sep 17 00:00:00 2001 From: Andrew Schwartzmeyer Date: Thu, 2 Sep 2021 13:24:11 -0700 Subject: [PATCH 1/3] Send `stopDebugger` notification when appropriate --- .../PowerShellContextService.cs | 31 +++++++++++++++++++ 1 file changed, 31 insertions(+) diff --git a/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs b/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs index ad35c519e..2a1fe1bfb 100644 --- a/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs +++ b/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs @@ -162,8 +162,18 @@ public RunspaceDetails CurrentRunspace /// public string InitialWorkingDirectory { get; private set; } + /// + /// Tracks the state of the LSP debug server (not the PowerShell debugger). + /// internal bool IsDebugServerActive { get; set; } + /// + /// Tracks if the PowerShell session started the debug server itself (true), or if it was + /// started by an LSP notification (false). Essentially, this marks if we're responsible for + /// stopping the debug server (and thus need to send a notification to do so). + /// + internal bool OwnsDebugServerState { get; set; } + internal DebuggerStopEventArgs CurrentDebuggerStopEventArgs { get; private set; } #endregion @@ -777,6 +787,21 @@ public async Task> ExecuteCommandAsync( await this.sessionStateLock.ReleaseForExecuteCommand().ConfigureAwait(false); } + // This is the edge case where the debug server is running because it was + // started by PowerShell (and not by an LSP event), and we're no longer in the + // debugger within PowerShell, so since we own the state we need to stop the + // debug server too. + // + // Strangely one would think we could check `!PromptNest.IsInDebugger` but that + // doesn't work, we have to check if the shell is nested instead. Therefore this + // is a bit fragile, and I don't know how it'll work in a remoting scenario. + if (IsDebugServerActive && OwnsDebugServerState && !shell.IsNested) + { + logger.LogDebug("Stopping LSP debugger because PowerShell debugger stopped running!"); + OwnsDebugServerState = false; + _languageServer?.SendNotification("powerShell/stopDebugger"); + } + if (shell.HadErrors) { var strBld = new StringBuilder(1024); @@ -2422,8 +2447,14 @@ private void OnDebuggerStop(object sender, DebuggerStopEventArgs e) // when the DebugServer is fully started. CurrentDebuggerStopEventArgs = e; + // If this event has fired but the LSP debug server is not active, it means that the + // PowerShell debugger has started some other way (most likely an existing PSBreakPoint + // was executed). So not only do we have to start the server, but later we will be + // responsible for stopping it too. if (!IsDebugServerActive) { + logger.LogDebug("Starting LSP debugger because PowerShell debugger is running!"); + OwnsDebugServerState = true; _languageServer?.SendNotification("powerShell/startDebugger"); } From 8522e0f3bb1d53efea448c2e29aba46b6dc0d90d Mon Sep 17 00:00:00 2001 From: Andrew Schwartzmeyer Date: Thu, 2 Sep 2021 13:25:34 -0700 Subject: [PATCH 2/3] Clean up logging in `PowerShellContextService` I added a bunch more recently that was became less useful and more noisy after my familiarity improved. --- .../Internal/EditorServicesRunner.cs | 2 +- .../PowerShellContextService.cs | 47 +++++-------------- 2 files changed, 13 insertions(+), 36 deletions(-) diff --git a/src/PowerShellEditorServices.Hosting/Internal/EditorServicesRunner.cs b/src/PowerShellEditorServices.Hosting/Internal/EditorServicesRunner.cs index a68842876..896a3d09f 100644 --- a/src/PowerShellEditorServices.Hosting/Internal/EditorServicesRunner.cs +++ b/src/PowerShellEditorServices.Hosting/Internal/EditorServicesRunner.cs @@ -308,7 +308,7 @@ private void WriteStartupBanner() private void DebugServer_OnSessionEnded(object sender, EventArgs args) { - _logger.Log(PsesLogLevel.Verbose, "Debug session ended. Restarting debug service"); + _logger.Log(PsesLogLevel.Verbose, "Debug session ended, restarting debug service..."); var oldServer = (PsesDebugServer)sender; oldServer.Dispose(); _alreadySubscribedDebug = false; diff --git a/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs b/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs index 2a1fe1bfb..f251d3e63 100644 --- a/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs +++ b/src/PowerShellEditorServices/Services/PowerShellContext/PowerShellContextService.cs @@ -192,7 +192,6 @@ public PowerShellContextService( OmniSharp.Extensions.LanguageServer.Protocol.Server.ILanguageServerFacade languageServer, bool isPSReadLineEnabled) { - logger.LogTrace("Instantiating PowerShellContextService and adding event handlers"); _languageServer = languageServer; this.logger = logger; this.isPSReadLineEnabled = isPSReadLineEnabled; @@ -214,7 +213,7 @@ public static PowerShellContextService Create( // Respect a user provided bundled module path. if (Directory.Exists(hostStartupInfo.BundledModulePath)) { - logger.LogTrace($"Using new bundled module path: {hostStartupInfo.BundledModulePath}"); + logger.LogDebug($"Using new bundled module path: {hostStartupInfo.BundledModulePath}"); s_bundledModulePath = hostStartupInfo.BundledModulePath; } @@ -238,7 +237,6 @@ public static PowerShellContextService Create( hostUserInterface, logger); - logger.LogTrace("Creating initial PowerShell runspace"); Runspace initialRunspace = PowerShellContextService.CreateRunspace(psHost, hostStartupInfo.InitialSessionState); powerShellContext.Initialize(hostStartupInfo.ProfilePaths, initialRunspace, true, hostUserInterface); powerShellContext.ImportCommandsModuleAsync(); @@ -327,7 +325,6 @@ public void Initialize( IHostOutput consoleHost) { Validate.IsNotNull("initialRunspace", initialRunspace); - this.logger.LogTrace($"Initializing PowerShell context with runspace {initialRunspace.Name}"); this.ownsInitialRunspace = ownsInitialRunspace; this.SessionState = PowerShellContextState.NotStarted; @@ -363,6 +360,7 @@ public void Initialize( } else { + // TODO: Also throw for PowerShell 6 throw new NotSupportedException( "This computer has an unsupported version of PowerShell installed: " + powerShellVersion.ToString()); @@ -577,10 +575,9 @@ public Task> ExecuteCommandAsync( cancellationToken); } - /// /// Executes a PSCommand against the session's runspace and returns - /// a collection of results of the expected type. + /// a collection of results of the expected type. This function needs help. /// /// The expected result type. /// The PSCommand to be executed. @@ -601,8 +598,6 @@ public async Task> ExecuteCommandAsync( Validate.IsNotNull(nameof(psCommand), psCommand); Validate.IsNotNull(nameof(executionOptions), executionOptions); - this.logger.LogTrace($"Attempting to execute command(s): {GetStringForPSCommand(psCommand)}"); - // Add history to PSReadLine before cancelling, otherwise it will be restored as the // cancelled prompt when it's called again. if (executionOptions.AddToHistory) @@ -636,8 +631,6 @@ public async Task> ExecuteCommandAsync( this.ShouldExecuteWithEventing(executionOptions) || (PromptNest.IsRemote && executionOptions.IsReadLine))) { - this.logger.LogTrace("Passing command execution to pipeline thread"); - if (shouldCancelReadLine && PromptNest.IsReadLineBusy()) { // If a ReadLine pipeline is running in the debugger then we'll stop responding here @@ -715,6 +708,7 @@ public async Task> ExecuteCommandAsync( } try { + this.logger.LogTrace($"Executing in debugger: {GetStringForPSCommand(psCommand)}"); return this.ExecuteCommandInDebugger( psCommand, executionOptions.WriteOutputToHost); @@ -742,8 +736,6 @@ public async Task> ExecuteCommandAsync( AddToHistory = executionOptions.AddToHistory }; - this.logger.LogTrace("Passing to PowerShell"); - PowerShell shell = this.PromptNest.GetPowerShell(executionOptions.IsReadLine); // Due to the following PowerShell bug, we can't just assign shell.Commands to psCommand @@ -767,6 +759,8 @@ public async Task> ExecuteCommandAsync( : this.CurrentRunspace.Runspace; try { + this.logger.LogDebug($"Invoking: {GetStringForPSCommand(psCommand)}"); + // Nested PowerShell instances can't be invoked asynchronously. This occurs // in nested prompts and pipeline requests from eventing. if (shell.IsNested) @@ -835,15 +829,11 @@ public async Task> ExecuteCommandAsync( hadErrors = true; } - else - { - this.logger.LogTrace("Execution completed successfully"); - } } } catch (PSRemotingDataStructureException e) { - this.logger.LogHandledException("Pipeline stopped while executing command", e); + this.logger.LogHandledException("PSRemotingDataStructure exception while executing command", e); errorMessages?.Append(e.Message); } catch (PipelineStoppedException e) @@ -1088,7 +1078,7 @@ public async Task ExecuteScriptWithArgsAsync(string script, string arguments = n .FirstOrDefault() .ProviderPath; - this.logger.LogTrace($"Prepending working directory {workingDir} to script path {script}"); + this.logger.LogDebug($"Prepending working directory {workingDir} to script path {script}"); script = Path.Combine(workingDir, script); } catch (System.Management.Automation.DriveNotFoundException e) @@ -1120,7 +1110,6 @@ public async Task ExecuteScriptWithArgsAsync(string script, string arguments = n strBld.Append(' ').Append(arguments); var launchedScript = strBld.ToString(); - this.logger.LogTrace($"Launch script is: {launchedScript}"); command.AddScript(launchedScript, false); } @@ -1262,6 +1251,8 @@ public void AbortExecution() /// public void AbortExecution(bool shouldAbortDebugSession) { + this.logger.LogTrace("Execution abort requested..."); + if (this.SessionState == PowerShellContextState.Aborting || this.SessionState == PowerShellContextState.Disposed) { @@ -1269,8 +1260,6 @@ public void AbortExecution(bool shouldAbortDebugSession) return; } - this.logger.LogTrace("Execution abort requested..."); - if (shouldAbortDebugSession) { this.ExitAllNestedPrompts(); @@ -1416,7 +1405,7 @@ private void ResumeDebugger(DebuggerResumeAction resumeAction, bool shouldWaitFo /// public void Close() { - logger.LogDebug("Closing PowerShellContextService..."); + logger.LogTrace("Closing PowerShellContextService..."); this.PromptNest.Dispose(); this.SessionState = PowerShellContextState.Disposed; @@ -1854,13 +1843,7 @@ private void OnSessionStateChanged(object sender, SessionStateChangedEventArgs e { if (this.SessionState != PowerShellContextState.Disposed) { - this.logger.LogTrace( - string.Format( - "Session state changed --\r\n\r\n Old state: {0}\r\n New state: {1}\r\n Result: {2}", - this.SessionState.ToString(), - e.NewSessionState.ToString(), - e.ExecutionResult)); - + this.logger.LogTrace($"Session state was: {SessionState}, is now: {e.NewSessionState}, result: {e.ExecutionResult}"); this.SessionState = e.NewSessionState; this.SessionStateChanged?.Invoke(sender, e); } @@ -1906,8 +1889,6 @@ private void OnExecutionStatusChanged( /// private void PowerShellContext_RunspaceChangedAsync(object sender, RunspaceChangedEventArgs e) { - this.logger.LogTrace("Sending runspaceChanged notification"); - _languageServer?.SendNotification( "powerShell/runspaceChanged", new MinifiedRunspaceDetails(e.NewRunspace)); @@ -1952,8 +1933,6 @@ public MinifiedRunspaceDetails(RunspaceDetails eventArgs) /// details of the execution status change private void PowerShellContext_ExecutionStatusChangedAsync(object sender, ExecutionStatusChangedEventArgs e) { - this.logger.LogTrace("Sending executionStatusChanged notification"); - // The cancelling of the prompt (PSReadLine) causes an ExecutionStatus.Aborted to be sent after every // actual execution (ExecutionStatus.Running) on the pipeline. We ignore that event since it's counterintuitive to // the goal of this method which is to send updates when the pipeline is actually running something. @@ -1973,8 +1952,6 @@ private void PowerShellContext_ExecutionStatusChangedAsync(object sender, Execut private IEnumerable ExecuteCommandInDebugger(PSCommand psCommand, bool sendOutputToHost) { - this.logger.LogTrace($"Attempting to execute command(s) in the debugger: {GetStringForPSCommand(psCommand)}"); - IEnumerable output = this.versionSpecificOperations.ExecuteCommandInDebugger( this, From 1b362fb88874b547b6e6a4aab4b37bfa75c708b0 Mon Sep 17 00:00:00 2001 From: Andrew Schwartzmeyer Date: Fri, 3 Sep 2021 14:24:51 -0700 Subject: [PATCH 3/3] Clean up tests in `DebugServiceTests.cs` --- .editorconfig | 1 + .../DebugAdapterProtocolMessageTests.cs | 7 +------ .../Debugging/DebugServiceTests.cs | 12 +++++------- 3 files changed, 7 insertions(+), 13 deletions(-) diff --git a/.editorconfig b/.editorconfig index 7e3c08d9a..ae44026f5 100644 --- a/.editorconfig +++ b/.editorconfig @@ -12,6 +12,7 @@ indent_size = 4 trim_trailing_whitespace = true csharp_space_before_open_square_brackets = true csharp_space_after_keywords_in_control_flow_statements = true +csharp_space_before_open_square_brackets = false # CS0168: The variable 'var' is declared but never used dotnet_diagnostic.CS0168.severity = error diff --git a/test/PowerShellEditorServices.Test.E2E/DebugAdapterProtocolMessageTests.cs b/test/PowerShellEditorServices.Test.E2E/DebugAdapterProtocolMessageTests.cs index 6e23abff2..bf8b193cc 100644 --- a/test/PowerShellEditorServices.Test.E2E/DebugAdapterProtocolMessageTests.cs +++ b/test/PowerShellEditorServices.Test.E2E/DebugAdapterProtocolMessageTests.cs @@ -260,12 +260,7 @@ public async Task CanStepPastSystemWindowsForms() new SetFunctionBreakpointsArguments { Breakpoints = new FunctionBreakpoint[] - { - new FunctionBreakpoint - { - Name = "Write-Host", - } - } + { new FunctionBreakpoint { Name = "Write-Host", } } }).ConfigureAwait(false); var breakpoint = setBreakpointsResponse.Breakpoints.First(); diff --git a/test/PowerShellEditorServices.Test/Debugging/DebugServiceTests.cs b/test/PowerShellEditorServices.Test/Debugging/DebugServiceTests.cs index f743ab255..42386192c 100644 --- a/test/PowerShellEditorServices.Test/Debugging/DebugServiceTests.cs +++ b/test/PowerShellEditorServices.Test/Debugging/DebugServiceTests.cs @@ -114,7 +114,7 @@ await this.debugService.SetCommandBreakpointsAsync( await executeTask.ConfigureAwait(false); StackFrameDetails[] stackFrames = debugService.GetStackFrames(); - Assert.Equal(StackFrameDetails.NoFileScriptPath, stackFrames [0].ScriptPath); + Assert.Equal(StackFrameDetails.NoFileScriptPath, stackFrames[0].ScriptPath); VariableDetailsBase[] variables = debugService.GetVariables(stackFrames[0].LocalVariables.Id); @@ -151,7 +151,7 @@ public async Task DebuggerAcceptsScriptArgs(string[] args) await this.debugService.SetLineBreakpointsAsync( debugWithParamsFile, - new [] { BreakpointDetails.Create(debugWithParamsFile.FilePath, 3) }).ConfigureAwait(false); + new[] { BreakpointDetails.Create(debugWithParamsFile.FilePath, 3) }).ConfigureAwait(false); string arguments = string.Join(" ", args); @@ -580,8 +580,6 @@ await this.AssertStateChange( PowerShellContextState.Ready, PowerShellExecutionResult.Stopped).ConfigureAwait(false); - // Abort script execution early and wait for completion - this.debugService.Abort(); await executeTask.ConfigureAwait(false); } @@ -872,7 +870,7 @@ await this.debugService.SetLineBreakpointsAsync( Assert.Equal("[1]", childVars[1].Name); var childVarStrs = new HashSet(childVars.Select(v => v.ValueString)); - var expectedVars = new [] { + var expectedVars = new[] { "[firstChild, \"Child\"]", "[secondChild, 42]" }; @@ -1026,7 +1024,7 @@ await this.debugService.SetLineBreakpointsAsync( await executeTask.ConfigureAwait(false); } - public async Task AssertDebuggerPaused() + private async Task AssertDebuggerPaused() { DebuggerStoppedEventArgs eventArgs = await this.debuggerStoppedQueue.DequeueAsync(new CancellationTokenSource(10000).Token).ConfigureAwait(false); @@ -1034,7 +1032,7 @@ public async Task AssertDebuggerPaused() Assert.Empty(eventArgs.OriginalEvent.Breakpoints); } - public async Task AssertDebuggerStopped( + private async Task AssertDebuggerStopped( string scriptPath, int lineNumber = -1) {