2017-04-07

Out-Default: Secrets Revealed

Intro

You may or may not know that Out-Default plays a very important but silent role in your everyday use of of PowerShell. If you don't know the role it plays, you may want to check out this post by Jeffry Snover. I had always had my suspicions about how the Console Host in PowerShell works, but during a recent discussion on /r/PowerShell I was linked to Snover's post and had many of my suspicions confirmed directly from the source.

But, after reading, re-reading, and re-re-reading the post I was left wondering about the specifics of when Out-Default is actually called. It wasn't clear to me if it was only attached to a line of input from the console, or attached to the end of every line of every piece of processed code, or if this done in a non-interactive session or not. I decided it would be fun to investigate this using PowerShell itself and even more fun to share my process and findings.

Test Methodology

One of my favorite things about PowerShell is how easy it is to investigate and manipulate everything in PowerShell except for the language primitives. Pretty much any function, cmdlet, or alias can be "hijacked". What I mean by "hijacked" is that you can replace even core functions like Out-Default with your own code. While this obviously isn't always a good idea, has a few security implications, and some major performance impact implications, it also has some amazing investigative use-cases.

The setup for this investigation is simple. I'm going to create a proxy function to wrap around Out-Default. Then I'm going to increment a Global variable each time the proxy function is called and update the contents of a file. This is akin to early web site visitor or hit counters. The reason for using the file instead of just looking at the variable itself is that we are trying to reduce the observer effect. If we were just to look at the variable contents every time and that happened to trigger a call to Out-Default, it would update the variable and pollute our results.The variable needs to be Global scoped because we need to test Out-Default being called in all scopes.

We will then run a series of lines of code. The same tests will be done from the PowerShell console, PowerShell ISE, and from a non-interactive session. For both the PowerShell Console and ISE we will test running individual lines, grouped lines, and multiple commands run on the same line separated by semi colons. After each test we will investigate the output file and the number contained therein should reveal the number of times Out-Default was run.



Creating the Out-Default Proxy Function

I only very recently learned about the built in ability to generate proxy functions in PowerShell. If you are interested in learning more, this Hey, Scripting Guy! blog is a pretty decent source. This is how I'm doing it:

$MetaData = New-Object System.Management.Automation.CommandMetaData (Get-Command  out-default)
$ProxyBody = (
    [System.Management.Automation.ProxyCommand]::Create($MetaData) -split "`r`n" | 
    ForEach-Object { $_ -replace '^','    '}
) -join "`r`n"
$Function = @"
Function Out-Default {
$ProxyBody
}
"@
$Function | Set-Content -Path 'C:\temp\Test-Out-Default.ps1'


We need to to make a change to the Out-Default function in C:\temp\Test-Out-Default.ps1 so that the counter file is updated with the run count on every execution of our proxy function. To do this we add the following four lines to the top of the Try block in the Begin block:

$CountFile = 'C:\temp\Out-Default_Count.txt'
$Global:OutputDefaultCount++
$Global:OutputDefaultCount |
    Microsoft.PowerShell.Management\set-Content -Path $CountFile

The finished Out-Default Proxy Command looks like this:
Function Out-Default {
    [CmdletBinding(HelpUri='http://go.microsoft.com/fwlink/?LinkID=113362', RemotingCapability='None')]
    param(
        [switch]
        ${Transcript},
    
        [Parameter(ValueFromPipeline=$true)]
        [psobject]
        ${InputObject})
    
    begin
    {
        try {
            $CountFile = 'C:\temp\Out-Default_Count.txt'
            $Global:OutputDefaultCount++
            $Global:OutputDefaultCount |
                Microsoft.PowerShell.Management\set-Content -Path $CountFile
            $outBuffer = $null
            if ($PSBoundParameters.TryGetValue('OutBuffer'[ref]$outBuffer))
            {
                $PSBoundParameters['OutBuffer'] = 1
            }
            $wrappedCmd = $ExecutionContext.InvokeCommand.GetCommand('Microsoft.PowerShell.Core\Out-Default'[System.Management.Automation.CommandTypes]::Cmdlet)
            $scriptCmd = {& $wrappedCmd @PSBoundParameters }
            $steppablePipeline = $scriptCmd.GetSteppablePipeline($myInvocation.CommandOrigin)
            $steppablePipeline.Begin($PSCmdlet)
        } catch {
            throw
        }
    }
    
    process
    {
        try {
            $steppablePipeline.Process($_)
        } catch {
            throw
        }
    }
    
    end
    {
        try {
            $steppablePipeline.End()
        } catch {
            throw
        }
    }
    <#
    
    .ForwardHelpTargetName Microsoft.PowerShell.Core\Out-Default
    .ForwardHelpCategory Cmdlet
    
    #>
    
}

Testing The Out-Default Proxy Function

Before we go forward we need to see if the proxy function actually update the test file with a count. For this, I'm going to keep a separate PowerShell console open running the following:

while($true){
    Clear-Host
    Get-Content -path 'C:\temp\Out-Default_Count.txt' -ErrorAction SilentlyContinue
    Start-Sleep -Milliseconds 500    
}

 This creates a "watch console" of sorts so I can see it being updated in realtime-ish. I'm just going to shrink this console to a very small size and move the window to the top left of my screen.
Now I'm going to open another console and run the following:

C:\temp\Test-Out-Default.ps1
"test"

 
If this is successful, my watch console should update from blank to 1. And it does!

Mission accomplished!

Testing Out-Default calls in PowerShell Console

Now that we know the proxy function works as intended, it's time to test the various scenarios in which Out-Default may or may not be called.

We already know from the test above that when entering an object (in that case the string "test")  Out-Default is called. So lets try a variable assignment
$a = 1
and check the watch console
Let's do something a bit more complex. Let's create a function and call it and see how many Out-Default calls are made:
function mygetprocess
        $a = 1
        $a++
        $null = Get-Process
        $a
}
mygetprocess
And the watch console:
We can see here that even though we made 7 lines of entry, Out-Default only ran 2 more time. Let's do some more tests:

# single line comment
<#
   Multi-line
   Comment
#>

and look at the watch console:
The behavior is consistent with code and comments: a single line adds 1 and a multi-line adds 1 for the whole block and not each line.

Now, what about multiple commands on a single line? Lets start with a pipeline

$a | Format-List

And the watch console says:
How about multiple commands separated by semicolons?

$a = 2; $a++; $a

And the watch console only increments once for all 3 commands!
Finally, what happens when we just hit Enter with no command? Nothing! the watch console stays the same.

Here is the entire code that was ran:
C:\temp\Test-Out-Default.ps1
"test"
$a = 1
function mygetprocess
        $a = 1
        $a++
        $null = Get-Process
        $a
}
mygetprocess
# single line comment
<#
   Multi-line
   Comment
#>
$a | Format-List
$a = 2; $a++; $a


And the final watch console:


Testing Out-Default Calls in PowerShell ISE

Now we need to do the same tests in PowerShell ISE. First, I'm going to delete the counter file. In theory, this should reset back to 1 on the first call to Out-Default in the new environment, but I want clean tests for each scenario. No need to show this part, but I just wanted it clear I was doing this each time I switch scenarios.

ISE is slightly different from how the PowerShell console works. Behind the scenes, ISE uses Microsoft.PowerShell.Host.ISE.PowerShellTab objects to manipulate the console when you run commands from the scripting pane. That means we actually have a few different tests to run in ISE. First, I'm going to ignore the script pane for now and run the same commands I did for the PowerShell Console in the ISE console
The watch console looks the same as it did at the end of the PowerShell Console tests:
The ISE Console behaves similar to the PowerShell Console with one exception. I had to copy and paste the entire blocks for the mygetprocess function and the multi-line comment. The ISE Console doesn't play nice with line continuations like the PowerShell Console does.

I'm going to clear the counter file and start testing the script pane on a fresh ISE. I'm going to paste all of the code into the script pane, but I'm only going to execute the first line to get the Out-Default proxy function in memory.

Now I'm going to go line by line and hit F8 except for the function block and multi-line comment which I will select each block as a whole and hit F8. 
The watch console shows 8 again, which is consistent with how the PowerShell Console and the ISE Console both work. But we are not done with the ISE. 

For the next test I want to clear the counter, run the first line in a clean ISE to import the Out-Default proxy and then execute all the other steps as a single F8 call.

And this time, the watch console reveals a different result!

The next ISE test is to reset the environment and run the entire set of code, including the dot source of the Out-Default proxy as a single F8.
This time the watch console remains blank!

The next ISE test is to save all of the commands except for the dot source line and run it as a script with F5 after dot sourcing the proxy function:
This time the watch console only shows 1:

The Final ISE test is to save all of the commands along with the dot source into a file and then run it with F5 in a fresh environment:
And the watch console remains blank:


Testing Out-Defaultin a Non-Interactive Session

Non-Interactive sessions are interesting. The code run in a non-interactive session is not attached to a console. There is no "Console Host" from the perspective of the code. You also cannot access anything under the System.Console namespace. This trips up many novice PowerShell scriptors who are fond of Write-Host but find their Schedule Tasks are not producing any output to a log file.

Anyway we want to see if Out-Default is called in a Non-Interactive session. To do that we are going to execute the last script we ran from the ISE tests from a CMD prompt by passing the -noninteractive command line option to PowerShell.exe:

PowerShell.exe -nologo -noprofile -noninteractive -file c:\temp\Test-Code.ps1

and the watch console remains blank:

Findings and Conclusions

So what do all of these test results mean? Mostly, it means that Out-Default is called at the end of every line of input, but not every line of code and only in Interactive console session (kind of, more in a bit).

For ISE a "line of input" can actually be more than one line if you are executing a chunk of code. I always say it's best to think of F8 operations as wrapping either the current line or the highlighted lines in a script block and calling .Invoke() on it.

{
    "test"
    $a = 1
    function mygetprocess
            $a = 1
            $a++
            $null = Get-Process
            $a
    }
    mygetprocess
    # single line comment
    <#
       Multi-line
       Comment
    #>
    $a | Format-List
    $a = 2; $a++; $a
}.Invoke()

That's not really what is happening, but close enough for an analogy. In that situation, the line or highlighted lines are more like a single piece of code rather than individual lines.Thus, the block of code has Out-Default attached to it as a whole instead of each line. Conceptually, it is like this:

{
    "test"
    $a = 1
    function mygetprocess
            $a = 1
            $a++
            $null = Get-Process
            $a
    }
    mygetprocess
    # single line comment
    <#
       Multi-line
       Comment
    #>
    $a | Format-List
    $a = 2; $a++; $a
}.Invoke() | Out-Default

I said that Out-Default wasn't called on Non-Interactive sessions, kind of. What I mean is that it is not called on your code inside the Non-Interactive environment. But, if your code from the non-Interactive session returns an object to a console session it will call Out-Default in that console session. Even running PowerShell.exe with the -noninteractive seems to ultimately pass to Out-Default even though it's not done within the interactive session itself. I don't have a way to test this, but the fact that objects returned from a non-interactive session end up properly formatted serves as good evidence.


In closing, this was really fun to investigate. I wanted to show this investigation from a pure PowerShell perspective, but if you want to see how it is really implemented you can look at the source code for Out-Default and Microsoft.PowerShell.ConsoleHost. There are sure to be more hidden nuggets there to unearth when I have more time and maybe better grasp of C#.