Process.StandardOutput.Readline() 在没有输出时挂起

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

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.

我有以下代码在后台设置 packer.exe 到 运行,这样我就可以使用它的输出并根据特定的日志消息采取行动。这是一个更大的脚本的一部分,但这是有问题的,它的行为不正确:

  $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
  }

基本上,while 条件的 ( $output = $p.StandardOutput.Readline() ) 部分似乎挂起,直到有更多输出要读取。我不确定这是为什么,因为 StreamReader.Readline() should either return the next line to be read, or null 如果没有更多的输出。关于我期望获得的日志消息,我对此进行了相当多的处理,因此在没有进一步的输出可供使用时读取 STDOUT 时阻塞会使脚本无用。在 packer.exe 继续执行的同时,它还在前台做其他事情。

我能够在调试器中确认 Readline() 确实读取空行("" 的值)很好,这似乎是在没有进一步的输出可供使用时发生的。这可能是切线的,但这也会导致调试器出错。

当这个问题发生时,VSCode 调试器会停在上面
$output = $p.StandardOutput.Readline() 突出显示几秒钟,然后调试器停止(一切都消失了,不再有变量跟踪,等等) .) 直到 Readline() 停止阻塞并继续执行,此时调试器似乎重新初始化跟踪变量、监视表达式等。所以当这种情况发生时我根本无法使用调试器。甚至
PowerShell Integrated Console(与调试器一起使用的那个)也挂起,我无法输入任何内容。


对于完整的上下文,此脚本的目标是让 packer.exe 在我不断循环到:

时执行它的操作
  1. 显示来自 packer.exe
  2. 的更多输出
  3. 检查是否存在特定日志消息
  4. packer.exe 一点时间尝试自己完成需要的事情
  5. 如果等待时间过长,我会针对节点执行脚本,因为 packer.exe 应该自行完成的操作可能会失败
    • 我正在使用 Invoke-AzVMRunCommand 来执行此操作,对于我正在解决的问题,在 packer.exe 状态下无法执行此操作。它必须在 packer.exe 运行 本身的带外执行。
  6. 应用解决方法后构建继续,我只是继续将 packer.exe 的输出转发到控制台,直到进程退出

但是由于脚本在没有输出时挂起,因此第 4 步将永远无法工作,因为我必须给打包程序时间来尝试自行完成配置,这就是我一起破解它的全部原因首先。


为什么 Readline() 在这里阻塞?我做错了什么吗?无论我 运行 我的脚本是在 Windows PowerShell 还是 PowerShell Core 中,都会出现此行为。

  • StreamReader.ReadLine() 被设计成阻塞。

  • 有一个异步替代方案,.ReadLineAsync(), which returns a Task<string>您可以轮询完成的实例,通过它 .IsCompleted 属性,不会阻塞您的前台线程(轮询是您在 PowerShell 中唯一的选择,因为它没有类似于 C# await 的语言功能)。

这里有一个简化的例子,它侧重于从 StreamReader 实例中异步读取,该实例恰好是一个文件,新行只会定期添加到该文件中;使用 Ctrl-C 中止。

如果您将代码调整为您的标准输出读取 System.Diagnostics.Process 代码,我希望代码能够正常工作。

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

来自标准输出的 StreamReader 正在等待 IO - 来自 StandardOutput 的流在获取更多数据或关闭 Process 之前无法打开以供读取。在 TCP 流上使用 StreamReader 也存在类似的问题,您可以在其中享受等待网络流量的乐趣。

通常 绕过它的方法是让不同的任务通过像 ReadLineAsync() 这样的异步读取等待它。这对您的 while 循环没有帮助,因为它仍然会等待相同的时间才能继续读取输出的 StreamReader.

如果 packer.exe 的输出表现良好,您可以尝试使用 powershell 作业的输出 属性 而不是 [process]?我用 ping 进行了测试,它给出了相同的等待 IO 锁定行为:

# 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
}

如上使用 StandardOutput.ReadLine(),您将输出重定向流设置为使用同步读取模式。这意味着当您调用 $p.StandardOutput.ReadLine() 时,它的行为就像一个普通的函数调用。

您调用它,并等待 return 值。 return 值是 完整行 $null 如果到达流的末尾。这意味着当 运行 程序用输出填充 System.Diagnostics.Process 输出流缓冲区时,您将继续做一个好的同步 PowerShell 男孩并等待对 return 的函数调用。一旦 System.Diagnostics.Process 检测到流中的换行符,函数调用 $p.StandardOutput.ReadLine() returns 与您的数据,一个 完整的行 .

这就是为什么它看起来像是阻塞的原因。它必须等到它有一个完整的行才能 return.

另一个 return 值 $null 更有意义,因为知道 StreamReader 对象用于许多不同的事物,这些事物可能有不同的流结尾。如果您使用 StreamReader 读取文本文件,则 stream/file 的结尾是您点击 EOF 标记时。如果您正在读取一个字符数组,它可能是 [=22=] 字符串终止符。 $null 在这种情况下是流的通用结束。

对于 System.Diagnostics.Process 对象,“流结束”的定义是进程完成的时间,而不是“此时我没有输出”。

为了消除这种阻塞,您必须以异步方式执行读取a.k.a。 ReadLineAsync().

不想踩@mklement0 脚趾,因为他正确地通过使用 ReadLineAsync() 使其异步并通过轮询将 checking/validation 脚本保持在同一范围内来解决您的问题.但是,另一种异步读取数据的方法是使用 Process.BeginOutputReadLine() and the OutputDataReceived 事件在您有更多数据时异步触发脚本块。

# Script to run when you have another line of data
$NewOutputSB = {
    param([object]$sender, [System.Diagnostics.DataReceivedEventArgs]$e)
    Write-Host "  #  " $e.Data
}

$pStartProps = @{
    FileName               = ( Get-Command -CommandType Application ping.exe ).Source
    Arguments              = "8.8.8.8"
    UseShellExecute        = $false
    RedirectStandardOutput = $true
    RedirectStandardError  = $false
    LoadUserProfile        = $true
}
$pStartInfo = New-Object System.Diagnostics.ProcessStartInfo -Property $pStartProps

$p = New-Object System.Diagnostics.Process

# Register the Event Handler
$EventSub = Register-ObjectEvent $p -EventName OutputDataReceived -Action $NewOutputSB

$p.StartInfo = $pStartInfo

$p.Start() | Out-Null

# Begin asynchronous reading on the Output stream
$p.BeginOutputReadLine()

# Do other work while we wait for it to finish running...
while ( !$p.HasExited ) {
    # Do stuff
    Start-Sleep -Milliseconds 250
    Write-Host "--- Do stuff"
}

# Cleanup Event Handler
Unregister-Event -SubscriptionId $EventSub.Id

在 运行 这段代码之后,输出显示异步模式下的流 运行:

PS C:\>
  #   
  #   Pinging 8.8.8.8 with 32 bytes of data:
  #   Reply from 8.8.8.8: bytes=32 time=28ms TTL=119
--- Do stuff
--- Do stuff
--- Do stuff
  #   Reply from 8.8.8.8: bytes=32 time=28ms TTL=119
--- Do stuff
--- Do stuff
--- Do stuff
--- Do stuff
  #   Reply from 8.8.8.8: bytes=32 time=31ms TTL=119
--- Do stuff
--- Do stuff
--- Do stuff
--- Do stuff
  #   Reply from 8.8.8.8: bytes=32 time=28ms TTL=119
  #
  #   Ping statistics for 8.8.8.8:
  #       Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
  #   Approximate round trip times in milli-seconds:
  #       Minimum = 28ms, Maximum = 31ms, Average = 28ms
  #
--- Do stuff