__PSDumpAMSILogContent debug logging sent to stdout

[rhubarb-geek-nz]

Prerequisites

• Write a descriptive title.
• Make sure you are able to repro it on the latest released version
• Search the existing issues.
• Refer to the FAQ.
• Refer to Differences between Windows PowerShell 5.1 and PowerShell.

Steps to reproduce

When enabling AMSI debug logging the log is written to stdout, this mixes in with the success stream. It should be written to stderr.

Expected behavior

When $env:__PSDumpAMSILogContent='1' is set the extra logging should go to stderr

Actual behavior

When $env:__PSDumpAMSILogContent='1' is set the extra logging goes to stdout

Error details

no error other reported by system

Environment data

Name                           Value
----                           -----
PSVersion                      7.4.2
PSEdition                      Core
GitCommitId                    7.4.2
OS                             Debian GNU/Linux 11 (bullseye)
Platform                       Unix
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0…}
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1
WSManStackVersion              3.0

Visuals

=== Amsi notification report content ===
<System.Byte[]>.new(<2048>)
=== Amsi notification report success: False ===

[mklement0]

I agree that Console.Error.WriteLine() is the better choice.

As an aside: an outside caller - unfortunately - sees all of PowerShell's output streams including Console.WriteLine() and PowerShell error output via stdout; see:

• Mapping file descriptors of pwsh process to Powershell streams #7989 (comment)

Console.Error.WriteLine() unconditionally writes to stderr, while PowerShell error output only goes to stderr if the caller uses a 2> redirection.

[rhubarb-geek-nz]

... while PowerShell error output only goes to stderr if the caller uses a 2> redirection.

Of course it would do that™ .....

$ pwsh -c "Write-Error 'foo'" >out.1 2>out.2
$ ls -l
total 4
-rw-r--r-- 1 onlyme users  0 Apr 18 19:18 out.1
-rw-r--r-- 1 onlyme users 35 Apr 18 19:18 out.2
$ rm out.*
$ pwsh -c "Write-Error 'foo'" >out.1
$ ls -l
-rw-r--r-- 1 onlyme users 35 Apr 18 19:19 out.1

[SteveL-MSFT]

Agree that the logging should be going to stderr, but not clear to me how this might affect existing tools relying on this. I don't see any tests using this special env var.

[rhubarb-geek-nz]

I don't see any tests using this special env var.

There is a whole world out there! It is built into every production release, and anyone can use it for whatever purposes.

#21473 (comment)

I was using it to track down a performance issue. It is quite 'illuminating' to see the volume of traffic sent to AMSI during what one might consider are normal script operations.

[SteveL-MSFT]

@rhubarb-geek-nz your usage is dumping to the console interactively. My question is if there's any tools that rely on it going to stdout which would break if we change it to stderr.

[mklement0]

A global GitHub code search for __PSDumpAMSILogContent shows only its use in the PowerShell repo itself (and forks of it): https://github.com/search?q=__PSDumpAMSILogContent&type=code

Also, the variable isn't documented.

[SteveL-MSFT]

The WG reviewed this and agreed that this is a bucket 3 breaking change (thanks @mklement0 for the code search) and accept making the change to write to STDERR. We believe the env var is a carryover from WinPS5.1 and used as a test hook.

[SteveL-MSFT]

I made the change, but now noticed an unexpected behavior. With the Console.WriteLine() calls now Console.Error.WriteLine(), you don't get ANY output in the interactive shell. STDERR is only written if you call pwsh itself. It might make more sense to just remove this env var altogether as it's not useful expect as a test hook.

[rhubarb-geek-nz]

It was useful to demonstrate that AMSI logging was implemented on Linux,

I think that writing a real AMSI module to demonstrate the volume and verbosity of the PowerShell logging would be an alternative approach. ( outside of the scope of this PowerShell project ). While not so easy to demonstrate with a simple script it would show what PowerShell is leaking from the process.