Revamp pipeline thread handling

SeeminglyScience commented 4 years ago

A lot of the problems we face is based around handling of the pipeline thread. In order to invoke something on it, we need to interact with the PowerShell class, making us invoke at least a small bit of script in most cases. The reason for this is that the actual thread used by PowerShell is internal to the runspace by default. The only way to access it is to invoke a command of some sort.

This is the default experience, but we can change it. Runspace has a property called ThreadOptions. One of the choices for that enum is UseCurrentThread. So what we can do is start our own thread, create the runspace there with that option, and never give up that thread.

One of the biggest wins here would be that we could call PSConsoleReadLine.ReadLine directly without having to invoke something. We could also ditch using the thread pool to wait for PowerShell.Invoke to finish (which probably causes some dead locks). We could get rid of a lot of the more complicated code in PowerShellContext.

I'm pretty confident that if this doesn't outright solve a lot of the sluggishness and dead locks, it'll at the very least be significantly easier to debug.

~~The rest of this post is taken from #980 since the idea is the same:~~ Nvm, just look at @rjmholt's code and the rest of conversation. The linked post is pretty outdated.

PaulHigin commented 4 years ago

I see. Yes the Debugger.ProcessCommand() does not write to the pipeline, and instead writes to the output collection object (PSDataCollection) provided. This was to support nested and remote debugging. You can stream to the host pipeline by adding a handler to the PSDataCollection.DataAdded event of the output collection provided to ProcessCommand().

SeeminglyScience commented 4 years ago

Oh I missed the other questions my bad. Yeah +1 to what @PaulHigin said. We swap in Out-String -Stream so we can write directly to host on the DataAdded event raise, basically pretending to be Out-Default. Far from perfect but it works.

I think it's mostly safe to assume that:

PSES is basically the primary external debugger implementation for PowerShell

For any hosts that are out there trying to implement remote debugging, there will be so few and it represents enough work that it's better for us to break them and help them fix it

FWIW I think this is only the case because it's currently impossible (without reflection) to take control away from the host here. Whoever adds an event handler first wins, so you aren't going to see any custom debuggers unless they're also implementing a whole host and spinning up a new runspace.

rjmholt commented 4 years ago

Ok, I now have a simple debug REPL, but:

I assume I need to create a nested PowerShell instance to use it -- I think I can't create new commands otherwise because the debugged command is still running
The Out-String trick in the REPL hasn't picked up formatting, and I'm not sure why yet

I'm not working on this today, but that second part is where I'll pick back up

SeeminglyScience commented 4 years ago

Oops forgot to reply again. If I ever don't reply within a day feel free to ping me (or dm on discord whenever), I probably just got distracted.

I assume I need to create a nested PowerShell instance to use it -- I think I can't create new commands otherwise because the debugged command is still running

Yeah depending on what you want. If it's a REPL evaluate (and most other things) you want to use ProcessCommand. I think PSRL you want to used a normal nested instance though.

The Out-String trick in the REPL hasn't picked up formatting, and I'm not sure why yet

Yeah... formatting is super finicky there. iirc ConsoleHost does the same thing. Maybe we can inject InvokeCommand.GetCmdletByTypeName(typeof(FormatDefaultCommand).FullName in there if we need to. But yeah I'm pretty sure that's a problem everywhere? Not 100% there, worth checking.

rjmholt commented 4 years ago

So I fixed the Out-String thing -- I wasn't sending in the right PSCommand object. Fixed in the latest commit.

Now trying to deal with debugger commands.

In particular it's not clear:

What q should do, since the debugger doesn't automatically handle it. It seems like I need to cancel the currently running parent command?
Whether other debugger commands are handled automatically at all...

rjmholt commented 4 years ago

I think PSRL you want to used a normal nested instance though.

Oh, good advice...

EDIT: Turns out this is a delegate already, so no need

SeeminglyScience commented 4 years ago

What q should do, since the debugger doesn't automatically handle it. It seems like I need to cancel the currently running parent command?

Doesn't it throw TerminateException? iirc you're supposed to just let that propagate and that'll get you out of the paused command.

PaulHigin commented 4 years ago

The q or quit debugger command should stop the running script, to be consistent with command line experience. It should already be implemented in the engine script debugger. The d or detach debugger command was added to work with Debug-Runspace, so that the attached debugger can be removed and allow the runspace script to continue running without any debugger interaction.

rjmholt commented 4 years ago

So currently I execute a command like this:

            if (_executionOptions.WriteOutputToHost)
            {
                _psCommand.AddDebugOutputCommand();

                // Use an inline delegate here, since otherwise we need a cast -- allocation < cast
                outputCollection.DataAdded += (object sender, DataAddedEventArgs args) =>
                    {
                        for (int i = args.Index; i < outputCollection.Count; i++)
                        {
                            _psHost.UI.WriteLine(outputCollection[i].ToString());
                        }
                    };
            }

            DebuggerCommandResults debuggerResult = _pwsh.Runspace.Debugger.ProcessCommand(_psCommand, outputCollection);

When the debug command is an ordinary PowerShell command (like gci) or l everything works fine. But s or q don't do anything special, they just set the DebuggerResumeAction on the returned DebuggerCommandResults object.

To what extent must I implement the behaviour there? Or is there a way to get all the default behaviours to work as I expect? If more should be automatically happening for me, I'm not sure how to set that up or hook into it...

SeeminglyScience commented 4 years ago

@rjmholt you need to use them to set DebuggerStopEventArgs.ResumeAction

rjmholt commented 4 years ago

Ok that works really well. I'm just missing the nice sequence point extent output that I get in the conhost:

C:\Users\Robert Holt\Documents\Dev\Microsoft\PowerShellEditorServices [async-ps-consumer +0 ~1 -0 !] [DBG]>> s
At C:\Users\Robert Holt\Documents\Dev\sandbox\debug.ps1:3 char:5
+     Write-Host 1
+     ~~~~~~~~~~~~

Is there an easy way to get that?

rjmholt commented 4 years ago

Also @PaulHigin you might prefer to unsubscribe from this issue if you don't want to be spammed by my updates in it, and I can just @-mention you when needed instead

SeeminglyScience commented 4 years ago

Ok that works really well. I'm just missing the nice sequence point extent output that I get in the conhost:
C:\Users\Robert Holt\Documents\Dev\Microsoft\PowerShellEditorServices [async-ps-consumer +0 ~1 -0 !] [DBG]>> s
At C:\Users\Robert Holt\Documents\Dev\sandbox\debug.ps1:3 char:5
+     Write-Host 1
+     ~~~~~~~~~~~~
Is there an easy way to get that?

In the editor we don't do that since the extent gets highlighted in the editor pane. If we did want it though, (or more likely for the poor soul reading this thread to implement a host from scratch) using this code in PowerShell/PowerShell is pretty straight forward.

Including inline for posterity (click to expand)

(`e` is `DebuggerStopEventArgs`) ```csharp // Display the banner only once per session // if (_displayDebuggerBanner) { WriteDebuggerMessage(ConsoleHostStrings.EnteringDebugger); WriteDebuggerMessage(string.Empty); _displayDebuggerBanner = false; } // // If we hit a breakpoint output its info // if (e.Breakpoints.Count > 0) { string format = ConsoleHostStrings.HitBreakpoint; foreach (Breakpoint breakpoint in e.Breakpoints) { WriteDebuggerMessage(string.Format(CultureInfo.CurrentCulture, format, breakpoint)); } WriteDebuggerMessage(string.Empty); } // // Write the source line // if (e.InvocationInfo != null) { // line = StringUtil.Format(ConsoleHostStrings.DebuggerSourceCodeFormat, scriptFileName, e.InvocationInfo.ScriptLineNumber, e.InvocationInfo.Line); WriteDebuggerMessage(e.InvocationInfo.PositionMessage); } ``` ```csharp ///

/// Writes a line using the debugger colors. ///

private void WriteDebuggerMessage(string line) { this.ui.WriteLine(this.ui.DebugForegroundColor, this.ui.DebugBackgroundColor, line); } ``` And the resource strings: ```xml Entering debug mode. Use h or ? for help. Hit {0} ```

rjmholt commented 4 years ago

In the editor we don't do that since the extent gets highlighted in the editor pane

Ah good point. Need to hook that up now

rjmholt commented 4 years ago

Ok, I have local debugging working in the prompt, but to hook it up to VSCode again, I need to make remoting sessions work so that I don't throw all the remoting abstractions away just to bring them back.

So now I'm working on remoting, and I can enter a remoting session and even execute a single command, but the prompt doesn't work like it should and completions soon peter out as well.

Some things that I think I need more info on are:

How do we call PSReadLine today, what's done to make it work with remoting?
Are there any other special things we need to do for remoting beyond the host's runspace stuff?

rjmholt commented 4 years ago

Ok, so I'm hitting an issue in completions where remoting doesn't return a CommandInfo object, but instead a deserialised object:

remotecompletion

I'm confused about how this wasn't an issue previously... Is there a way to handle this without changing all the call sites?

rjmholt commented 4 years ago

Here's the current invocation:

https://github.com/PowerShell/PowerShellEditorServices/blob/13ea3db5164ba9c1a50f17be8a284277fc5a0f4d/src/PowerShellEditorServices/Services/PowerShellContext/Utilities/CommandHelpers.cs#L93-L96

Here's my version:

https://github.com/rjmholt/PowerShellEditorServices/blob/11b75dc30f1b3014e56bf6ebb03ff04f26965534/src/PowerShellEditorServices/Services/PowerShellContext/Utilities/CommandHelpers.cs#L97-L102

rjmholt commented 4 years ago

I'm also experiencing a freeze when I try to exit out of remoting. The debugger shows the pipeline execution thread still on the PowerShell.Invoke() call. I'll see if I can delve deeper

rjmholt commented 4 years ago

Ok I've fixed both of these

rjmholt commented 4 years ago

Next problem: the prompt I get doesn't reflect my remote session (I just execute prompt in the remote session, so no surprise there). Does prompt have a mechanism for this, or do we need to construct it ourselves?

SeeminglyScience commented 4 years ago

Next problem: the prompt I get doesn't reflect my remote session (I just execute prompt in the remote session, so no surprise there). Does prompt have a mechanism for this, or do we need to construct it ourselves?

Nah that's us:

https://github.com/PowerShell/PowerShellEditorServices/blob/13ea3db5164ba9c1a50f17be8a284277fc5a0f4d/src/PowerShellEditorServices/Services/PowerShellContext/Session/Host/EditorServicesPSHostUserInterface.cs#L752-L762

rjmholt commented 4 years ago

This looks promising too:

https://github.com/PowerShell/PowerShell/blob/58c371ca31d9e1b72da5d94821f2d670da5b4dfa/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHost.cs#L2796-L2800

rjmholt commented 4 years ago

Ok I actually just reuse PowerShell's own method using reflection now

remoteprompt

rjmholt commented 4 years ago

Right, now left on the agenda are:

Debugging while remoting -- what happens here? Do we nest a debug prompt within the remote runspace as normal, or is there something else we need to take note of?
Then hook up the debugger to VSCode's debugger
Hook remoting into our UI to set the correct version string
Hook the executing UI up
Then look at PS eventing again -- see if it now works with PSRL or otherwise what we can do
Then deal with prompt colours
Then multihop remoting
Then put the legacy readline implementation back...?
DSC support

Anything I've left out?

rjmholt commented 4 years ago

So when trying to push a new runspace when a remote session drops into the debugger, neither PowerShell.CreateNestedPowerShell() or PowerShell.Create(RunspaceMode.CurrentRunspace) does the right thing.

I see in the existing code, when the session is remote a simple PowerShell.Create() is used. Do I just let it create a new runspace, or do I need to attach the remote runspace back to it again?

SeeminglyScience commented 4 years ago

I see in the existing code, when the session is remote a simple PowerShell.Create() is used. Do I just let it create a new runspace, or do I need to attach the remote runspace back to it again?

I thought if it dropped into the debugger you still use Debugger.ProcessCommand, on the remote runspace's Debugger instance. If not though, yeah attach it with the PowerShell.Runspace property. PowerShell.Create will only create a new runspace if it's invoked before that property is assigned to.

rjmholt commented 4 years ago

Ok, I've been battling this since my last post, but I'm hitting an issue where, in the remote debugger, the prompt is racing output. So the prompt prints before the debugged script's output can:

remotedebug

The strange thing is:

This doesn't occur for local debugging
We only push a debug REPL from OnDebuggerStopped(), so otherwise the REPL should not be running

Is there any chance that writing to the host from a remote session has some special behaviour or hook I should be waiting for? /cc @PaulHigin

PaulHigin commented 4 years ago

-- the prompt is racing output.

Yeah, this has always been a problem with remote debugging, and is a conflict between how script debugging and remoting works. I tried to fix the problem here, but with limited success.

rjmholt commented 4 years ago

From my logpoints, the sequence is as I expect:

TASK: Complete {ReadLine} with result "s"
TASK: Run {s}
DEBUG: Set resuming
REPL {39b2b929-b9df-491b-98c8-a189e3f8ef78}: cancelled
TASK: Complete {s | Out-String -Stream True} with result {System.Management.Automation.PSObject[0]}
REPL CANCELLED {39b2b929-b9df-491b-98c8-a189e3f8ef78}
REPL {39b2b929-b9df-491b-98c8-a189e3f8ef78}: ended
DEBUG: Ending loop
DEBUG: Stopped
REPL {95635f00-19e7-449b-924e-6eb9823a7ff4}: started
TASK: Run {prompt}
TASK: Complete {prompt} with result Count = 1
REPL {95635f00-19e7-449b-924e-6eb9823a7ff4}: write prompt
REPL {95635f00-19e7-449b-924e-6eb9823a7ff4} invoking readline

I know these are meaningless without context, but basically Debug: stopped is when the new DebuggerStopped event is raised. You can see we've processed the previous command, cancelled and ended the debug REPL and finished handling debugging before handling anything from the new event.

Given that we wait properly for the event and the internal implementation is supposed to block like this, is it possible there's something I'm doing wrong here? Is there some call that will block until this is done, or maybe an event or a boolean or something?

I'm very reluctant to just put a sleep in, since there could be an arbitrary amount of output before the next debugger stop. And I don't think shipping the remote debugging experience as it is is an option; it just feels quite broken.

PaulHigin commented 4 years ago

Yeah, I struggled with the same thing. I don't know why it would be worse here, unless there are more delays due to more complexity? But the only real way to fix this is to separate debug output from prompt and command input, to match how the remoting system works. That is not possible with a command shell, but can work for IDEs.

rjmholt commented 4 years ago

Ok I think this is actually my bug. It's just a question of where and how.

rjmholt commented 4 years ago

Stepping through in the debugger, the prompt function is called from the REPL thread as I expect, executed as a callback by the remoting session, and then written to the UI.

After that, the pending callback service queue dequeues the call to write the output to the UI and calls that on the PSES host UI object:

    Microsoft.PowerShell.EditorServices.dll!Microsoft.PowerShell.EditorServices.Services.PowerShell.Host.EditorServicesConsolePSHostUserInterface.WriteLine(string value) Line 116  C#
    System.Management.Automation.dll!System.Management.Automation.Internal.Host.InternalHostUserInterface.WriteLine(string value) Line 266  C#
    [External Code] 
    System.Management.Automation.dll!System.Management.Automation.Remoting.RemoteHostCall.ExecuteVoidMethod(System.Management.Automation.Host.PSHost clientHost) Line 187   C#
    System.Management.Automation.dll!System.Management.Automation.Runspaces.Internal.ClientRemotePowerShell.ExecuteHostCall(System.Management.Automation.Remoting.RemoteHostCall hostcall) Line 686 C#
    System.Management.Automation.dll!System.Management.Automation.Runspaces.Internal.ClientRemotePowerShell.HandleHostCallReceived(object sender, System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.Remoting.RemoteHostCall> eventArgs) Line 600    C#
    System.Management.Automation.dll!System.Management.Automation.ExtensionMethods.SafeInvoke<System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.Remoting.RemoteHostCall>>(System.EventHandler<System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.Remoting.RemoteHostCall>> eventHandler, object sender, System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.Remoting.RemoteHostCall> eventArgs) Line 25    C#
    System.Management.Automation.dll!System.Management.Automation.Internal.ClientPowerShellDataStructureHandler.ProcessReceivedData(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> receivedData) Line 1325   C#
    System.Management.Automation.dll!System.Management.Automation.Internal.ClientRunspacePoolDataStructureHandler.DispatchMessageToPowerShell(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> rcvdData) Line 280  C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.ClientRemoteSessionDSHandlerImpl.ProcessNonSessionMessages(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> rcvdData) Line 728  C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.ClientRemoteSessionDSHandlerImpl.DispatchInputQueueData(object sender, System.Management.Automation.RemoteDataEventArgs dataArg) Line 583    C#
    System.Management.Automation.dll!System.Management.Automation.ExtensionMethods.SafeInvoke<System.Management.Automation.RemoteDataEventArgs>(System.EventHandler<System.Management.Automation.RemoteDataEventArgs> eventHandler, object sender, System.Management.Automation.RemoteDataEventArgs eventArgs) Line 25  C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.BaseTransportManager.OnDataAvailableCallback(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> remoteObject) Line 345    C#
>   System.Management.Automation.dll!System.Management.Automation.Remoting.Client.BaseClientTransportManager.ServicePendingCallbacks(object objectToProcess) Line 843   C#
    System.Management.Automation.dll!System.Management.Automation.Utils.WorkItemCallback(object callBackArgs) Line 1522 C#

The problem is that the output written in the second callback is something I want synchronously...

In fact it doesn't seem to be added to my PSDataCollection that I hand to Debugger.ProcessCommand, so I can't get to it to print it synchronously (my code already does that, but the my printing callback is never fired)

rjmholt commented 4 years ago

My execution code looks like this:

            var outputCollection = new PSDataCollection<PSObject>();

            if (_executionOptions.WriteOutputToHost)
            {
                _psCommand.AddDebugOutputCommand();

                // Use an inline delegate here, since otherwise we need a cast -- allocation < cast
                outputCollection.DataAdded += (object sender, DataAddedEventArgs args) =>
                    {
                        for (int i = args.Index; i < outputCollection.Count; i++)
                        {
                            _psHost.UI.WriteLine(outputCollection[i].ToString());
                        }
                    };
            }

            DebuggerCommandResults debuggerResult = _pwsh.Runspace.Debugger.ProcessCommand(_psCommand, outputCollection);

            _psRunspaceContext.ProcessDebuggerResult(debuggerResult);

            // Optimisation to save wasted computation if we're going to throw the output away anyway
            if (_executionOptions.WriteOutputToHost)
            {
                return Array.Empty<TResult>();
            }

The DataAdded event is never fired

rjmholt commented 4 years ago

Ok, so the bug I've found is about error handling. Cancelling the pipeline with Debugger.StopProcessCommand() when in remote debugging throws a RuntimeException with the text The pipeline has been stopped. No idea if that's supposed to happen, but it's very hard to handle properly since it's not a PipelineStoppedException. In my current code, the REPL task doesn't handle that well and limps on in a bad state. I'm intending to handle it properly when I work out whether the exception I get is what I should be getting.

But handling that error eliminates the other bug I was seeing, so it's back to why results aren't delivered back synchronously.

rjmholt commented 4 years ago

Ok, so I notice the pipeline API has some methods that the Console Host uses:

DrainIncomingData()
SuspendIncomingData()
ResumeIncomingData()

These do exactly what we need, but their equivalents in the PowerShell API are internal:

WaitForServicingComplete()
SuspendIncomingData()
ResumeIncomingData()

Looking into this more, these methods seem to be employed by the embedded debugger (for Debug-Runspace), but they're not in the callstack for my debug stop event:

    Microsoft.PowerShell.EditorServices.dll!Microsoft.PowerShell.EditorServices.Services.PowerShell.PowerShellExecutionService.OnDebuggerStopped(object sender, System.Management.Automation.DebuggerStopEventArgs debuggerStopEventArgs) Line 651  C#
    System.Management.Automation.dll!System.Management.Automation.ExtensionMethods.SafeInvoke<System.Management.Automation.DebuggerStopEventArgs>(System.EventHandler<System.Management.Automation.DebuggerStopEventArgs> eventHandler, object sender, System.Management.Automation.DebuggerStopEventArgs eventArgs) Line 25    C#
    System.Management.Automation.dll!System.Management.Automation.Debugger.RaiseDebuggerStopEvent(System.Management.Automation.DebuggerStopEventArgs args) Line 487 C#
>   System.Management.Automation.dll!System.Management.Automation.RemoteDebugger.ProcessDebuggerStopEventProc(object state) Line 2711   C#
    System.Management.Automation.dll!System.Management.Automation.Utils.WorkItemCallback(object callBackArgs) Line 1522 C#

I'm not sure if this means I'm doing something wrong, or if the API lacks something here. I'll see if I can look into how the previous implementation accomplished this.

PaulHigin commented 4 years ago

Right, I remember now. The implementation in debugger.cs is for nested debugging. But each host that supports remote debugging also needs to use the drain/suspend/resume pattern. Unfortunately, the APIs are internal access because they can easily be misused (and really are just a hack).

But I believe this is only needed for WinRM based remoting because it allows multiple channels. Currently, SSH based remoting is a single channel, and so data cannot get out of order. Have you tried this with either remoting type?

Regarding PipelineStopped exception, that has always annoyed me too, but it is by design in PowerShell when stopping a running pipeline. Unfortunately, this means having to search for that exception type in a RemoteException.

rjmholt commented 4 years ago

Ha!

remotingfixed

(I used reflection to get those methods back and turn them into extension methods)

rjmholt commented 4 years ago

For the record, I have no idea how the existing implementation didn't hit this. Perhaps it did and nobody noticed?

TylerLeonhardt commented 4 years ago

Perhaps it did and nobody noticed?

Entirely possible. I'm not sure how many folks use Enter-PSSession in the extension at all these days. We could add some telemetry there to our Remote File Manager or whatever it's called... That'd be nice.

rjmholt commented 4 years ago

I notice the stepping/sequence points aren't quite right though... Not sure what's happening there

SeeminglyScience commented 4 years ago

Yeah. That's also the type of issue where it would be very difficult for a user to articulate the problem distinctly enough that it wouldn't get lumped in with other debug issues.

Plus most use cases of Enter-PSSession in the extension are probably just gonna be so they can do psedit/get machine based intellisense.

I can tell you for sure I wouldn't have thought to test that. I didn't think it would be any different than Enter-PSHostProcess.

rjmholt commented 4 years ago

Ok so my current debug session looks like this:

[localhost]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> .\debug.ps1
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    1:* .\debug.ps1

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    2:  function WriteThings {
    3:      Write-Output 1    
    4:      Write-Output 2    
    5:  }
    6:
    7:* Write-Host 'Hi'
    8:
    9:  Wait-Debugger
   10:
   11:  WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    4:      Write-Output 2
    5:  }
    6:
    7:  Write-Host 'Hi'
    8:  
    9:* Wait-Debugger
   10:
   11:  WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
Hi
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    6:
    7:  Write-Host 'Hi'
    8:
    9:  Wait-Debugger
   10:
   11:* WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    1:
    2:* function WriteThings {
    3:      Write-Output 1
    4:      Write-Output 2
    5:  }
    6:
    7:  Write-Host 'Hi'
    8:
    9:  Wait-Debugger
   10:
   11:  WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    1:
    2:  function WriteThings {
    3:*     Write-Output 1
    4:      Write-Output 2
    5:  }
    6:
    7:  Write-Host 'Hi'
    8:
    9:  Wait-Debugger
   10:
   11:  WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    1:
    2:  function WriteThings {
    3:      Write-Output 1
    4:*     Write-Output 2
    5:  }
    6:
    7:  Write-Host 'Hi'
    8:
    9:  Wait-Debugger
   10:
   11:  WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
1
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    1:
    2:  function WriteThings {
    3:      Write-Output 1
    4:      Write-Output 2
    5:* }
    6:
    7:  Write-Host 'Hi'
    8:
    9:  Wait-Debugger
   10:
   11:  WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
2
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    8:
    9:  Wait-Debugger
   10:
   11:  WriteThings
   12:
   13:* Write-Host 'Doing'
   14:
   15:  Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

   10:
   11:  WriteThings
   12:
   13:  Write-Host 'Doing'
   14:
   15:* Write-Host 'Something'

[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> s
Doing
Something
[localhost]: [DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox>> l

    1:
    2:* "PS $($executionContext.SessionState.Path.CurrentLocation)$('>' * ($nestedPromptLevel + 1)) ";
    3:  # .Link
    4:  # https://go.microsoft.com/fwlink/?LinkID=225750
    5:  # .ExternalHelp System.Management.Automation.dll-help.xml
    6:

Two things that are wrong there:

Output is out of sequence with stepping, in particular notice how stepping over Write-Host 'Doing' outputs nothing, and then stepping over Write-Host 'Something' outputs Doing\nSomething
The debugger stop seems to fire before I enter into the script and stepping continues into the prompt function execution after it...

rjmholt commented 4 years ago

In local debugging these don't happen:

PS C:\Users\Robert Holt\Documents\Dev\sandbox> .\debug.ps1
Hi
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
1
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
2
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
Doing
[DBG]: PS C:\Users\Robert Holt\Documents\Dev\sandbox> s
Something
PS C:\Users\Robert Holt\Documents\Dev\sandbox> s

rjmholt commented 4 years ago

I think I'm willing to write that difference off for now as something occurring at the PowerShell platform level. We can try and fix it later if need be.

Moving on to cancellation, and then hooking up the UI.

PaulHigin commented 4 years ago

Yes, that is the best you are likely to do. Anyway, it was the best I could do :). The strategy on remote debugger stop is to stream all available data in the queue, and then block any more so that it doesn't overwrite the prompt. That doesn't mean all expected data was streamed. There is no way to no when the last data item arrives, and the problem is only compounded when connections go off box. But I feel this as a minor problem. Seeing pipeline data while debugging is important, but not as important as stepping through code execution and checking state.

rjmholt commented 4 years ago

Seeing pipeline data while debugging is important, but not as important as stepping through code execution and checking state.

Yeah, I think as long as l works and we can get it to highlight the right line, I'm happy enough

rjmholt commented 4 years ago

I'm currently hitting a thing where cancelling sleep 20 with Ctrl+C in a remote debugging session (into PS 5.1 over WinRM) doesn't get to fire my registered cancellation delegate. It seems like something else is intercepting the Ctrl+C, which fires OnCloseCmdCompleted():

    System.Management.Automation.dll!System.Management.Automation.Runspaces.AsyncResult.SignalWaitHandle() Line 181 C#
    System.Management.Automation.dll!System.Management.Automation.Runspaces.AsyncResult.SetAsCompleted(System.Exception exception) Line 150 C#
    System.Management.Automation.dll!System.Management.Automation.PowerShell.SetStateChanged(System.Management.Automation.PSInvocationStateInfo stateInfo) Line 4275    C#
    System.Management.Automation.dll!System.Management.Automation.Runspaces.Internal.ClientRemotePowerShell.SetStateInfo(System.Management.Automation.PSInvocationStateInfo stateInfo) Line 80  C#
    System.Management.Automation.dll!System.Management.Automation.Runspaces.Internal.ClientRemotePowerShell.HandleCloseCompleted(object sender, System.EventArgs args) Line 661 C#
    System.Management.Automation.dll!System.Management.Automation.Internal.ClientPowerShellDataStructureHandler.CloseConnectionAsync.AnonymousMethod__48_0(object source, System.EventArgs args) Line 1386  C#
    System.Management.Automation.dll!System.Management.Automation.ExtensionMethods.SafeInvoke<System.EventArgs>(System.EventHandler<System.EventArgs> eventHandler, object sender, System.EventArgs eventArgs) Line 25  C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.Client.BaseClientTransportManager.RaiseCloseCompleted() Line 566 C#
>   System.Management.Automation.dll!System.Management.Automation.Remoting.Client.WSManClientCommandTransportManager.OnCloseCmdCompleted(System.IntPtr operationContext, int flags, System.IntPtr error, System.IntPtr shellOperationHandle, System.IntPtr commandOperationHandle, System.IntPtr operationHandle, System.IntPtr data) Line 3587 C#

When this happens, the Debugger.ProcessCommand() call just returns, rather than throwing anything. I think there's at least a way to detect cancellation (by checking my cancellation token), but I'm not entirely sure that it will always work due to this race of cancellers.

The most interesting thing is that the second time I try this behaviour in the same session, my canceller does cancel the command call and gets it to throw (a RuntimeException -- so I have to check the cancellation token there too).

rjmholt commented 4 years ago

Ok here's the top of the callstack for the previous stack trace (it goes through a native callback handle in WSMan, so I had to track it down):

>   System.Management.Automation.dll!System.Management.Automation.Remoting.Client.WSManClientCommandTransportManager.CloseAsync() Line 3144 C#
    System.Management.Automation.dll!System.Management.Automation.Internal.ClientPowerShellDataStructureHandler.CloseConnectionAsync(System.Exception sessionCloseReason) Line 1392 C#
    System.Management.Automation.dll!System.Management.Automation.Runspaces.Internal.ClientRemotePowerShell.HandleInvocationStateInfoReceived(object sender, System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.PSInvocationStateInfo> eventArgs) Line 457   C#
    System.Management.Automation.dll!System.Management.Automation.ExtensionMethods.SafeInvoke<System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.PSInvocationStateInfo>>(System.EventHandler<System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.PSInvocationStateInfo>> eventHandler, object sender, System.Management.Automation.RemoteDataEventArgs<System.Management.Automation.PSInvocationStateInfo> eventArgs) Line 25  C#
    System.Management.Automation.dll!System.Management.Automation.Internal.ClientPowerShellDataStructureHandler.ProcessReceivedData(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> receivedData) Line 1223   C#
    System.Management.Automation.dll!System.Management.Automation.Internal.ClientRunspacePoolDataStructureHandler.DispatchMessageToPowerShell(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> rcvdData) Line 280  C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.ClientRemoteSessionDSHandlerImpl.ProcessNonSessionMessages(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> rcvdData) Line 728  C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.ClientRemoteSessionDSHandlerImpl.DispatchInputQueueData(object sender, System.Management.Automation.RemoteDataEventArgs dataArg) Line 583    C#
    System.Management.Automation.dll!System.Management.Automation.ExtensionMethods.SafeInvoke<System.Management.Automation.RemoteDataEventArgs>(System.EventHandler<System.Management.Automation.RemoteDataEventArgs> eventHandler, object sender, System.Management.Automation.RemoteDataEventArgs eventArgs) Line 25  C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.BaseTransportManager.OnDataAvailableCallback(System.Management.Automation.Remoting.RemoteDataObject<System.Management.Automation.PSObject> remoteObject) Line 345    C#
    System.Management.Automation.dll!System.Management.Automation.Remoting.Client.BaseClientTransportManager.ServicePendingCallbacks(object objectToProcess) Line 843   C#
    System.Management.Automation.dll!System.Management.Automation.Utils.WorkItemCallback(object callBackArgs) Line 1522 C#

So something is deciding to close the connection it seems? I feel like the cancellation must have another handler registered that's doing this, but I'm not sure what could be doing it...

rjmholt commented 4 years ago

When this happens and the connection is closed, the debug PowerShell we're using is closed too, putting us in a bad state. It's just not at all clear why CtrlC closes the connection...

PaulHigin commented 4 years ago

This is the same behavior you get in PowerShell shell remoting when you connect to older (WindowsPowerShell 5.1) endpoint. The above behavior is expected when you stop a running remote command, so it looks like older versions of PowerShell do not interpret Ctrl+C in the right debug context.

But this appears to be fixed in PowerShell 7 preview. Try connecting to that endpoint:

$s = nsn . -config powershell.7-preview

PowerShell / PowerShellEditorServices

Revamp pipeline thread handling #1295