PS exe output and error redirection

bla.cs

namespace Test
{
	using System;
	using System.Linq;

	class Program
	{
		public static void Main(string[] args)
		{
			// pipe buffers seem to be around 4100 bytes on my system
			var lines = 0 < args.Length ? int.Parse(args[0]) : 100;
			var o = string.Join(string.Empty, Enumerable.Repeat("o", 50));
			var e = string.Join(string.Empty, Enumerable.Repeat("e", 50));
			for (int i = 0; i < lines; i++)
			{
				Console.Out.WriteLine(o);
				Console.Error.WriteLine(e);
			}

			Console.WriteLine("done");
		}
	}
}

test-redirection.ps1

Param (
    $method = 'naive',
    $lines = 78, # deadlock happens at 79+
    $iterations = 10,
    [switch] $sleepAfterRoe
)
$ErrorActionPreference = 'Stop'

$scriptDir = Split-Path $MyInvocation.MyCommand.Path

$exe = Join-Path $scriptDir bla.exe
if (-not (Test-Path $exe)) {
    csc (Resolve-Path (Join-Path $scriptDir))
}

$exe = Resolve-Path $exe

$times = New-Object System.Collections.ArrayList

# Helper function to emit an IL opcode
function emit($opcode)
{
    if ( ! ($op = [System.Reflection.Emit.OpCodes]::($opcode)))
    {
        throw "new-method: opcode '$opcode' is undefined"
    }

    if ($args.Length -gt 0)
    {
        $ilg.Emit($op, $args[0])
    }
    else
    {
        $ilg.Emit($op)
    }
}

$Source = @" 
using System;
using System.Collections;
using System.Diagnostics;
using System.IO;

namespace DeadlockTest
{ 
    public class ReceiverToFile
    {
        private StreamWriter sw;

        public ReceiverToFile(StreamWriter sw)
        {
            this.sw = sw;
        }

        public void AttachError(Process p)
        {
            p.ErrorDataReceived += this.OnData;
        }

        private void OnData(object sender, DataReceivedEventArgs e)
        {
            sw.WriteLine(e.Data);
        }
    } 

    public class ReceiverToList
    {
        public ArrayList Storage { get; set; }

        public void AttachError(Process p)
        {
            p.ErrorDataReceived += this.OnData;
        }

        private void OnData(object sender, DataReceivedEventArgs e)
        {
            this.Storage.Add(e.Data);
        }
    } 
} 
"@

function Test()
{

    $global:output = New-Object System.Collections.ArrayList
    $global:errors = New-Object System.Collections.ArrayList
    $process = New-Object System.Diagnostics.Process
    $process.StartInfo = New-Object System.Diagnostics.ProcessStartInfo($exe, $lines)
    $process.StartInfo.RedirectStandardOutput = $true
    $process.StartInfo.RedirectStandardError = $true
    $process.StartInfo.UseShellExecute = $false

    $sw = New-Object System.Diagnostics.Stopwatch
    $sw.Start()

    switch ($method) {
        'naive' {}
        'roe' {
                $process.EnableRaisingEvents = $true
                $onOutput = { $EventArgs.Data | % { $global:output.Add($_) | Out-Null } }
                $onError  = { $EventArgs.Data | % { $global:errors.Add($_) | Out-Null } }
                Register-ObjectEvent -InputObject $process -SourceIdentifier "DeadlockTestOutput" -EventName OutputDataReceived -Action $onOutput | Out-Null
                Register-ObjectEvent -InputObject $process -SourceIdentifier "DeadlockTestErrors" -EventName ErrorDataReceived  -Action $onError  | Out-Null
            }
        'errorfile' {
                Add-Type -TypeDefinition $Source -Language CSharp  
                $process.EnableRaisingEvents = $true
                $errorFile = Join-Path $scriptDir errors.txt
                $global:errorFileWriter = [IO.File]::CreateText($errorFile)
                $recv = New-Object DeadlockTest.ReceiverToFile $global:errorFileWriter
                $recv.AttachError($process)
            }
        'errorbuffer' {
                Add-Type -TypeDefinition $Source -Language CSharp  
                $process.EnableRaisingEvents = $true
                $recv = New-Object DeadlockTest.ReceiverToList
                $recv.Storage = [System.Collections.ArrayList]$global:errors
                $recv.AttachError($process)
            }
        'task' {}
        'bigguns' {
                $process.EnableRaisingEvents = $true

                #$sw2 = New-Object System.Diagnostics.Stopwatch
                #$sw2.Start()
                $dynMethod = New-Object System.Reflection.Emit.DynamicMethod ('', [void], (@([Collections.ArrayList],[Object],[System.Diagnostics.DataReceivedEventArgs])), [object], $false)
                $ilg = $dynMethod.GetILGenerator()
                emit Ldarg_0
                emit Ldarg_2
                emit Call ([Collections.ArrayList].GetMethod('Add'))
                $del = $dynMethod.CreateDelegate([System.Diagnostics.DataReceivedEventHandler], $global:errors)
                #Write-Host "Delegate construction: $($sw2.ElapsedMilliseconds) ms"

                $process.add_ErrorDataReceived($del)
            }
        'begininvoke' {
                Add-Type -AssemblyName System.Core
            }
        default { throw "unknown method: $method" }
    }

    $process.Start() | Out-Null

    # powershell -version 4 -command ".\test-redirection.ps1 -iterations 20 -method task -lines 78"
    switch ($method) {
        'naive' {
                # first call 50 ms, later 30 ms
                # fastest, but deadlocks at 79+ lines
                $global:output = $process.StandardOutput.ReadToEnd()
                $global:errors = $process.StandardError.ReadToEnd()
            }
        'roe' {
                # first call 125 ms, later 80-120 ms
                # all calls about twice time of naive, UNRELIABLE (no deterministic wait possible)
                $process.BeginOutputReadLine()
                $process.BeginErrorReadLine()
            }
        'errorfile' {
                # first call 195 ms, later 30 ms
                # slowest first call (4x naive), but later as fast as the leaders
                $process.BeginErrorReadLine()
                $global:output = $process.StandardOutput.ReadToEnd()
            }
        'errorbuffer' {
                # first call 180 ms, later 30 ms
                # marginally better than errorfile
                $process.BeginErrorReadLine()
                $global:output = $process.StandardOutput.ReadToEnd()
            }
        'task' {
                # first call 60 ms, later 30 ms
                # second fastest (by a whisker), close to naive, cleanest code, but requires .NET 4, so PS 3+
                $errorReadTask = $process.StandardError.ReadToEndAsync()
                $global:output = $process.StandardOutput.ReadToEnd()
            }
        'bigguns' {
                # first call 125 ms, later 30 ms
                # first call twice time of naive, later as fast as the leaders
                $process.BeginErrorReadLine()
                $global:output = $process.StandardOutput.ReadToEnd()
            }
        'begininvoke' {
                # first call 65 ms, later 30 ms
                # third fastest, requires .NET 3.5 (works on PS 2)
                $del = [Delegate]::CreateDelegate([Func``1[[System.String, mscorlib, Version=2.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089]]],$process.StandardError,'ReadToEnd')
                $errorReadAsyncResult = $del.BeginInvoke($null, $null)
                $global:output = $process.StandardOutput.ReadToEnd()
            }
    }

    $process.WaitForExit()

    switch ($method) {
        'naive' {}
        'roe' {
                Unregister-Event -SourceIdentifier "DeadlockTestOutput"
                Unregister-Event -SourceIdentifier "DeadlockTestErrors"
            }
        'errorfile' {
                $recv = $null
                $global:errorFileWriter.Close()
                $global:errors = [IO.File]::ReadAllText($errorFile)
            }
        'errorbuffer' {
                $recv = $null
            }
        'task' {
                $global:errors = $errorReadTask.Result
            }
        'bigguns' {
                foreach ($ea in $dic.Values) {
                    $global:errors.Add($ea.Data)
                }
            }
        'begininvoke' {
                $global:errors = $del.EndInvoke($errorReadAsyncResult)
            }
    }

    $ms = $sw.ElapsedMilliseconds
    #"Elapsed: $ms ms"
    $times.Add($ms) | Out-Null

    if ($sleepAfterRoe -and $method -eq 'roe') {
        # this sleep mitigates the unreliability of events passing through Register-ObjectEvent
        # (no way to wait for all of them to be processed), allowing the test code to finish
        Start-Sleep -Milliseconds 300
    }

    #"Exit code: $($process.ExitCode)"
    #"Output length: $($global:output.Count) or $($global:output.Length)"
    #"Errors length: $($global:errors.Count) or $($global:errors.Length)"
    if ($process.ExitCode -ne 0) { throw "Process exited with code $($process.ExitCode)" }
    if ($global:output.Count -eq 0) { throw "Standard output not captured" }
    if ($global:errors.Count -eq 0) { throw "Standard error not captured" }

    if ($method -eq 'roe') {
        # note: std output will have 1 line more than both std err and $lines ('done')
        # the arrays will have a zero-length element at the end
        if ($global:output.Count -ne ($lines + 2)) { throw "Standard output not captured in its entirety (got $($global:output.Count - 1) lines instead of $($lines + 1)" }
        if ($global:errors.Count -ne ($lines + 1)) { throw "Standard error not captured in its entirety (got $($global:errors.Count - 1) lines instead of $lines" }
    }
}

"Method: $method"
"Std output length: $($lines*(50+2)+6)" # 50 chars per line, 2 chars for crlf, 6 chars for the 'done' line
"Std error length: $($lines*(50+2))" # 50 chars per line, 2 chars for crlf

1..$iterations | % { $i = $_; try { Test } catch { Write-Host "Failed on iteration $i"; throw } }

$times
$times | Measure-Object -Average -Maximum -Minimum
"First:"
$times | Select-Object -First 1