PowerShell異步重定向標準輸出/帶時間戳錯誤

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 

我期待寫入控制檯標準輸出/標準錯誤消息發送到具有時間戳的第二開的（如平寫入顯然每秒鐘都會到管道），但由於某些原因，時間戳都在彼此的大約10毫秒之內，所以註冊事件顯然在過程完成時觸發。所以我期待這樣：

2016-11-27 14：53：15.6581302 [ExecCmd]：Pinging google.com [172.217.17.110]與32個字節的數據： 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：字節= 32時間= 1毫秒TTL = 59 等...

但是，相反，看到此...

2016-11-26 19:00:00 53.0813327 [ExecCmd]：Pinging google.com [172.217.17.46]機智h 32個字節的數據： 2016-11-26 19:00:00 53.0842700 [ExecCmd]：172.217.17.46的回覆：bytes = 32 time = 1ms TTL = 59 2016-11-26 19:00:00 53.0860183 [ExecCmd] ：172.217.17.46：bytes = 32 time = 1ms TTL = 59 2016-11-26 19:00:00 53.0899003 [ExecCmd]：172.217.17.46：bytes = 32 time = 1ms TTL = 59 等等。 。

我已經在C＃中使用.NET Framework v2.0重新創建了這個（因爲我使用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框架版本。省略$ Process.WaitForExit（1000）語句返回正確的時間戳值，所以我知道PS能夠返回正確的值。我能得到的最接近的是用while (!$Process.HasExited) {}聲明替換if ($Process.WaitForExit(10000))聲明。這是有效的，但不是一個可行的解決方案，因爲它（可以理解）殺死CPU - 奇怪的是，添加Start-Sleep x會導致進程不能退出。我玩過$ Process.Exited事件，但是這會導致進程永遠不會退出，儘管事件觸發並且$ Process.HasExited事件返回$ true。同樣，創建一個Timer對象並檢查$ Process.HasExited會導致該進程永遠不會退出。

我見過很多與PS中的Process對象異步捕獲stdout/stderr有關的問題，但找不到與我的用例有關的任何特定問題。任何幫助/建議/指導將非常感激，因爲我用這個撓我的頭！先謝謝你！

西蒙

Answer 1

我無法弄清楚如何顯示標準輸出/ 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 $_} 

這工作，但我不知道這是否是最好的做法還是不 - 這似乎是有效的而且可靠。

Answer 2

您不能使用獲取最新登錄立即時間。您應該訪問Powershell的TimeGenerated。

一個樣本實施例：

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

它會給你該事件的確切時間。 在你的情況，你可以用下面的：

$Event.TimeGenerated.ToString("AnyFormat")