Write-Output broken

[KevinWGagel]

Prerequisites

• I have written a descriptive issue title.
• I have searched all issues to ensure it has not already been reported.
• I have read the troubleshooting guide.
• I am sure this issue is with the extension itself and does not reproduce in a standalone PowerShell instance.
• I have verified that I am using the latest version of Visual Studio Code and the PowerShell extension.
• If this is a security issue, I have read the security issue reporting guidance.

Summary

Edit: Changed title to remove "for elevated accounts" as it is now not working at all regardless of account used.

The PowerShell Extension is not starting correctly. I worked with folks over at discord who guided me through finding the issue.
Attaching diagnostic log files for review as well as screen shots of the symptoms.
Essentially I cannot get output from scripts I'm writing in VSCode in the PowerShell Extension terminal window

WARNING: In development mode but PowerShellEditorServices dev module path cannot be found (or has not been built yet): c:\Users\u598743a.vscode\extensions\PowerShellEditorServices\module

PowerShell Version

PS C:\Users\u598743a\.vscode> $PSVersionTable

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

Visual Studio Code Version

PS C:\Users\u598743a\.vscode> code --version
1.67.2
c3511e6c69bb39013c4a4b7b9566ec1ca73fc4d5
x64

Extension Version

PS C:\Users\u598743a\.vscode> code --list-extensions --show-versions | select-string powershell

[email protected]

Steps to Reproduce

Just run a script, run a code snippet and nothing gets returned.
Interestingly though if I change my code to write-host instead of write-output then I get results to the Extension's terminal.

Visuals

Logs

vscode-powershell.log
EditorServices.log
StartEditorServices.log

[KevinWGagel]

I have two domain accounts I can login with. This problem is affecting the elevated level account, not the regular account.

[andyleejordan]

Ah! That's super helpful @KevinWGagel. Also, thanks for pushing us onto further investigation, we figured out that the "development mode" problem was a red herring caused by really dumb code I wrote a few months back, but is now fixed via #3992

[KevinWGagel]

I didn't bring it up sooner because I have the executable set to launch as administrator. I do a lot of remote ps. I wanted to keep going with a script that didn't do remote ps so I switched over to regular launching and found it working. So, sorry for the extra work in the wrong direction. Glad you're getting to the bottom of it. Any idea on a timeline for a fix?

[SydneyhSmith]

@KevinWGagel thanks for the report-- we are finding time to investigate this issue...once we do that we will have a better sense of if this is fixable or not. Thanks!

[KevinWGagel]

Just wanted give an update. I've been using VS Code in my non-elevated account. Today after a bunch of debugging I had the same problem. No more output from write-output. This time it was right after I added a bunch of write-verbose statements, saved the file, then ran it in the VS Code terminal using -verbose. After all the verbose messages came through the final output which was to show the end results didn't appear. Just like what I get when I'm using an elevated VS Code session. I tried remarking the write-verbose lines to see if it would change anything. It didn't. I ran the script from an elevated PS shell with -verbose and it displayed all the verbose and the final output.

I then exited VS Code and restarted it in a non-elevated session and tried the script again - then the final output displayed as it should. I unremarked the write-verbose statements and ran it from the VS Code terminal and it continued to work as expected.

I'm wondering if there is a memory corruption of some kind that happens after a lot of runs with break points set. I often run to a break point, check some things in the terminal and then stop the script. Make whatever changes I must then try again.

[SeeminglyScience]

Thanks for the update! If that happens again in a non-elevated session can you grab the logs? Might be helpful to see a before and after

[KevinWGagel]

I will.

[KevinWGagel]

I can't get any output now. Even something as simple as get-variable is outputting nothing at all in the integrated terminal. I can't see any errors in the debug logs. I am working in a non-elevated vscode session. I've killed the terminal and had it restart, I've uninstalled vscode and deleted all the directories and re-installed and still - no output. This is making using vscode very difficult!

[KevinWGagel]

I found this in the "EditorServices.log" file.
2022-07-12 13:59:11.978 -07:00 [VRB] Could not write to output handler, perhaps serialization failed?

[KevinWGagel]

Here is a visual of what I see


.

[andyleejordan]

Interestingly I was only able to find an instance of perhaps serialization failed in my own logs; it appears to be emitted by OmniSharp itself and not PSES, and in my case is emitted after an early startup failure, which is something we just fixed. Can you double check which version of the extension you're running?

[KevinWGagel]

Version v2022.6.3

[KevinWGagel]

Updated debug log files
EditorServices.log
StartEditorServices.log
vscode-powershell.log
.

[KevinWGagel]

I have installed Powershell 7.2. Default-output seems to be working again now. I'll leave this open for a while and see how things go when I start working in ps again.

[KevinWGagel]

Well, it works perfectly with PS 7. but if I want to switch back to 5.1 for development/debugging then I'm stuck with no output again.

[KevinWGagel]

Well, PowerShell 7.x is working like a charm but any development I try in 5.1 sucks. I get no output at all in 5.1. It's a struggle to get anything done when the module you need to use requires PS5.1

[KevinWGagel]

Here's something interesting about this. I just found it. When I'm developing with PS 5.1 and I set a breakpoint to debug, while in debug mode I can get results. As soon as I exit debug mode the terminal stops giving me output.

[andyleejordan]

In fact, I am. Yes.

All right! Well, that's at least four confirmations I know of that this is happening when the transcript is running. Which is helpful, except I still can't seem to repro the dang bug.

But also, @lotekjunky in the dup #4390 says they were not using Start-Transcript. So there's still a bit of mystery.

[KevinWGagel]

The first thing in my powershell profiles is “Start-Transcript -OutputDirectory "C:\PS Transcripts" -IncludeInvocationHeader” try adding something like that to yours and see if that makes a difference.

[lotek4u]

I went back and looked at my code in VS code. I actually stopped using VSC because it was so unusable for me. I'm here to report that I was wrong and my logging function WAS using start-transcript. Sorry for the bad info, I'd kinda written it off. Very glad to see someone looking at it!

On Fri, May 5, 2023, at 1:40 PM, Andy Jordan wrote: > In fact, I am. Yes. > All right! Well, that's at least four confirmations I know of that this is happening when the transcript is running. Which is helpful, except I still can't seem to repro the dang bug. But also, @lotekjunky <https://github.com/lotekjunky> in the dup #4390 <#4390> says they were *not* using `Start-Transcript`. So there's still a bit of mystery. — Reply to this email directly, view it on GitHub <#3991 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AG6CC6ABAKYXCRY5LFGOONDXEVCRHANCNFSM5WM3MXGQ>. You are receiving this because you were mentioned.Message ID: ***@***.***>

Thanks, Nick

[andyleejordan]

Ah ha! Great. Ok, we have a narrower scope. And a way to workaround for all you for now (obviously that workaround is to not start the transcript). I am really trying to figure out what it is about the transcript that breaks it, but even with it started in profile I have yet to see a repro locally. Are any of you on Windows 11? I'm about to move to an older Windows 10 device to see if that makes a difference for me.

[KevinWGagel]

Both laptops this has been happening on are Windows 10 professional. Since reporting this issues work has replaced my laptop and the issue followed once the laptop was setup the same. IE with the transcript enabled.

[lotek4u]

Win 11 for me here

[andyleejordan]

Ok folks, I have a hunch. When I've left my session overnight or so, I've seen the transcript file grow easily to 200 MB. That in and of itself is a problem (inspecting it I'm finding all sorts of things I can fix). Can you guys take a look at your transcript files when things stop working and let me know what you find? Like, how big is the file, what's getting repeated over and over (probably a few things, one I've found is 0 from the artificial pipeline we use to flush events, another is Failed to load DSC since it keeps trying when it fails, another is Get-Command -Type Aliases which we use when finding references). I'm working on all three of those right now. As it is, I still don't repro even with a huge a transcript file...so given my hunch I'm going to get this as cleaned up as possible, do a pre-release, and ask you guys to test things out.

[andyleejordan]

Folks I have great news. Despite not ever reproducing this locally...I believe we've found the problem. Here's a bit of a technical write-up:

Like PSReadLine, we run an artificial pipeline to force event processing in an OnPowerShellIdle delegate (which essentially override’s PSReadLine’s same logic…with practically the same logic but for PSES’s own use cases). That pipeline does not have Out-Default added. However, when a transcript is running, when we invoke the PowerShell command to run this artificial pipeline (without Out-Default), the invocation implementation in PowerShell adds Out-Default -Transcribe True to the pipeline. This triggers a known (and since fixed) bug in PowerShell 5.1, where that command disables output to the console (since it is “only” transcribing)…and fails to re-enable it (since the flag reset happens in an EndProcessing block that is not guaranteed to be called). Hence the output disappearing after this scenario occurs.

We should be able to fix this by resetting that flag ourselves immediately after this happens, working around the bug. For PowerShell 5.1, we need to Host.UI.TranscribeOnly = false; afterwards. Working on it as I write this, will have a pre-release for you all to test soon.

[andyleejordan]

@lotekjunky @KevinWGagel @photon-fj @baywack, I know it took a week shy of a year to figure this one out and fix it (it's extra hard when you can't see it happen before your own eyes!) but v2023.5.1-preview will be up on the marketplace as a pre-release momentarily and should fix this. Please try it out and let us know!

[andyleejordan]

I'd love to get confirmation from one of you that this has indeed fixed the issue, and then I'll roll that pre-release to stable. Thanks so much!

[KevinWGagel]

Andy, Unfortunately, I can’t replicate the issue at the moment. My company upgraded my laptop and now I am not seeing the problem. Kevin W. Gagel Temp Support Analyst, Enterprise IT Services Information Technology Group Canadian Forest Products Ltd. T 250-962-3544 ***@***.******@***.***> www.canfor.com<http://www.canfor.com/> 5162 Northwood Pulp Mill Road, Prince George, BC, V2L 4W2 From: Andy Jordan ***@***.***> Sent: Tuesday, May 16, 2023 11:49 AM To: PowerShell/vscode-powershell ***@***.***> Cc: Gagel, Kevin ***@***.***>; Mention ***@***.***> Subject: [EXTERNAL] - Re: [PowerShell/vscode-powershell] `Write-Output` broken (Issue #3991) CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. If you are unsure, please click the "Report Message" button at the top-right of the message window and select "phishing" to have the Cybersecurity team investigate. I'd love to get confirmation from one of you that this has indeed fixed the issue, and then I'll roll that pre-release to stable. Thanks so much! — Reply to this email directly, view it on GitHub<#3991 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/AYCKL62BX7SWLGWIMQBUGDLXGPDYDANCNFSM5WM3MXGQ>. You are receiving this because you were mentioned.Message ID: ***@***.******@***.***>> Canfor Legal Disclaimer: This e-mail and any attachment(s) are confidential. If you are not the intended recipient, please notify the sender immediately by return e-mail, delete this e-mail and do not copy, use or disclose it to any other person.

[baywack]

I can confirm that it doesn't appear to fix the issue. I tried using both the command: code --install-extension 'C:\temp\powershell-2023.5.1.vsix' as well as "Switch to Pre-Release Version" in vscode for PowerShell. Is there anything you would like me to try validate on my impacted system?

[andyleejordan]

@baywack, could you follow these instructions to get me as detailed a set of logs as possible from a session where the issue recurs? I would much appreciate it.

Given the info in #4204 I am pretty sure that the root cause I posted above must be the cause for you: it's only happening in PowerShell 5.1, and it's only affecting Out-Default (because you can get output from Write-Host and via OCGV). So it's possible we didn't get the bug-fix for it quite right. If you have a good way to repro, please let me know!

[andyleejordan]

Ok @baywack so, we were right about the bug, but our fix set the field on the wrong instance of the UI. There's a super hidden internal UI we had to get instead, and we're pretty sure we were able to confirm that PowerShell/PowerShellEditorServices#2026 fixes it. I'm going to get another pre-release out and ping you, would appreciate a fix confirmation again!

[bc-nf]

@andschwa -- Hey there, it looks like this might still not be fixed up. Tried prerelease 2023.5.3 just now and still experiencing the same. Attaching logs, along with output and version information, as requested a few comments ago.
logs.zip

Edit: For reference, I do not have start-transcript in my profile, 3 of the 4 do not exist and the last profile is empty. However, there is logging set at the ModuleLogging, ScriptBlockLogging, and Transcription levels in GPO. Not sure if that's a factor, but it's worth noting.

When I checked the system level transcription log on my system, I see the output.

[andyleejordan]

Well...it's take three. Define constants got messed up. So sorry. This has been a doozy. I tested it too which is the weird thing. Maybe it's a compilation order issue...I don't know for sure.

[andyleejordan]

Ok, we got it in PowerShell/PowerShellEditorServices#2031. Tested and verified by @SeeminglyScience and myself. I'll get a pre-release out soon, and if it still doesn't work for you then we'll have to revisit because we can absolutely repro the TranscribeOnly bug and verify the fix in that PR. We just goofed a bit because it's...complicated.

[bc-nf]

Ok, we got it in PowerShell/PowerShellEditorServices#2031. Tested and verified by @SeeminglyScience and myself. I'll get a pre-release out soon, and if it still doesn't work for you then we'll have to revisit because we can absolutely repro the TranscribeOnly bug and verify the fix in that PR. We just goofed a bit because it's...complicated.

Thank you Andy! I’ll try to test it out in the next day or two. I’m on vacation this week so trying hard to stay away from my workstation when I can. 🙂

[andyleejordan]

Ok! v2023.5.4-preview is out and available for testing. I hope it's resolved everything 🙏 if not, then you definitely have something else going on, but I was very happy to be able to repro this with Patrick and see at least a very real bug with a transcription running, in PowerShell 5.1, with a known cause and a verifiable (if not unit-testable) fix. Please enjoy your vacation! Don't worry about getting back to us too soon. I need to start writing some talks any how.

[baywack]

So far so good in my testing! I've been running 5.4-preview for the last few days and all the previous steps I was able to complete to reproduce the issue have stopped. Thank you so much @andschwa for pushing through this. It was an annoying bug for me to deal with and sounds like you got to join in the fun as well :)

[bc-nf]

I just got back in from vacation and am glad baywack said something, reminded me to test this. Can confirm it's finally working. Thank you so much Andy @andschwa , this has been a really weird issue to track down. Appreciate your efforts to get it fixed up!

PS C:\PSScripts> write-host 'a'
a
PS C:\PSScripts> get-date

Tuesday, June 6, 2023 8:36:00 AM

[andyleejordan]

That is just fantastic news, made my day! Ok, I'll roll this pre-release out to stable. Thanks for the confirmation folks!

[KevinWGagel]

Thank you for your hard work to get it fixed. From: Andy Jordan ***@***.***> Sent: Tuesday, June 6, 2023 10:05 AM To: PowerShell/vscode-powershell ***@***.***> Cc: Gagel, Kevin ***@***.***>; Mention ***@***.***> Subject: [EXTERNAL] - Re: [PowerShell/vscode-powershell] `Write-Output` broken (Issue #3991) CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe. If you are unsure, please click the "Report Message" button at the top-right of the message window and select "phishing" to have the Cybersecurity team investigate. That is just fantastic news, made my day! Ok, I'll roll this pre-release out to stable. Thanks for the confirmation folks! — Reply to this email directly, view it on GitHub<#3991 (comment)>, or unsubscribe<https://github.com/notifications/unsubscribe-auth/AYCKL65KNL4367HXUY7DW6LXJ5PLRANCNFSM5WM3MXGQ>. You are receiving this because you were mentioned.Message ID: ***@***.******@***.***>> Canfor Legal Disclaimer: This e-mail and any attachment(s) are confidential. If you are not the intended recipient, please notify the sender immediately by return e-mail, delete this e-mail and do not copy, use or disclose it to any other person.