Script output does not get written to the debug console #284

pcgeek86 · 2016-09-07T16:11:59Z

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

The text was updated successfully, but these errors were encountered:

daviwil · 2016-09-07T16:59:33Z

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: PowerShell/PowerShellEditorServices#138

pcgeek86 · 2016-09-07T18:43:57Z

@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 · 2016-09-07T21:31:05Z

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

daviwil · 2016-09-07T21:38:36Z

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):

#243 (comment)

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

bughit · 2016-09-07T22:16:18Z

Is it the script output issue that's blocking you

yes

GHRoss · 2016-10-02T12:52:51Z

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

daviwil · 2016-10-02T14:33:59Z

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 · 2016-10-08T19:10:59Z

Awesome, thanks David.

sba923 · 2016-11-17T21:05:20Z

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 · 2016-11-25T16:57:53Z

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

sba923 · 2016-11-25T19:55:25Z

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

rkeithhill · 2016-11-25T19:56:29Z

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

pcgeek86 · 2016-11-28T15:45:40Z

@daviwil any ETA on the fix for this?

daviwil · 2016-11-28T15:53:51Z

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

pcgeek86 · 2016-11-28T16:09:08Z

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

RobertBernstein · 2016-11-28T17:10:50Z

Thanks, @daviwil!

This change fixes an issue where script output for very small scripts is not being written out reliably before the debug adapter terminates. The fix is to add an extra output flush before sending the TerminatedEvent back to the client. This fix is temporary until we get the REPL integration online. Resolves #138. Resolves PowerShell/vscode-powershell#284.

daviwil · 2016-11-29T15:40:00Z

I've got a fix for this, it'll definitely be in 0.8.0: PowerShell/PowerShellEditorServices#306

GHRoss · 2016-11-29T16:02:32Z

Can we test somehow?

daviwil · 2016-11-29T16:10:35Z

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

GHRoss · 2016-11-29T16:24:19Z

Cool, where would I be able to find this?

daviwil · 2016-11-29T17:08:37Z

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

daviwil · 2016-11-29T20:21:55Z

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 · 2016-11-29T21:56:55Z

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

ConstantineK · 2016-11-29T22:01:21Z

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

daviwil · 2016-11-29T22:02:24Z

Cool! Let me know how it goes :)

sba923 · 2016-11-29T22:04:18Z

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 · 2016-11-29T22:09:15Z

@sba923 thanks for letting me know! Keep me posted

rkeithhill · 2016-11-29T22:47:30Z

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 · 2016-11-29T23:31:34Z

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

rkeithhill · 2016-11-29T23:51:01Z

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

GHRoss · 2016-11-30T11:11:06Z

Works for me, thanks David.

Does this build include any other fixes?

daviwil · 2016-11-30T15:04:05Z

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 · 2016-11-30T15:06:52Z

That's awesome actually.

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

daviwil · 2016-11-30T15:13:19Z

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 · 2016-11-30T15:35:22Z

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 · 2016-11-30T16:11:58Z

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 · 2016-12-01T16:42:53Z

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

daviwil added the Issue-Bug A bug to squash. label Sep 7, 2016

daviwil added this to the 0.8.0 milestone Sep 7, 2016

daviwil changed the title ~~Inconsistent results in VSCode Debug Console~~ Output does not flush reliably in the debug console Sep 7, 2016

daviwil changed the title ~~Output does not flush reliably in the debug console~~ Script output does not flush to the debug console reliably Sep 7, 2016

daviwil modified the milestones: 0.7.3, 0.8.0 Sep 8, 2016

daviwil mentioned this issue Sep 10, 2016

Debug adapter process has terminated unexpectedly #243

Closed

daviwil modified the milestones: 0.8.0, 0.7.3 Sep 20, 2016

daviwil mentioned this issue Sep 20, 2016

Output not displaying in Debug Console for Powershell #299

Closed

rkeithhill mentioned this issue Oct 5, 2016

No Debug Console output when no breakpoint set on script #309

Closed

daviwil mentioned this issue Oct 25, 2016

Powershell last statement output not seen #326

Closed

daviwil mentioned this issue Nov 18, 2016

Powershell Plugin - Inconsistent Debug Console Output #332

Closed

daviwil changed the title ~~Script output does not flush to the debug console reliably~~ Script output does not get written to the debug console Nov 29, 2016

daviwil mentioned this issue Nov 29, 2016

Powershell write-output does not write to debug console microsoft/vscode#16176

Closed

daviwil mentioned this issue Nov 29, 2016

Fix issue with debugger output not being written for short scripts PowerShell/PowerShellEditorServices#306

Merged

daviwil closed this as completed in PowerShell/PowerShellEditorServices#306 Nov 29, 2016

This was referenced Dec 2, 2016

Debug Console Output #355

Closed

Add troubleshooting note about slow IntelliSense results in PowerShell v5 #361

Closed

Unable to see Write-Host output #363

Closed

Script output does not get written to the debug console #284

Script output does not get written to the debug console #284

Comments

pcgeek86 commented Sep 7, 2016

System Details

Issue Description

Reproduction Steps

daviwil commented Sep 7, 2016

pcgeek86 commented Sep 7, 2016

bughit commented Sep 7, 2016

daviwil commented Sep 7, 2016

bughit commented Sep 7, 2016 • edited Loading

GHRoss commented Oct 2, 2016

daviwil commented Oct 2, 2016

GHRoss commented Oct 8, 2016

sba923 commented Nov 17, 2016

RobertBernstein commented Nov 25, 2016

sba923 commented Nov 25, 2016

rkeithhill commented Nov 25, 2016

pcgeek86 commented Nov 28, 2016

daviwil commented Nov 28, 2016

pcgeek86 commented Nov 28, 2016

RobertBernstein commented Nov 28, 2016

daviwil commented Nov 29, 2016

GHRoss commented Nov 29, 2016

daviwil commented Nov 29, 2016

GHRoss commented Nov 29, 2016

daviwil commented Nov 29, 2016

daviwil commented Nov 29, 2016

daviwil commented Nov 29, 2016

ConstantineK commented Nov 29, 2016

daviwil commented Nov 29, 2016

sba923 commented Nov 29, 2016

daviwil commented Nov 29, 2016

rkeithhill commented Nov 29, 2016

daviwil commented Nov 29, 2016

rkeithhill commented Nov 29, 2016

GHRoss commented Nov 30, 2016

daviwil commented Nov 30, 2016

GHRoss commented Nov 30, 2016

daviwil commented Nov 30, 2016

GHRoss commented Nov 30, 2016

ozu945 commented Nov 30, 2016

ConstantineK commented Dec 1, 2016

bughit commented Sep 7, 2016 •

edited

Loading