POWERSHELL: Transcript not working properly after format-table and new-item

Building on the helpful comments:

tl;dr

• You're seeing a bug (though it isn't classified as such) that is one of several manifestations of asynchronous behavior when PowerShell implicitly applies Format-Table for-display formatting.

• Workarounds, all suboptimal, unfortunately:

  • Per-command [cumbersome, error-prone]: Use a Format-* cmdlet explicitly with any call that normally results in table formatting by default in order to force synchronous output; in your case, place | Format-Table after your New-Item call.

    • Note:
      • Using Format-Table prevents you from capturing a command's output as data, when you try to assign to a variable or process the output further in a pipeline, because what the Format-* cmdlets emit are formatting instructions, not data.

  • Script-wide [introduces a 300-msec delay]: As you've discovered, inserting a Start-Sleep at the end helps, under the following conditions:

    • The script must end with a command that synchronously outputs to the success output stream (i.e. it must not be implicitly table-formatted), notably by outputting a string, such as in your Write-Output "2) A very simple message AFTER new-item." call. (Note that you may omit Write-Output to take advantage of PowerShell's implicit output behavior).

    • Start-Sleep -MilliSeconds 300 must be placed immediately before it, which forces the following synchronous output to also render the pending asynchronous output.

    • However, due to another design limitation in PowerShell's for-display output-formatting system that is separate from the asynchronous behavior (note that neither is specific to Start-Transcript use, but the latter manifests in a way that is specific to that cmdlet) there is general pitfall if you don't use Format-Table calls explicitly:

      • If the first implicitly table-formatted statement in a script uses no predefined formatting-data, it locks in the display columns for all subsequent implicitly table-formatted statements, which can make the latters' output effectively invisible - see this answer.
      • Per-command Format-Table calls avoid this problem (while also forcing synchronous output), at the expense of not outputting data, as noted above.

A simplified example:

Start-Transcript t.txt

# This triggers *implicit* Format-Table output that is *asynchronous*,
# due to the output object having 4 or fewer properties and
# its type not having formatting-data associated with, as with the
# Get-Acl output in your question.
# NOTE:
#  * Curiously, the asynchronous behavior is also triggered in this case
#    if you append | Format-Table, but only affects SUBSEQUENT 
#    implicitly table-formatted statements, including those whose 
#    output types DO have formatting-data.
[pscustomobject] @{ Foo = 'Bar' }

# WORKAROUND:
#  Sleep for 300 msecs., then output *synchronously* to the success output stream.
#  This forces pending asynchronous table output to print. 
Start-Sleep -Milliseconds 300
"==== Done."

Stop-Transcript

You're seeing another manifestation of the infamous 300-msec. delay that occurs when Format-Table formatting is implicitly applied to output that goes to the display - see this answer for details.

While the typical manifestation is that output appears out of order (across different output streams), in your case information is lost, which is obviously a more serious problem. Data loss can also occur with the PowerShell CLI. See the GitHub issues below.

Relevant GitHub issues:

• GitHub issue #10994: the problem at hand (Start-Transcript-related).

  • The unfortunate conclusion appears to be that this will not be fixed.

• GitHub issue #4594: discussion of the surprising asynchronous behavior in general (output appearing out of order).

• GitHub issue #13985: potential data loss when using the CLI.