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.

CodePudding user response：

• 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()
}

CodePudding user response：

The StreamReader from standard output is waiting for IO - the stream from StandardOutput can't get opened for reading until it gets more data or the Process is closed. There's a similar issue with using StreamReader on TCP streams, where you get to enjoy waiting for network traffic.

The usual way around it is to let a different task wait on it via async reads like ReadLineAsync(). This doesn't help your while loop, because it still sits and waits the same amount before it can progress to read the output's StreamReader.

If packer.exe's output behaves well, you can try using a powershell job's output property instead of [process]? I tested with ping that gives the same waiting-for-IO lockup behavior:

# Locks up for full ping timeout example: 
$pStartProps = @{ FileName  = 'ping.exe' ; Arguments = '10.bad.ip.0' ... }
$p = [System.Diagnostics.Process]::Start($pStartInfo)

# Locks when reading
$output = $p.StandardOutput.ReadLine()
while ( $output -ne $null ) {
  $output = $p.StandardOutput.ReadLine(); ## read the output
  # Do stuff
}

#####

# Does not lock when using Job output instead:
$job = Start-Job -ScriptBlock { ping.exe 10.bad.ip.0 }

While ($job.State -ne 'Completed') {
  $job.ChildJobs[0].Output  ## read the output
  # Do stuff
}