read the process output in a thread safe way, fixes #1051 (#1053)

* read the process output in a thread safe way, fixes #1051

* this test started to fail, most probably due to an AppVeyor change

* this test takes a LOT of time and since we have new InProcessEmitToolchain we can disable it

* disable UserCanSpecifyCustomNuGetPackageDependency which is for some reason this test is unstable on Ubuntu for both AzureDevOps and Travis CI

src/BenchmarkDotNet/Diagnosers/MonoDisassembler.cs

@@ -42,7 +42,7 @@ namespace BenchmarkDotNet.Diagnosers
             string monoPath = mono?.CustomPath ?? "mono";
             string arguments = $"--compile {fqnMethod} {llvmFlag} {exePath}";
 
-            (int exitCode, IReadOnlyList<string> output) = ProcessHelper.RunAndReadOutputLineByLine(monoPath, arguments, environmentVariables: environmentVariables, includeErrors: true);
+            var (exitCode, output) = ProcessHelper.RunAndReadOutputLineByLine(monoPath, arguments, environmentVariables: environmentVariables, includeErrors: true);
             string commandLine = $"{GetEnvironmentVariables(environmentVariables)} {monoPath} {arguments}";
             
             return OutputParser.Parse(output, benchmarkTarget.WorkloadMethod.Name, commandLine);

src/BenchmarkDotNet/Helpers/ProcessHelper.cs

@@ -1,6 +1,8 @@
 using System;
 using System.Collections.Generic;
+using System.Collections.Immutable;
 using System.Diagnostics;
+using BenchmarkDotNet.Loggers;
 using JetBrains.Annotations;
 
 namespace BenchmarkDotNet.Helpers
@@ -40,11 +42,9 @@ namespace BenchmarkDotNet.Helpers
             }
         }
 
-        internal static (int exitCode, IReadOnlyList<string> output) RunAndReadOutputLineByLine(string fileName, string arguments = "", string workingDirectory = "",
+        internal static (int exitCode, ImmutableArray<string> output) RunAndReadOutputLineByLine(string fileName, string arguments = "", string workingDirectory = "",
             Dictionary<string, string> environmentVariables = null, bool includeErrors = false)
         {
-            var output = new List<string>(20000);
-
             var processStartInfo = new ProcessStartInfo
             {
                 FileName = fileName,
@@ -61,21 +61,18 @@ namespace BenchmarkDotNet.Helpers
                     processStartInfo.Environment[environmentVariable.Key] = environmentVariable.Value;
 
             using (var process = new Process { StartInfo = processStartInfo })
+            using (var outputReader = new AsyncProcessOutputReader(process))
             {
-                process.OutputDataReceived += (sender, args) => output.Add(args.Data);
-                process.ErrorDataReceived += (sender, args) =>
-                {
-                    if (includeErrors)
-                        output.Add(args.Data);
-                };
-
                 process.Start();
 
-                process.BeginOutputReadLine();
-                process.BeginErrorReadLine();
+                outputReader.BeginRead();
 
                 process.WaitForExit();
 
+                outputReader.StopRead();
+
+                var output = includeErrors ? outputReader.GetOutputAndErrorLines() : outputReader.GetOutputLines();
+
                 return (process.ExitCode, output);
             }
         }

src/BenchmarkDotNet/Loggers/AsyncProcessOutputReader.cs

@@ -0,0 +1,114 @@
+using System;
+using System.Collections.Concurrent;
+using System.Collections.Immutable;
+using System.Diagnostics;
+using System.Linq;
+using System.Threading;
+
+namespace BenchmarkDotNet.Loggers
+{
+    internal class AsyncProcessOutputReader : IDisposable
+    {
+        private readonly Process process;
+        private readonly ConcurrentStack<string> output, error;
+
+        private long status;
+
+        internal AsyncProcessOutputReader(Process process)
+        {
+            if (!process.StartInfo.RedirectStandardOutput)
+                throw new NotSupportedException("set RedirectStandardOutput to true first");
+            if (!process.StartInfo.RedirectStandardError)
+                throw new NotSupportedException("set RedirectStandardError to true first");
+
+            this.process = process;
+            output = new ConcurrentStack<string>();
+            error = new ConcurrentStack<string>();
+            status = (long)Status.Created;
+        }
+
+        public void Dispose()
+        {
+            Interlocked.Exchange(ref status, (long)Status.Disposed);
+
+            Detach();
+        }
+
+        internal void BeginRead()
+        {
+            if (Interlocked.CompareExchange(ref status, (long)Status.Started, (long)Status.Created) != (long)Status.Created)
+                throw new InvalidOperationException("Reader can be started only once");
+
+            Attach();
+
+            process.BeginOutputReadLine();
+            process.BeginErrorReadLine();
+        }
+
+        internal void CancelRead()
+        {
+            if (Interlocked.CompareExchange(ref status, (long)Status.Stopped, (long)Status.Started) != (long)Status.Started)
+                throw new InvalidOperationException("Only a started reader can be stopped");
+
+            process.CancelOutputRead();
+            process.CancelErrorRead();
+
+            Detach();
+        }
+
+        internal void StopRead()
+        {
+            if (Interlocked.CompareExchange(ref status, (long)Status.Stopped, (long)Status.Started) != (long)Status.Started)
+                throw new InvalidOperationException("Only a started reader can be stopped");
+
+            Detach();
+        }
+
+        internal ImmutableArray<string> GetOutputLines() => ReturnIfStopped(() => output.ToImmutableArray());
+
+        internal ImmutableArray<string> GetErrorLines() => ReturnIfStopped(() => error.ToImmutableArray());
+
+        internal ImmutableArray<string> GetOutputAndErrorLines() => ReturnIfStopped(() => output.Concat(error).ToImmutableArray());
+
+        internal string GetOutputText() => ReturnIfStopped(() => string.Join(Environment.NewLine, output));
+
+        internal string GetErrorText() => ReturnIfStopped(() => string.Join(Environment.NewLine, error));
+
+        private void Attach()
+        {
+            process.OutputDataReceived += ProcessOnOutputDataReceived;
+            process.ErrorDataReceived += ProcessOnErrorDataReceived;
+        }
+
+        private void Detach()
+        {
+            process.OutputDataReceived -= ProcessOnOutputDataReceived;
+            process.ErrorDataReceived -= ProcessOnErrorDataReceived;
+        }
+
+        private void ProcessOnOutputDataReceived(object sender, DataReceivedEventArgs e)
+        {
+            if (!string.IsNullOrEmpty(e.Data))
+                output.Push(e.Data);
+        }
+
+        private void ProcessOnErrorDataReceived(object sender, DataReceivedEventArgs e)
+        {
+            if (!string.IsNullOrEmpty(e.Data))
+                error.Push(e.Data);
+        }
+
+        private T ReturnIfStopped<T>(Func<T> getter)
+            => Interlocked.Read(ref status) == (long)Status.Stopped
+                ? getter.Invoke()
+                : throw new InvalidOperationException("The reader must be stopped first");
+
+        private enum Status : long
+        {
+            Created,
+            Started,
+            Stopped,
+            Disposed
+        }
+    }
+}

src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliCommandExecutor.cs

@@ -3,7 +3,6 @@ using System.Collections.Generic;
 using System.ComponentModel;
 using System.Diagnostics;
 using System.Linq;
-using System.Text;
 using System.Text.RegularExpressions;
 using BenchmarkDotNet.Extensions;
 using BenchmarkDotNet.Jobs;
@@ -19,38 +18,33 @@ namespace BenchmarkDotNet.Toolchains.DotNetCli
         public static DotNetCliCommandResult Execute(DotNetCliCommand parameters)
         {
             using (var process = new Process { StartInfo = BuildStartInfo(parameters.CliPath, parameters.GenerateResult.ArtifactsPaths.BuildArtifactsDirectoryPath, parameters.Arguments, parameters.EnvironmentVariables) })
+            using (var outputReader = new AsyncProcessOutputReader(process))
             {
                 parameters.Logger.WriteLineInfo($"// start {parameters.CliPath ?? "dotnet"} {parameters.Arguments} in {parameters.GenerateResult.ArtifactsPaths.BuildArtifactsDirectoryPath}");
 
-                var standardOutput = new StringBuilder();
-                var standardError = new StringBuilder();
-
-                process.OutputDataReceived += (sender, args) => standardOutput.AppendLine(args.Data);
-                process.ErrorDataReceived += (sender, args) => standardError.AppendLine(args.Data);
-                
                 var stopwatch = Stopwatch.StartNew();
 
                 process.Start();
-
-                process.BeginOutputReadLine();
-                process.BeginErrorReadLine();
+                outputReader.BeginRead();
 
                 if (!process.WaitForExit((int)parameters.Timeout.TotalMilliseconds))
                 {
                     parameters.Logger.WriteLineError($"// command took more that the timeout: {parameters.Timeout.TotalSeconds:0.##}s. Killing the process tree!");
 
+                    outputReader.CancelRead();
                     process.KillTree();
-                    
-                    return DotNetCliCommandResult.Failure(stopwatch.Elapsed, $"The configured timeout {parameters.Timeout} was reached!" + standardError.ToString(), standardOutput.ToString());
+
+                    return DotNetCliCommandResult.Failure(stopwatch.Elapsed, $"The configured timeout {parameters.Timeout} was reached!" + outputReader.GetErrorText(), outputReader.GetOutputText());
                 }
 
                 stopwatch.Stop();
+                outputReader.StopRead();
 
                 parameters.Logger.WriteLineInfo($"// command took {stopwatch.Elapsed.TotalSeconds:0.##}s and exited with {process.ExitCode}");
 
                 return process.ExitCode <= 0
-                    ? DotNetCliCommandResult.Success(stopwatch.Elapsed, standardOutput.ToString())
-                    : DotNetCliCommandResult.Failure(stopwatch.Elapsed, standardError.ToString(), standardOutput.ToString());
+                    ? DotNetCliCommandResult.Success(stopwatch.Elapsed, outputReader.GetOutputText())
+                    : DotNetCliCommandResult.Failure(stopwatch.Elapsed, outputReader.GetOutputText(), outputReader.GetErrorText());
             }
         }
         

src/BenchmarkDotNet/Toolchains/Mono/MonoAotBuilder.cs

@@ -22,12 +22,12 @@ namespace BenchmarkDotNet.Toolchains.Mono
                 return result;
 
             var exePath = generateResult.ArtifactsPaths.ExecutablePath;
-            var monoRuntime = buildPartition.Runtime as MonoRuntime;
+            var monoRuntime = (MonoRuntime)buildPartition.Runtime;
             var environmentVariables = string.IsNullOrEmpty(monoRuntime.MonoBclPath)
                 ? null
-                : new Dictionary<string, string>() { { "MONO_PATH", monoRuntime.MonoBclPath } };
+                : new Dictionary<string, string> { { "MONO_PATH", monoRuntime.MonoBclPath } };
 
-            (int exitCode, IReadOnlyList<string> output) = ProcessHelper.RunAndReadOutputLineByLine(
+            var (exitCode, output) = ProcessHelper.RunAndReadOutputLineByLine(
                 fileName: monoRuntime.CustomPath ?? "mono",
                 arguments: $"{monoRuntime.AotArgs} \"{Path.GetFullPath(exePath)}\"",
                 workingDirectory: Path.GetDirectoryName(exePath),

tests/BenchmarkDotNet.IntegrationTests/MemoryDiagnoserTests.cs

@@ -19,7 +19,6 @@ using BenchmarkDotNet.Tests.Loggers;
 using BenchmarkDotNet.Tests.XUnit;
 using BenchmarkDotNet.Toolchains;
 using BenchmarkDotNet.Toolchains.CoreRt;
-using BenchmarkDotNet.Toolchains.InProcess;
 using BenchmarkDotNet.Toolchains.InProcess.Emit;
 using Xunit;
 using Xunit.Abstractions;
@@ -38,7 +37,7 @@ namespace BenchmarkDotNet.IntegrationTests
                 : new[]
                 {
                     new object[] { Job.Default.GetToolchain() },
-                    new object[] { InProcessToolchain.Instance },
+                    // new object[] { InProcessToolchain.Instance }, // this test takes a LOT of time and since we have new InProcessEmitToolchain we can disable it 
                     new object[] { InProcessEmitToolchain.Instance },
 #if NETCOREAPP2_1 
                     // we don't want to test CoreRT twice (for .NET 4.6 and Core 2.1) when running the integration tests (these tests take a lot of time)

tests/BenchmarkDotNet.IntegrationTests/NugetReferenceTests.cs

@@ -1,5 +1,4 @@
-using BenchmarkDotNet.Configs;
-using BenchmarkDotNet.Jobs;
+using BenchmarkDotNet.Jobs;
 using Xunit;
 using Xunit.Abstractions;
 using BenchmarkDotNet.Portability;
@@ -11,6 +10,7 @@ using BenchmarkDotNet.Toolchains.Roslyn;
 using BenchmarkDotNet.Running;
 using BenchmarkDotNet.Loggers;
 using System.Collections.Immutable;
+using BenchmarkDotNet.Tests.XUnit;
 
 namespace BenchmarkDotNet.IntegrationTests
 {
@@ -18,7 +18,7 @@ namespace BenchmarkDotNet.IntegrationTests
     {
         public NuGetReferenceTests(ITestOutputHelper output) : base(output) { }
 
-        [Fact]
+        [FactNotLinux("For some reason this test is unstable on Ubuntu for both AzureDevOps and Travis CI")]
         public void UserCanSpecifyCustomNuGetPackageDependency()
         {
             var toolchain = RuntimeInformation.IsFullFramework

tests/BenchmarkDotNet.Tests/Portability/RuntimeInformationTests.cs

@@ -1,17 +0,0 @@
-using BenchmarkDotNet.Portability;
-using BenchmarkDotNet.Tests.XUnit;
-using Xunit;
-
-namespace BenchmarkDotNet.Tests.Portability
-{
-    public class RuntimeInformationTests
-    {
-        [AppVeyorWithClrOnlyFact]
-        public void DetectsHyperVOnAppveyor()
-        {
-            VirtualMachineHypervisor hypervisor = RuntimeInformation.GetVirtualMachineHypervisor();
-
-            Assert.Equal(hypervisor, HyperV.Default);
-        }
-    }
-}

tests/BenchmarkDotNet.Tests/XUnit/AppveyorOnlyFactAttribute.cs

@@ -1,21 +0,0 @@
-using System;
-using BenchmarkDotNet.Portability;
-using Xunit;
-
-namespace BenchmarkDotNet.Tests.XUnit
-{
-    public class AppVeyorOnlyFactAttribute : FactAttribute
-    {
-        private const string Message = "Test is available only on the AppVeyor";
-        private static readonly string skip;
-
-        static AppVeyorOnlyFactAttribute()
-        {
-            string value = Environment.GetEnvironmentVariable("APPVEYOR");
-            bool appVeyorDetected = !string.IsNullOrEmpty(value) && value.EqualsWithIgnoreCase("true");
-            skip = appVeyorDetected ? null : Message;
-        }
-
-        public override string Skip => skip;
-    }
-}

tests/BenchmarkDotNet.Tests/XUnit/AppveyorWithClrOnlyFactAttribute.cs

@@ -1,11 +0,0 @@
-using BenchmarkDotNet.Portability;
-
-namespace BenchmarkDotNet.Tests.XUnit
-{
-    public class AppVeyorWithClrOnlyFactAttribute : AppVeyorOnlyFactAttribute
-    {
-        private const string Message = "Test requires CLR";
-
-        public override string Skip => base.Skip ?? (RuntimeInformation.IsFullFramework ? null : Message);
-    }
-}

tests/BenchmarkDotNet.Tests/XUnit/FactNotLinuxAttribute.cs

@@ -0,0 +1,15 @@
+using BenchmarkDotNet.Portability;
+using Xunit;
+
+namespace BenchmarkDotNet.Tests.XUnit
+{
+    public class FactNotLinuxAttribute : FactAttribute
+    {
+        // ReSharper disable once VirtualMemberCallInConstructor
+        public FactNotLinuxAttribute(string linuxSkipReason)
+        {
+            if (RuntimeInformation.IsLinux())
+                Skip = linuxSkipReason;
+        }
+    }
+}