powershellloggingpowershell-cmdletpowershell-v5.1

Write-Information does not show in a file transcribed by Start-Transcript


I'm using PowerShell 5.1 and I am trying to determine why Write-Information messages do not show in the transcript log created by Start-Transcript unless I set $InformationPreference to SilentlyContinue. I want to both display the messages in the console and have them written to the log file.

I looked here: https://learn.microsoft.com/en-us/powershell/module/microsoft.powershell.core/about/about_preference_variables?view=powershell-5.1#informationpreference

Then I decided to create this script to test what gets written and when. See the preference section right underneath Testing explicit behavior with transcripts -------------

Clear-Host

$ErrorActionPreference = "Stop"

try {
    Write-Host "Starting transcript"
    Start-Transcript -Force -Path "$PSScriptRoot\default.txt"

    <#
        In PowerShell 5.1 the default behavior is as follows:
            $DebugPreference       = SilentlyContinue
            $InformationPreference = SilentlyContinue
            $ProgressPreference    = Continue
            $VerbosePreference     = SilentlyContinue

        See the following for more information:
        https://learn.microsoft.com/en-us/powershell/module/microsoft.powershell.core/about/about_preference_variables?view=powershell-5.1
    #>

    # I am not testing Write-Output as I am not worried about programmatic/pipeline stuff, just contextual messages for end-users or logging

    Write-Host "`nTesting default behavior with transcripts --------------------------------`n"

    # Setting these just in case I launch this script in a session where a previous script might have modified the preference variables
    $DebugPreference = "SilentlyContinue"
    $InformationPreference = "SilentlyContinue"
    $ProgressPreference = "Continue"
    $VerbosePreference = "SilentlyContinue"

    Write-Host "Calling Write-Host"
    Write-Debug "Calling Write-Debug"
    Write-Error "Calling Write-Error" -ErrorAction "Continue"
    Write-Information "Calling Write-Information"
    Write-Progress "Calling Write-Progress"
    Write-Verbose "Calling Write-Verbose"

    Stop-Transcript
    Start-Transcript -Force -Path "$PSScriptRoot\everything_continue.txt"

    Write-Host "`nTesting explicit behavior with transcripts --------------------------------`n"

    # Turn everything on
    $DebugPreference = "Continue"
    $InformationPreference = "Continue" # Setting this to SilentlyContinue makes it show up in the log but not the console. Setting this to 'Continue' makes it show up in the console but not the log.
    $ProgressPreference = "Continue"
    $VerbosePreference = "Continue"

    Write-Host "Calling Write-Host"
    Write-Debug "Calling Write-Debug"
    Write-Error "Calling Write-Error" -ErrorAction "Continue"
    Write-Information "Calling Write-Information"
    Write-Progress "Calling Write-Progress"
    Write-Verbose "Calling Write-Verbose"

    Stop-Transcript

    Write-Host "`nResults -------------------------------------------------------------------`n"

    # See what actually gets captured and written by the transcriber

    $messageTypes = @("Write-Debug", "Write-Error", "Write-Host", "Write-Information", "Write-Verbose")

    Write-Host "Default" -ForegroundColor Cyan
    $lines = Get-Content "$PSScriptRoot\default.txt"
    foreach ($message in $messageTypes) {
        if ($lines -like "*Calling $message*") {
            Write-Host "  $message PRESENT" -ForegroundColor Green
        }
        else {
            Write-Host "  $message MISSING" -ForegroundColor Red
        }
    }

    Write-Host "Everything Continue" -ForegroundColor Cyan
    $lines = Get-Content "$PSScriptRoot\everything_continue.txt"
    foreach ($message in $messageTypes) {
        if ($lines -like "*Calling $message*") {
            Write-Host "  $message PRESENT" -ForegroundColor Green
        }
        else {
            Write-Host "  $message MISSING" -ForegroundColor Red
        }
    }
}
catch {
    Write-Host "----------------------------------------------------------------------------------------------------"
    Write-Host $_.Exception
    Write-Host $_.ScriptStackTrace
    Write-Host "----------------------------------------------------------------------------------------------------"

    try { Stop-Transcript } catch { }

    throw $_
}

Solution

  • What you're seeing is a bug in Windows PowerShell (as of v5.1.17134.590) that has been fixed in PowerShell Core (as of at least v6.1.0 - though other transcript-related problems persist; see this GitHub issue).

    I encourage you to report it in the Windows PowerShell UserVoice forum (note that the PowerShell GitHub-repo issues forum is only for errors also present in PowerShell Core).

    Here's how to verify if the bug is present in your PowerShell version:

    Create a script with the code below and run it:

    '--- Direct output'
    
    $null = Start-Transcript ($tempFile = [io.path]::GetTempFileName())
    
        # Note that 'SilentlyContinue' is also the default value.
        $InformationPreference = 'SilentlyContinue'
    
        # Produces no output.
        Write-Information '1-information' 
    
        # Prints '2-Information' to the console.
        Write-Information '2-information' -InformationAction Continue
    
    $null = Stop-Transcript
    
    '--- Write-Information output transcribed:'
    
    Select-String '-information' $tempFile | Select-Object -ExpandProperty Line
    
    Remove-Item $tempFile
    

    With the bug present (Windows PowerShell), you'll see:

    --- Direct output
    2-information
    --- Write-Information output transcribed:
    INFO: 1-information
    

    That is, the opposite of the intended behavior occurred: the transcript logged the call it should'nt have (because it produced no output), and it didn't log the one it should have.

    Additionally, the logged output is prefixed with INFO: , which is an inconsistency that has also been fixed in PowerShell Core.

    There is no full workaround, except that you can use Write-Host calls in cases where do you want the output logged in the transcript - but such calls will be logged unconditionally, irrespective of the value of preference variable $InformationPreference (while Write-Host formally provides an -InformationAction common parameter, it is ignored).


    With the bug fixed (PowerShell Core), you'll see:

    --- Direct output
    2-information
    --- Write-Information output transcribed:
    2-information
    

    The transcript is now consistent with the direct output.