Dispose parameters, kill benchmarking process when it hangs after printing the results (#1571)

* add test

* dispose unused dispsable parameters

* stop the benchmark process output stream processing after receiving the last signal

* don't try to read the standard error as it might also hang

the benchmark process is catching all exceptions and writing to standard output, so it's OK (this is what the class Executor does already)

* kill benchmarking process if it does not quit within 250ms after finishing benchmarking

* exit code can be != 0 for benchmarks that have executed fine but hanged after printing the results

* some benchmarks might be using parameters that have locking finalizers

so we need to dispose them after we are done running the benchmarks

see #1383 and dotnet/runtime#314 for more

Author: adamsitnik

src/BenchmarkDotNet/Helpers/ConsoleExitHandler.cs

@@ -57,7 +57,7 @@ private void Detach()
         // the user has closed the console window so we kill the entire process tree
         private void ProcessExitEventHandlerHandlerCallback(object sender, EventArgs e) => KillProcessTree();
 
-        private void KillProcessTree()
+        internal void KillProcessTree()
         {
             try
             {

src/BenchmarkDotNet/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs

@@ -55,6 +55,13 @@ internal void ProcessInput()
                 {
                     diagnoser?.Handle(signal, diagnoserActionParameters);
                     process.StandardInput.WriteLine(Engine.Signals.Acknowledgment);
+
+                    if (signal == HostSignal.AfterAll)
+                    {
+                        // we have received the last signal so we can stop reading the output
+                        // if the process won't exit after this, its hung and needs to be killed
+                        return;
+                    }
                 }
                 else if (!string.IsNullOrEmpty(line))
                 {

src/BenchmarkDotNet/Parameters/ParameterInstance.cs

@@ -8,7 +8,7 @@
 
 namespace BenchmarkDotNet.Parameters
 {
-    public class ParameterInstance
+    public class ParameterInstance : IDisposable
     {
         public const string NullParameterTextRepresentation = "?";
 
@@ -24,6 +24,8 @@ public ParameterInstance(ParameterDefinition definition, object value, SummarySt
             maxParameterColumnWidth = summaryStyle?.MaxParameterColumnWidth ?? SummaryStyle.DefaultMaxParameterColumnWidth;
         }
 
+        public void Dispose() => (Value as IDisposable)?.Dispose();
+
         public string Name => Definition.Name;
         public bool IsStatic => Definition.IsStatic;
         public bool IsArgument => Definition.IsArgument;

src/BenchmarkDotNet/Parameters/ParameterInstances.cs

@@ -1,10 +1,11 @@
-using System.Collections.Generic;
+using System;
+using System.Collections.Generic;
 using System.Linq;
 using BenchmarkDotNet.Extensions;
 
 namespace BenchmarkDotNet.Parameters
 {
-    public class ParameterInstances
+    public class ParameterInstances : IDisposable
     {
         public IReadOnlyList<ParameterInstance> Items { get; }
         public int Count => Items.Count;
@@ -18,6 +19,14 @@ public ParameterInstances(IReadOnlyList<ParameterInstance> items)
             Items = items;
         }
 
+        public void Dispose()
+        {
+            foreach (var parameterInstance in Items)
+            {
+                parameterInstance.Dispose();
+            }
+        }
+
         public string FolderInfo => string.Join("_", Items.Select(p => $"{p.Name}-{p.ToDisplayText()}")).AsValidFileName();
 
         public string DisplayInfo =>  Items.Any() ? "[" + string.Join(", ", Items.Select(p => $"{p.Name}={p.ToDisplayText()}")) + "]" : "";

src/BenchmarkDotNet/Parameters/SmartParamBuilder.cs

@@ -1,4 +1,6 @@
 using System;
+using System.Collections.Generic;
+using System.ComponentModel;
 using System.Diagnostics.CodeAnalysis;
 using System.Linq;
 using System.Reflection;
@@ -97,9 +99,8 @@ public string ToSourceCode()
                 ? $"[{argumentIndex}]" // IEnumerable<object[]>
                 : string.Empty; // IEnumerable<object>
 
-            // we just execute (cast)source.ToArray()[case][argumentIndex];
-            // we know that source is IEnumerable so we can do that!
-            return $"{cast}System.Linq.Enumerable.ToArray({source.Name}{callPostfix})[{sourceIndex}]{indexPostfix};";
+            // we do something like enumerable.ElementAt(sourceIndex)[argumentIndex];
+            return $"{cast}BenchmarkDotNet.Parameters.ParameterExtractor.GetParameter({source.Name}{callPostfix}, {sourceIndex}){indexPostfix};";
         }
     }
 
@@ -129,8 +130,38 @@ public string ToSourceCode()
 
             string callPostfix = source is PropertyInfo ? string.Empty : "()";
 
-            // we just execute (cast)source.ToArray()[index];
-            return $"{cast}System.Linq.Enumerable.ToArray({instancePrefix}.{source.Name}{callPostfix})[{index}];";
+            // we so something like enumerable.ElementAt(index);
+            return $"{cast}BenchmarkDotNet.Parameters.ParameterExtractor.GetParameter({instancePrefix}.{source.Name}{callPostfix}, {index});";
+        }
+    }
+
+    public static class ParameterExtractor
+    {
+        [EditorBrowsable(EditorBrowsableState.Never)] // hide from intellisense, it's public so we can call it form the boilerplate code
+        public static T GetParameter<T>(IEnumerable<T> parameters, int index)
+        {
+            int count = 0;
+
+            foreach (T parameter in parameters)
+            {
+                if (count == index)
+                {
+                    return parameter;
+                }
+
+                if (parameter is IDisposable disposable)
+                {
+                    // parameters might contain locking finalizers which might cause the benchmarking process to hung at the end
+                    // to avoid that, we dispose the parameters that were created, but won't be used
+                    // (for every test case we have to enumerate the underlying source enumerator and stop when we reach index of given test case)
+                    // See https://github.com/dotnet/BenchmarkDotNet/issues/1383 and https://github.com/dotnet/runtime/issues/314 for more
+                    disposable.Dispose();
+                }
+
+                count++;
+            }
+
+            throw new InvalidOperationException("We should never get here!");
         }
     }
 }

src/BenchmarkDotNet/Running/BenchmarkCase.cs

@@ -6,7 +6,7 @@
 
 namespace BenchmarkDotNet.Running
 {
-    public class BenchmarkCase : IComparable<BenchmarkCase>
+    public class BenchmarkCase : IComparable<BenchmarkCase>, IDisposable
     {
         public Descriptor Descriptor { get; }
         public Job Job { get; }
@@ -26,6 +26,8 @@ private BenchmarkCase(Descriptor descriptor, Job job, ParameterInstances paramet
             Config = config;
         }
 
+        public void Dispose() => Parameters.Dispose();
+
         public int CompareTo(BenchmarkCase other) => string.Compare(FolderInfo, other.FolderInfo, StringComparison.Ordinal);
 
         public bool HasParameters => Parameters != null && Parameters.Items.Any();

src/BenchmarkDotNet/Running/BenchmarkRunInfo.cs

@@ -3,7 +3,7 @@
 
 namespace BenchmarkDotNet.Running
 {
-    public class BenchmarkRunInfo
+    public class BenchmarkRunInfo : IDisposable
     {
         public BenchmarkRunInfo(BenchmarkCase[] benchmarksCase, Type type, ImmutableConfig config)
         {
@@ -12,6 +12,14 @@ public BenchmarkRunInfo(BenchmarkCase[] benchmarksCase, Type type, ImmutableConf
             Config = config;
         }
 
+        public void Dispose()
+        {
+            foreach (var benchmarkCase in BenchmarksCases)
+            {
+                benchmarkCase.Dispose();
+            }
+        }
+
         public BenchmarkCase[] BenchmarksCases { get; }
         public Type Type { get; }
         public ImmutableConfig Config { get; }

src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs

@@ -107,6 +107,14 @@ internal static Summary[] Run(BenchmarkRunInfo[] benchmarkRunInfos)
                 }
                 finally
                 {
+                    // some benchmarks might be using parameters that have locking finalizers
+                    // so we need to dispose them after we are done running the benchmarks
+                    // see https://github.com/dotnet/BenchmarkDotNet/issues/1383 and https://github.com/dotnet/runtime/issues/314 for more
+                    foreach (var benchmarkInfo in benchmarkRunInfos)
+                    {
+                        benchmarkInfo.Dispose();
+                    }
+
                     compositeLogger.WriteLineHeader("// * Artifacts cleanup *");
                     Cleanup(new HashSet<string>(artifactsToCleanup.Distinct()));
                     compositeLogger.Flush();
@@ -509,10 +517,12 @@ private static ExecuteResult RunExecute(ILogger logger, BenchmarkCase benchmarkC
                 logger.WriteLineError($"Executable {buildResult.ArtifactsPaths.ExecutablePath} not found");
             }
 
-            if (executeResult.ExitCode != 0)
+            // exit code can be different than 0 if the process has hanged at the end
+            // so we check if some results were reported, if not then it was a failure
+            if (executeResult.ExitCode != 0 && executeResult.Data.IsEmpty())
             {
                 success = false;
-                logger.WriteLineError("ExitCode != 0");
+                logger.WriteLineError("ExitCode != 0 and no results reported");
             }
 
             return executeResult;

src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs

@@ -69,7 +69,7 @@ private ExecuteResult Execute(BenchmarkCase benchmarkCase,
             startInfo.SetEnvironmentVariables(benchmarkCase, resolver);
 
             using (var process = new Process { StartInfo = startInfo })
-            using (new ConsoleExitHandler(process, logger))
+            using (var consoleExitHandler = new ConsoleExitHandler(process, logger))
             {
                 var loggerWithDiagnoser = new SynchronousProcessOutputLoggerWithDiagnoser(logger, process, diagnoser, benchmarkCase, benchmarkId);
 
@@ -86,21 +86,15 @@ private ExecuteResult Execute(BenchmarkCase benchmarkCase,
                 }
 
                 loggerWithDiagnoser.ProcessInput();
-                string standardError = process.StandardError.ReadToEnd();
 
-                process.WaitForExit(); // should we add timeout here?
-
-                if (process.ExitCode == 0)
+                if (!process.WaitForExit(milliseconds: 250))
                 {
-                    return new ExecuteResult(true, process.ExitCode, process.Id, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput);
-                }
+                    logger.WriteLineInfo("// The benchmarking process did not quit on time, it's going to get force killed now.");
 
-                if (!string.IsNullOrEmpty(standardError))
-                {
-                    logger.WriteError(standardError);
+                    consoleExitHandler.KillProcessTree();
                 }
 
-                return new ExecuteResult(true, process.ExitCode, process.Id, Array.Empty<string>(), Array.Empty<string>());
+                return new ExecuteResult(true, process.ExitCode, process.Id, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput);
             }
         }
     }

src/BenchmarkDotNet/Toolchains/Executor.cs

@@ -40,13 +40,13 @@ private ExecuteResult Execute(BenchmarkCase benchmarkCase, BenchmarkId benchmark
             try
             {
                 using (var process = new Process { StartInfo = CreateStartInfo(benchmarkCase, artifactsPaths, args, resolver) })
-                using (new ConsoleExitHandler(process, logger))
+                using (var consoleExitHandler = new ConsoleExitHandler(process, logger))
                 {
                     var loggerWithDiagnoser = new SynchronousProcessOutputLoggerWithDiagnoser(logger, process, diagnoser, benchmarkCase, benchmarkId);
 
                     diagnoser?.Handle(HostSignal.BeforeProcessStart, new DiagnoserActionParameters(process, benchmarkCase, benchmarkId));
 
-                    return Execute(process, benchmarkCase, loggerWithDiagnoser, logger);
+                    return Execute(process, benchmarkCase, loggerWithDiagnoser, logger, consoleExitHandler);
                 }
             }
             finally
@@ -55,7 +55,7 @@ private ExecuteResult Execute(BenchmarkCase benchmarkCase, BenchmarkId benchmark
             }
         }
 
-        private ExecuteResult Execute(Process process, BenchmarkCase benchmarkCase, SynchronousProcessOutputLoggerWithDiagnoser loggerWithDiagnoser, ILogger logger)
+        private ExecuteResult Execute(Process process, BenchmarkCase benchmarkCase, SynchronousProcessOutputLoggerWithDiagnoser loggerWithDiagnoser, ILogger logger, ConsoleExitHandler consoleExitHandler)
         {
             logger.WriteLineInfo($"// Execute: {process.StartInfo.FileName} {process.StartInfo.Arguments} in {process.StartInfo.WorkingDirectory}");
 
@@ -69,17 +69,17 @@ private ExecuteResult Execute(Process process, BenchmarkCase benchmarkCase, Sync
 
             loggerWithDiagnoser.ProcessInput();
 
-            process.WaitForExit(); // should we add timeout here?
-
-            if (process.ExitCode == 0)
+            if (!process.WaitForExit(milliseconds: 250))
             {
-                return new ExecuteResult(true, process.ExitCode, process.Id, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput);
+                logger.WriteLineInfo("// The benchmarking process did not quit on time, it's going to get force killed now.");
+
+                consoleExitHandler.KillProcessTree();
             }
 
             if (loggerWithDiagnoser.LinesWithResults.Any(line => line.Contains("BadImageFormatException")))
                 logger.WriteLineError("You are probably missing <PlatformTarget>AnyCPU</PlatformTarget> in your .csproj file.");
 
-            return new ExecuteResult(true, process.ExitCode, process.Id, Array.Empty<string>(), Array.Empty<string>());
+            return new ExecuteResult(true, process.ExitCode, process.Id, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput);
         }
 
         private ProcessStartInfo CreateStartInfo(BenchmarkCase benchmarkCase, ArtifactsPaths artifactsPaths, string args, IResolver resolver)

tests/BenchmarkDotNet.IntegrationTests/ArgumentsTests.cs

@@ -770,6 +770,56 @@ public void Test(string first, string second)
             }
         }
 
-        private void CanExecute<T>(IToolchain toolchain) => CanExecute<T>(CreateSimpleConfig(job: Job.Dry.With(toolchain)));
+        [Fact]
+        public void UnusedDisposableParamsAreDisposed() => CanExecute<WithDisposableArguments>(Job.Default.GetToolchain());
+
+        public class WithDisposableArguments
+        {
+            public IEnumerable<Disposable> GetDisposables()
+            {
+                yield return new Disposable(0);
+                yield return new Disposable(1);
+            }
+
+            [ParamsSource(nameof(GetDisposables))]
+            public Disposable used;
+
+            [Benchmark]
+            public void CheckDisposed()
+            {
+                if (used.Id == 0)
+                {
+                    if (Disposable.Created != 1)
+                        throw new ArgumentException("Only one instance should be created so far!");
+                    if (Disposable.Disposed != 0)
+                        throw new ArgumentException("None should be disposed as only one was created and is still in use");
+                }
+                if (used.Id == 1)
+                {
+                    if (Disposable.Created != 2)
+                        throw new ArgumentException("Two instances should be created so far!");
+                    if (Disposable.Disposed != 1)
+                        throw new ArgumentException("The first one should be disposed as it's not used");
+                }
+            }
+
+            public class Disposable : IDisposable
+            {
+                public static int Created = 0;
+                public static int Disposed = 0;
+
+                public int Id { get; private set; }
+
+                public Disposable(int id)
+                {
+                    Id = id;
+                    ++Created;
+                }
+
+                public void Dispose() => ++Disposed;
+            }
+        }
+
+        private void CanExecute<T>(IToolchain toolchain) => CanExecute<T>(CreateSimpleConfig(job: Job.Dry.WithToolchain(toolchain)));
     }
 }