weird delay of the output of an object when followed by start-sleep (or until script end)

by

tl;dr

  • If a command’s output results in automatic tabular display (implicit Format-Table), display output can situationally be delayed for up to 300 ms. (see below for why and when), which can have two unexpected effects:

    • As in the question, a subsequent Start-Sleep submitted before the delay has elapsed further delays output for (at least) the duration of the sleep – it effectively suspends completing the 300 ms. wait.

    • A subsequent Write-Host or Out-Host call can produce output that unexpectedly comes first.

  • You can force synchronous display output by piping the command to Out-Host or to Format-Table explicitly (or any of the other Format-* cmdlets).

    • However, doing so means producing for-display output only, which means you lose the ability to (meaningfully) capture or relay the command’s output.
# The Out-Host forces instant display, before sleeping starts.
# However, use of Out-Host means you can't capture the output.
[pscustomobject] @{message="hi"} | Out-Host; sleep 5

The behavior is explained by the infamous PSv5+ asynchronous behavior of implicitly applied Format-Table output: For data types without predefined formatting data that have 4 or fewer properties (which is what auto-selects table display), it waits for up to 300 msecs. before displaying output, in an effort to determine suitable column widths.

If you use Start-Sleep before that period has elapsed, you suspend waiting for as long as you’re sleeping.

Output objects that happen not to trigger implicit Format-Table formatting are not affected, however:

# Immediate output, before sleeping ends:

# Out-of-band formatting of a .NET primitive.
PS> 1; Start-Sleep 5

# Implicit Format-*List* formatting due to having 5+ properties.
PS> [pscustomobject]@{a=1; b=2; c=3; d=4; e=5}; sleep 10

By contrast, because your command’s output is an object with just 1 property and its type ([pscustomobject]) has no predefined formatting data associated with it, it triggers implicit Format-Table formatting and therefore exhibits the problem.

In short: The following command outputs are affected, because they select implicit Format-Table output while lacking predefined column widths, necessitating the delay:

  • objects whose type happens to have 4 or fewer properties

  • if those types have no associated predefined formatting data (see about_Format.ps1xml), which is generally true for [pscustomobject] instances.

    • Additionally, but far less commonly, types with formatting data that default to table view but don’t have column widths predefined, are also affected (e.g., the System.Guid type instances that New-Guid outputs).

Types without formatting data that have 5 or more properties default to implicitly applied Format-List, where, due to line-by-line output, there’s no need to determine useful column widths, and therefore no delay.

Note that this is only a display problem, and that if the command is captured or sent to a pipeline the data is immediately output (though the command won’t finish overall until the Start-Sleep period has elapsed):

# The ForEach-Object command's script block receives the [pscustomobject]
# instance right away (and itself prints it *immediately* to the display, 
# due to outputting a *string* (which never triggers the asynchronous behavior).
& { [pscustomobject]@{message="hi"}; sleep 5 } | ForEach-Object { "[$_]" }

While there are several ways to force synchronous (immediate) display output, they all change the fundamental behavior of the command:

# Piping to Out-Host:
# Directly prints to the *display* (host).
# No way for a caller to capture the result or for processing
# the result in a pipeline.
[pscustomobject]@{message="hi"} | Out-Host; sleep 5

# Using Write-Host:
# Prints directly to the *display* (host) by default.
# While it *is* possible to capture the result via output stream 6.
# the information stream (6> file.txt), that output:
#  * is invariably converted to *strings*
#  * and the string representation does *not* use the friendly default
#    output formatting; instead, the objects are stringified with simple
#    [psobject.].ToString() calls, which results in a much less friendly
#    representation.
Write-Host ([pscustomobject]@{message="hi"}); sleep 5

# Piping to a Format-* cmdlet explicitly:
# While this does write to the success-output stream (stream number 1),
# as the command would by default, what is written isn't the original
# objects, but *formatting instructions*, which are useless for further
# programmatic processing.
# However, for redirecting the output to a file with Out-File or >
# this makes no difference, because they convert the formatting instructions
# to the strings you would see on the screen by default.
# By contrast, using Set-Content or any other cmdlet that expects actual data
# would not work meaningfully.
[pscustomobject]@{message="hi"} | Format-Table; sleep 5

More Related Contents:

  1. Powershell Join-Path showing 2 dirs in result instead of 1 – accidental script/function output
  2. PowerShell says “execution of scripts is disabled on this system.”
  3. Create objects with custom properties containing derived filesystem path information and export them to a CSV – calculated properties
  4. What’s the best way to determine the location of the current PowerShell script?
  5. Using a Variable (PowerShell) inside of a command
  6. Changing PowerShell’s default output encoding to UTF-8
  7. PowerShell outputting array items when interpolating within double quotes
  8. PSCustomObject to Hashtable
  9. Get remote registry value
  10. What’s the difference between single quote and double quote to define a string in powershell
  11. Catching FULL exception message
  12. Powershell call msbuild with nested quotation marks
  13. Redirection of standard and error output appending to the same log file
  14. Replacing only the first occurrence of a word in a string
  15. How can I get the file system location of a PowerShell script?
  16. How can I get the current PowerShell executing file?
  17. What’s the equivalent of xargs in PowerShell?
  18. You cannot call a method on a null-valued expression
  19. How do I call the PowerShell CLI robustly, with respect to character encoding, input and output streams, quoting and escaping?
  20. Visual studio code cmd error: Cannot be loaded because running scripts is disabled on this system
  21. Invoke-WebRequest, POST with parameters
  22. Powershell ConvertFrom-Json Encoding Special Characters Issue
  23. How to use a variable in each loop in Azure DevOps yaml pipeline
  24. Powershell Formatting for a String
  25. The response content cannot be parsed because the Internet Explorer engine is not available, or
  26. PowerShell FTP download files and subfolders
  27. Powershell: How can I stop errors from being displayed in a script?
  28. Using Powershell environmental variables as strings when outputting files
  29. PowerShell launch script in new instance
  30. How to return specific data type from PowerShell function i.e. DataTable

Leave a Comment