Powershell: Redirection vs. -*Variable common parameters, and the limited usefulness of the data that is captured

[KirkMunro]

I'm working on #6702 right now, normalizing the stream-related common parameters so that you can capture a stream in a variable or provide an ActionPreference for any stream, when I came across what appears to be a design bug.

It's easier to understand when looking at an example, so run this script first to get started:

# Capture a warning using redirection
$o1 = Write-Warning 'Message' 3>&1

# Capture a warning using -WarningVariable
$o2 = $null
Write-Warning 'Message' -WarningVariable o2

# Capture a warning using a -WarningVariable while silencing output via -WarningAction
$o3 = $null
Write-Warning 'Message' -WarningVariable o3 -WarningAction Ignore

# Capture a warning using a -WarningVariable while silencing output via redirection
$o4 = $null
Write-Warning 'Message' -WarningVariable o4 *>$null

# Look at the default output, and notice the rendering differences
$o1,$o2,$o3,$o4

# Look at the list output, and notice how the rendering differences persist
$o1,$o2,$o3,$o4 | Format-List * -Force

# Look at the string output, and notice that you can't tell at all that the messages
# came from warnings
$o1,$o2,$o3,$o4 | Out-String

While each of these commands are designed to capture warning records, there are several problems that this output illustrates, as follows:

1. All WarningRecord instances captured while redirection is used are decorated with additional information that is not captured when redirection is not used.
2. WarningRecord instances are indistinguishable from other output when converted to string, such as when the results of a command are captured and written to a log file.
3. PowerShell hosts not only apply specific colors to records from various streams, they also render additional text before the object data, even when that object data is displayed in its non-default format such as a list or a table.

The exact same behavior holds true for verbose and debug message streams, as can be seen through the PR that I am working on.

The first issue is not a huge issue, but it would probably be better if records captured via -*Variable common parameters were also properly decorated for proper output in a console.

The second and third issue are the more serious problem, because they limit the usefulness of capturing various types of stream data. Scripters who run a command and want to capture and review results from a log will find that much easier if output from different streams is properly identified in a black and white format with a prefix. This isn't just nice to have information: it's critical for scanning and searching purposes.

Digging into the technical details, part of the problems stem from these methods in the default host implementation:

   TypeName: System.Management.Automation.Internal.Host.InternalHostUserInterface
Name             MemberType Definition
----             ---------- ----------
Write            Method     void Write(string value), void Write(System.ConsoleColor foregroundColor, System.ConsoleColor backgroundColor, string value)
WriteDebugLine   Method     void WriteDebugLine(string message)
WriteErrorLine   Method     void WriteErrorLine(string value)
WriteInformation Method     void WriteInformation(System.Management.Automation.InformationRecord record)
WriteLine        Method     void WriteLine(), void WriteLine(string value), void WriteLine(System.ConsoleColor foregroundColor, System.ConsoleColor backgroundColor, string value)
WriteProgress    Method     void WriteProgress(long sourceId, System.Management.Automation.ProgressRecord record)
WriteVerboseLine Method     void WriteVerboseLine(string message)
WriteWarningLine Method     void WriteWarningLine(string message)
````

Notice how progress and information streams have methods that accept actual records, but error, warning, verbose and debug streams only have methods that accept strings. Also note that some of these methods decorate output with stream-identifying text (`WriteDebugLine`, `WriteVerboseLine`, `WriteWarningLine`), while others do not (`WriteInformation`, `WriteErrorLine`).

What I think should happen to address this issue and provide a much better foundation for script logging going forward:

1. New methods should be added to an abstract `PSHostUserInterface2` class that is derived from `PSHostUserInterface` to avoid breaking changes. There should be one `Write*Line` method and one `Write*` method for each stream.
1. Once the abstract methods are added, internal classes that derive from `PSHostUserInterface` should derive from the new `PSHostUserInterface2` class and implement the new methods. Other hosts can catch up when they're ready to do so.
1. The F&O layer should decorate the default output of Warning, Verbose, Debug, and Information records with an all caps prefix so that they can be properly identified and searched for when all you have is text data to work with (e.g. log files).
1. Any internal classes that output stream data to the host should apply a prefix in the `Write*Line` methods, but not apply in the `Write*` methods (for those we rely on the default output from the F&O layer for those records). That allows for prefixing in text written directly to the host while leveraging prefixing that is inherent in the default format applied to stream record instances.

Thoughts/comments are welcome and appreciated.

# Environment data

```none
Name                           Value
----                           -----
PSVersion                      6.2.1
PSEdition                      Core
GitCommitId                    6.2.1
OS                             Microsoft Windows 10.0.17763
Platform                       Win32NT
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0…}
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1
WSManStackVersion              3.0

[Jaykul]

First, let me say that I find it really confusing that the formatting is different depending on this WriteWarningStream NoteProperty. If we normalize that:

$o1,$o2,$o3,$o4 | % { $_ } | Add-Member NoteProperty WriteWarningStream $False -force

They will suddenly all format the same way.

I'm not sure what the intent of that feature is, but I've never liked it (it's very confusing when $Error occasionally shows default/white text, too).

However ...

The reason we have separate methods on the host for different streams is to allow the host to decide whether it needs to add text to the front, or can rely on colors or some other formatting like prefixing with emoji or whatever. Maybe my next host will enhance the UI to display errors as pinned messages you have to dismiss and make progress output fade away gradually or ... it might put different streams in 3D parallax layers, or tabs, or columns ... or have a checkbox that lets you hide or show all messages from specific streams.

Normalizing on adding text to the front (as though the world is black and white) might be a step in the wrong direction. I mean, I would love to have _templates_ for these strings, so I could put a timestamp and user or host name in them, maybe even a duration (i.e. the time since script start), or the path of the script that wrote the message...

But I'm not sure hard-coding extra text -- in particular text that the current hosts are also already adding -- is the right solution. Clearly someone's making a deliberate choice to output these differently based on a property of the object...

• Would applying prefixes to the _existing_ Write*Line methods mean that existing hosts hosting a new PowerShell would end up with double "WARNING: WARNING: " text on the front of their messages (as long as they have the WriteWarningStream property)?

• Would _all_ output need to go through an extra if/else switch to decide which interface the host supports in order to be able to fall back to the available Write*Line method if the newer one wasn't available?

[KirkMunro]

I'm going to think about this more while I take care of some real-life needs, but one thought comes to mind up front:

I think having PowerShell deal with how to display stream messages in a clear and unambiguous manner by default (i.e. in a black and white world, how should stream messages appear to a user), and having hosts deal with all of the extras that a runtime doesn't deal with (i.e. color, pinning, showing output in separate windows, etc.) would be a good model to follow. Whether that text is prefixed or not, I don't care that much, as long as it is clear from the _default_ output where a stream message came from, irrespective of the host that is displaying that stream message. Hosts should then be able to show that default output, or show some other output, depending on their needs. If hosts had more methods that accepted *Record objects, they could decide what to do with them, and they wouldn't be subject to default views unless they wanted to, no?

[KirkMunro]

Circling back to this, the best model still seems to be to have methods on hosts that accept *Record objects. Hosts can then convert those to string (i.e. take the default textual presentation from PowerShell, which may include a prefix to uniquely identify the type of record when shown among other records), or work with the actual object to render the record in a way that is better for that specific host. This is the only way that I can think of that allows hosts to present message information in the best possible way (i.e. they need all of the details available on the record) while also allowing PowerShell to also present the information in the best way possible when working with text-only, without colors.

[KirkMunro]

Also FYI @Jaykul, the Write*Stream Note Property "magic" is no longer in PowerShell's code base. I'm not sure what PR they were removed with, but its gone in v7.

[iSazonov]

@KirkMunro Maybe you ready split the meta issue to small issues for fixing (like add prefix in WarningRecord .ToString)?

[Jaykul]

For what it's worth, after fighting with this a little, I think the plan you laid out makes sense:

1. normalizing the methods in a new interface
2. handling the labeling in a format file

If it's not done in the formatting engine, commands like Out-String and Out-File don't handle it properly even when I manually collect all the output for them with redirection, and PAGERs can't handle those extra streams (even when redirected)...