Vscode-powershell: Script output does not get written to the debug console

[pcgeek86]

System Details

• Operating system name and version:
• VS Code version: 1.4.0
• PowerShell extension version: 0.7.2
• Output from $PSVersionTable:

PS C:\Users\TrevorSullivan> $PSVersionTable

Name                           Value
----                           -----
PSVersion                      5.1.14393.103
PSEdition                      Desktop
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0...}
BuildVersion                   10.0.14393.103
CLRVersion                     4.0.30319.42000
WSManStackVersion              3.0
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1

Issue Description

Sometimes I run a PowerShell script, and the Debug Console shows nothing.

Sometimes I run a PowerShell script, and the Debug Console shows output, but not Error stream output.

Sometimes I run a PowerShell script and the Debug Console shows output from the Output and Error streams, as expected.

This happens with both VSCode and VSCode Insiders (as of today's release).

Reproduction Steps

Inconsistent results.

Cheers,
Trevor Sullivan
Docker Captain
Microsoft MVP: Cloud & Data Center Management
https://trevorsullivan.net
https://twitter.com/pcgeek86

[daviwil]

Yep, this is a general problem with output flushing at the moment. I've got an issue filed at the PS Editor Services repo to track the work for this: https://github.com/PowerShell/PowerShellEditorServices/issues/138

[pcgeek86]

@daviwil Thanks, this is a show-stopper for VSCode. I'm using the PowerShell Console host to run tests for now, instead. Still authoring in VSCode.

[bughit]

can you make 0.6.2 available, it;s the last working verion

[daviwil]

Hey @bughit, there's a set of steps you can follow here to get back to 0.6.2 (just change the version from 0.6.1 to 0.6.2):

https://github.com/PowerShell/vscode-powershell/issues/243#issuecomment-243296211

Is it the script output issue that's blocking you or something else?

[bughit]

Is it the script output issue that's blocking you

yes

[GHRoss]

Has there been any progress made on this? It's sort of killing me.

[daviwil]

Yep! I've made huge progress with moving everything to a new model where all console activity happens directly in the real PowerShell console running in the integrated terminal. I think I'll have a new update ready in a couple weeks.

I'm really sorry this issue has been causing your trouble, soon you won't have to deal with it anymore :)

[GHRoss]

Awesome, thanks David.

[sba923]

Problem's still there with VSCode 1.7.1 (upgraded today) with version 0.7.2 of the extension...

Back to ISE for now ;-)

[RobertBernstein]

Hoping this gets fixed in VSCode v1.7.2 and v0.7.2 of the extension soon. Thanks!

[sba923]

I hate to say, but with VSCode v1.7.2 and v0.7.2 of the extension the problem's still there...

[rkeithhill]

Yes, it is still a problem. You can workaround the issue by setting a breakpoint on the last line of script that executes.

[pcgeek86]

@daviwil any ETA on the fix for this?

[daviwil]

I'm working in it this week to be included with 0.8.0. Will keep you posted!

[pcgeek86]

@daviwil Nice!! I will test and tweet about it as soon as it drops!

[RobertBernstein]

Thanks, @daviwil!

[daviwil]

I've got a fix for this, it'll definitely be in 0.8.0: https://github.com/PowerShell/PowerShellEditorServices/pull/306

[GHRoss]

Can we test somehow?

[daviwil]

I'll send out a preview build a little later today, would be nice to have folks try it out.

[GHRoss]

Cool, where would I be able to find this?

[daviwil]

I'll post it to this issue so you'll see it.

[daviwil]

OK, here's a preview package. Ignore the version number here, I'm using an arbitrarily increased version just for the purpose of sending out a preview. Also, just to be clear, USE AT YOUR OWN RISK. This build was created on my dev machine as a convenience for you guys so make sure you do the proper virus scanning, etc before you use it.

Download here: PowerShell-0.7.10.zip
IMPORTANT: After downloading this file, rename the extension from .zip to .vsix!

To install the preview, go into VS Code and run the Extensions: Install from VSIX... command then select the VSIX file that you downloaded and renamed. The extension should install, click the 'Reload' button afterward so that VS Code gets restarted. At this point you should be able to run a short script with output statements as you would expect.

This build should be stable enough to use until 0.8.0 gets released next week, but definitely file issues if you find any problems.

[daviwil]

@ConstantineK Do your reactions mean that it worked for you? :)

[ConstantineK]

Have to test in a bit, just something I have been waiting for :D

[daviwil]

Cool! Let me know how it goes :)

[sba923]

I've tested with a first, very small script of mine, works fine.

My plan is to try to stop using ISE for a while, and see what that gets me...

I'll keep you posted.

[daviwil]

@sba923 thanks for letting me know! Keep me posted

[rkeithhill]

I did manage to get it to crash:

11/29/2016 3:44:19 PM [VERBOSE] - Method "LaunchScript" at line 82 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\Server\DebugAdapter.cs

    Execution completed, flushing output then terminating...

11/29/2016 3:44:19 PM [VERBOSE] - Method "WriteMessage" at line 59 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    WRITE MESSAGE:

    {
      "type": "event",
      "event": "output",
      "body": {
        "category": "stdout",
        "output": "Done!\n8\r\n\r\nPS C:\\Users\\hillr\\.vscode\\extensions\\ms-vscode.PowerShell-0.7.10\\examples\r\n"
      }
    }

11/29/2016 3:44:19 PM [VERBOSE] - Method "WriteMessage" at line 59 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageWriter.cs

    WRITE MESSAGE:

    {
      "type": "event",
      "event": "terminated",
      "body": null
    }

11/29/2016 3:44:19 PM [NORMAL] - Method "Shutdown" at line 101 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\Server\DebugAdapter.cs

    Debug adapter is shutting down...

11/29/2016 3:44:19 PM [VERBOSE] - Method "ReadMessage" at line 111 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageReader.cs

    READ MESSAGE:

    {
      "command": "disconnect",
      "arguments": {
        "restart": false
      },
      "type": "request",
      "seq": 5
    }

11/29/2016 3:44:19 PM [VERBOSE] - Method "Shutdown" at line 57 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\Channel\TcpSocketServerChannel.cs

    TCP listener has been stopped

11/29/2016 3:44:19 PM [VERBOSE] - Method "Shutdown" at line 69 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\Channel\TcpSocketServerChannel.cs

    TCP client has been closed

11/29/2016 3:44:19 PM [NORMAL] - Method "StartDebugService" at line 172 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Host\EditorServicesHost.cs

    Previous debug session ended, restarting debug service...

11/29/2016 3:44:19 PM [ERROR] - Method "OnListenTaskCompleted" at line 334 of C:\dev\PowerShellEditorServices\src\PowerShellEditorServices.Protocol\MessageProtocol\MessageDispatcher.cs

    MessageDispatcher loop terminated due to unhandled exception:

    System.AggregateException: One or more errors occurred. ---> System.NullReferenceException: Object reference not set to an instance of an object.
       at Microsoft.PowerShell.EditorServices.Protocol.Server.DebugAdapter.HandleDisconnectRequest(Object disconnectParams, RequestContext`1 requestContext)
       at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<>c__DisplayClass25_0`2.<SetRequestHandler>b__0(Message requestMessage, MessageWriter messageWriter)
       at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<DispatchMessage>d__34.MoveNext()
    --- End of stack trace from previous location where exception was thrown ---
       at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
       at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<ListenForMessages>d__33.MoveNext()
    --- End of stack trace from previous location where exception was thrown ---
       at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
       at Microsoft.PowerShell.EditorServices.Utility.AsyncContext.Start(Func`1 asyncMainFunc)
       at Microsoft.PowerShell.EditorServices.Utility.AsyncContextThread.<>c__DisplayClass4_0.<Run>b__0()
       at System.Threading.Tasks.Task.Execute()
       --- End of inner exception stack trace ---
    ---> (Inner Exception #0) System.NullReferenceException: Object reference not set to an instance of an object.
       at Microsoft.PowerShell.EditorServices.Protocol.Server.DebugAdapter.HandleDisconnectRequest(Object disconnectParams, RequestContext`1 requestContext)
       at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<>c__DisplayClass25_0`2.<SetRequestHandler>b__0(Message requestMessage, MessageWriter messageWriter)
       at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<DispatchMessage>d__34.MoveNext()
    --- End of stack trace from previous location where exception was thrown ---
       at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
       at Microsoft.PowerShell.EditorServices.Protocol.MessageProtocol.MessageDispatcher.<ListenForMessages>d__33.MoveNext()
    --- End of stack trace from previous location where exception was thrown ---
       at System.Runtime.CompilerServices.TaskAwaiter.ThrowForNonSuccess(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
       at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
       at Microsoft.PowerShell.EditorServices.Utility.AsyncContext.Start(Func`1 asyncMainFunc)
       at Microsoft.PowerShell.EditorServices.Utility.AsyncContextThread.<>c__DisplayClass4_0.<Run>b__0()
       at System.Threading.Tasks.Task.Execute()<---

[daviwil]

@rkeithhill Consistently or just once? That seems unrelated to this change but its in an area where I've seen crashes before

[rkeithhill]

Just once. Unfortunately, I haven't been able to repro it.

[GHRoss]

Works for me, thanks David.

Does this build include any other fixes?

[daviwil]

It includes a pretty big change that improves the user-friendliness of the PowerShell integration. Most of it you won't see unless there's a problem with the extension, but you can see one change in the status bar:

Clicking this brings up this handy menu:

Would certainly appreciate some feedback :)

[GHRoss]

That's awesome actually.

My intellisense is incredibly slow, but that's always been the case. Ha.

[daviwil]

Shouldn't be slow, are you running it on a machine with limited resources (like a VM)? Was it faster in an earlier version of the extension?

[GHRoss]

I'm not, and I can't work out why it's so slow. I have to wait about 30 seconds to a minute to get any suggestions back.

[ozu945]

got the same crash as rkeithhill, twice. but now it doesn't happen again.
saw the dialog asking to restart the poweshell session, that's new.

[ConstantineK]

Having a few situations this morning where the same behavior (output not flushing) is occuring, trying to create a reproducible scenario now.