PowerShell 异步重定向标准 Output/Error 带时间戳

Question

我正在使用 PowerShell v2.0 使用 System.Diagnostics.Process 对象执行给定进程，异步拦截 stdout/stderr 消息，将相应的 $EventArgs.Data 写入主机（对于调试目的）并在其前面加上时间戳，最终用于记录目的：

$ProcessInfo = New-Object System.Diagnostics.ProcessStartInfo
$ProcessInfo.RedirectStandardOutput = $true
$ProcessInfo.RedirectStandardError = $true
$ProcessInfo.UseShellExecute = $false
$ProcessInfo.CreateNoWindow = $true
$ProcessInfo.FileName = "ping"
$ProcessInfo.Arguments = "google.com"

$Process = New-Object System.Diagnostics.Process
$Process.StartInfo = $ProcessInfo

$CaptureStandardOutputStandardError = {
    If (![String]::IsNullOrEmpty($EventArgs.Data)) {
        Write-Host "$(Get-Date -Format "yyyy-MM-dd HH:mm:ss.fffffff") [ExecCmd]: $($EventArgs.Data)"
    }
}

Register-ObjectEvent -InputObject $Process -SourceIdentifier StdOutEvent -Action $CaptureStandardOutputStandardError -EventName 'OutputDataReceived' | Out-Null
Register-ObjectEvent -InputObject $Process -SourceIdentifier ErrOutEvent -Action $CaptureStandardOutputStandardError -EventName 'ErrorDataReceived' | Out-Null

$Process.Start() | Out-Null
$Process.BeginOutputReadLine()
$Process.BeginErrorReadLine()

If ($Process.WaitForExit(10000)) {
    # Ensure streams are flushed
    $Process.WaitForExit()

    # Do stuff
} Else {
    # Timeout
}

Unregister-Event StdOutEvent
Unregister-Event ErrOutEvent

我希望写入控制台的 stdout/stderr 消息具有间隔一秒的时间戳（因为 ping 显然每秒写入管道），但由于某种原因，时间戳都在大约 10 毫秒内彼此，因此注册的事件显然会在流程完成时触发。所以我期待这个：

2016-11-27 14:53:15.6581302 [ExecCmd]：使用 32 字节数据 Pinging google.com [172.217.17.110]： 2016-11-27 14:53:15.8778445 [ExecCmd]：来自 172.217.17.110 的回复：bytes=32 time=1ms TTL=59 2016-11-27 14:53:16.6796113 [ExecCmd]：来自 172.217.17.110 的回复：bytes=32 time=1ms TTL=59 2016-11-27 14:53:17.7548025 [ExecCmd]：来自 172.217.17.110 的回复：bytes=32 time=1ms TTL=59 等...

但是，看到这个...

2016-11-26 19:00:53.0813327 [ExecCmd]：使用 32 字节数据 Pinging google.com [172.217.17.46]： 2016-11-26 19:00:53.0842700 [ExecCmd]：来自 172.217.17.46 的回复：bytes=32 time=1ms TTL=59 2016-11-26 19:00:53.0860183 [ExecCmd]：来自 172.217.17.46 的回复：bytes=32 time=1ms TTL=59 2016-11-26 19:00:53.0899003 [ExecCmd]：来自 172.217.17.46 的回复：bytes=32 time=1ms TTL=59 等...

我使用 .NET Framework v2.0 在 C# 中重新创建了它（因为我使用的是 PSv2）并且它按预期工作。代码参考：

ProcessStartInfo processInfo = new ProcessStartInfo();
processInfo.RedirectStandardError = true;
processInfo.RedirectStandardOutput = true;
processInfo.UseShellExecute = false;
processInfo.CreateNoWindow = true;
processInfo.FileName = "ping";
processInfo.Arguments = "google.com";

Process process = new Process();
process.StartInfo = processInfo;

process.OutputDataReceived += (sender, e) => {
    if (!string.IsNullOrEmpty(e.Data))
    {
        Console.WriteLine("{0} [ExecCmd]: {1}", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fffffff"), e.Data);
    }
};

process.ErrorDataReceived += (sender, e) => {
    if (!string.IsNullOrEmpty(e.Data))
    {
        Console.WriteLine("{0} [ExecCmd]: {1}", DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fffffff"), e.Data);
    }
};

process.Start();
process.BeginOutputReadLine();
process.BeginErrorReadLine();

if (process.WaitForExit(10000))
{
    // Ensure streams are flushed
    process.WaitForExit();

    // Do stuff
}
else
{
    // Timeout
}

我错过了什么？我不明白为什么相同的代码在 C# 中有效，但在 PS 中使用相同的 .NET Framework 版本却无效。省略 $Process.WaitForExit(1000) 语句 returns 正确的时间戳值，所以我知道 PS 能够返回正确的值。我能得到的最接近的是用 while (!$Process.HasExited) {} 语句替换 if ($Process.WaitForExit(10000)) 语句。这可行，但不是一个可行的解决方案，因为它（可以理解）杀死了 CPU - 奇怪的是，添加 Start-Sleep x 会导致进程不退出。我玩过 $Process.Exited 事件，但这导致进程永远不会退出，尽管事件触发并且 $Process.HasExited 事件 returns $true。类似地，创建一个 Timer 对象并检查 $Process.HasExited 也会导致进程永远不会退出。

我在 PS 中看到了很多与使用 Process 对象异步捕获 stdout/stderr 有关的问题，但找不到与我的用例相关的任何具体问题。任何 help/advice/guidance 都将不胜感激，因为我正在为这个问题挠头！提前致谢！

西蒙

Answer 1

您无法使用 Get-Date 记录即时时间。您应该访问 Powershell 的 TimeGenerated。

示例：

(get-eventlog System | where-object {$_.EventID -eq “6005”})[0].TimeGenerated

它将为您提供活动的确切时间。在您的情况下，您可以使用以下内容：

$Event.TimeGenerated.ToString("AnyFormat")

Answer 2

我不知道如何在控制台上实时显示 stdout/err 流并在订阅 Process.OutputDataReceived 和 ErrorDataReceived 事件时写入带有附加值（时间戳等）的文件，所以最后我改变了策略并最终做了以下事情：

Function Write-Log ($Message) {
    Write-Output $Message
    Add-Content -Path "C:\temp\test.txt" -Value "$(Get-Date -Format "yyyy-MM-dd HH:mm:ss.fffffff") [ExecCmd]: $Message"
}

Invoke-Expression "ping google.com" | ForEach-Object {Write-Log $_}

这行得通，但我不确定这是否是最佳做法 - 虽然它看起来高效且可靠。

PowerShell 异步重定向标准 Output/Error 带时间戳

PowerShell Async Redirect Standard Output/Error with Timestamp

powershell

timestamp

asynchronous

stdout

stderr