Warm tip: This article is reproduced from serverfault.com, please click

Process.StandardOutput.Readline() is hanging when there is no output

发布于 2021-10-20 20:53:03

Note: I am trying to run packer.exe as a background process to workaround a particular issue with the azure-arm builder, and I need to watch the output. I am not using
Start-Process because I don't want to use an intermediary file to consume the output.

I have the following code setting up packer.exe to run in the background so I can consume its output and act upon a certain log message. This is part of a larger script but this is the bit in question that is not behaving correctly:

  $builderDir = ( Split-Path -Parent $PSCommandPath )
  Push-Location $builderDir
  
  # Set up the packer command to run asynchronously
  $pStartProps = @{
    FileName               = ( Get-Command -CommandType Application packer ).Source
    Arguments              = "build -var-file ""${builderDir}\win-dev.pkrvars.hcl"" -only ""azure-arm.base"" ."
    UseShellExecute        = $false
    RedirectStandardOutput = $true
    RedirectStandardError  = $false
    LoadUserProfile        = $true
  }
  $pStartInfo = New-Object ProcessStartInfo -Property $pStartProps

  $p = [Process]::Start($pStartInfo)

  while ( $null -ne ( $output = $p.StandardOutput.Readline() ) -or !$p.HasExited ) {
    # Do stuff
  }

Basically, the ( $output = $p.StandardOutput.Readline() ) portion of the while condition seems to be hanging until there is more output to be read. I'm not sure why this is, because StreamReader.Readline() should either return the next line to be read, or null if there is no more output. I have a fair bit of processing around this regarding the log message I'm expecting to get, so blocking when reading STDOUT when there is no further output to consume renders the script useless. There are other things it is doing in the foreground while packer.exe continues to execute.

I am able to confirm in the debugger that Readline() does read empty lines (value of "") fine, this seems to happen be when there is not yet further output to consume. This may be tangential but this causes the debugger to bug out as well.

When this issue occurs the VSCode debugger sits on this with
$output = $p.StandardOutput.Readline() highlighted for a few seconds, then the debugger stops (everything disappears, no more variable tracking, etc.) until Readline() stops blocking and execution continues, at which point the debugger seems to re-initialize the tracked variables, watched expressions, etc. So I can't use the debugger at all when this occurs. Even the
PowerShell Integrated Console (the one used with the debugger) hangs and I cannot type anything.


For full context, the goal of this script is to let packer.exe do its thing while I loop continuously to:

  1. Display more output from packer.exe
  2. Check for the presence of a certain log message
  3. Give packer.exe a bit of time to try to do what it needs on its own
  4. If it waits too long, I execute a script against the node being since what packer.exe should have done on its own likely failed
    • I am using Invoke-AzVMRunCommand to do this, which can't be done at the state packer.exe for the issue I am working around. It must be performed out-of-band of the packer.exe run itself.
  5. The build continues on after the workaround is applied and I simply continue forwarding the output of packer.exe to the console until the process exits

But since the script hangs when there is no output, step 4 will never work as I have to give packer time to try to complete the config on its own, and is the entire reason why I'm hacking this together in the first place.


Why is Readline() blocking here? Am I doing something incorrectly? This behavior occurs whether I run my script in Windows PowerShell or PowerShell Core.

Questioner
codewario
Viewed
0
mklement0 2021-10-21 06:36:25
  • StreamReader.ReadLine() is blocking by design.

  • There is an asynchronous alternative, .ReadLineAsync(), which returns a Task<string> instance that you can poll for completion, via its .IsCompleted property, without blocking your foreground thread (polling is your only option in PowerShell, given that it has no language feature analogous to C#'s await).

Here's a simplified example that focuses on asynchronous reading from a StreamReader instance that happens to be a file, to which new lines are added only periodically; use Ctrl-C to abort.

I would expect the code to work the same if you adapt it to your stdout-reading System.Diagnostics.Process code.

# Create a sample input file.
$n=3
1..$n > tmp.txt

# Open the file for reading, and convert it to a System.IO.StreamReader instance.
[IO.StreamReader] $reader = 
  [IO.File]::Open("$pwd/tmp.txt", 'Open', 'Read', 'ReadWrite')

try {
  $task = $reader.ReadLineAsync() # Start waiting for the first line.
  while ($true) { # Loop indefinitely to wait for new lines.
    if ($task.IsCompleted) {  # A new line has been received.
      $task.Result # Output
      # Start waiting for the next line.
      $task.Dispose(); $task = $reader.ReadLineAsync(); 
    }
    else { # No new line available yet, do other things.
      Write-Host '.' -NoNewline
      Start-Sleep 1
    }
    # Append a new line to the sample file every once in a while.
    if (++$n % 10 -eq 0) { $n >> tmp.txt }
  }
}
finally {
  $reader.Dispose()
}