From 18636fff4bfae9db7b5c6e4240fb1577bbbd1106 Mon Sep 17 00:00:00 2001 From: Adam Sitnik Date: Thu, 22 Oct 2020 18:24:02 +0200 Subject: [PATCH 1/7] add test --- .../ArgumentsTests.cs | 52 ++++++++++++++++++- 1 file changed, 51 insertions(+), 1 deletion(-) diff --git a/tests/BenchmarkDotNet.IntegrationTests/ArgumentsTests.cs b/tests/BenchmarkDotNet.IntegrationTests/ArgumentsTests.cs index fb8cd69bb6..88f6ee5611 100644 --- a/tests/BenchmarkDotNet.IntegrationTests/ArgumentsTests.cs +++ b/tests/BenchmarkDotNet.IntegrationTests/ArgumentsTests.cs @@ -770,6 +770,56 @@ public void Test(string first, string second) } } - private void CanExecute(IToolchain toolchain) => CanExecute(CreateSimpleConfig(job: Job.Dry.With(toolchain))); + [Fact] + public void UnusedDisposableParamsAreDisposed() => CanExecute(Job.Default.GetToolchain()); + + public class WithDisposableArguments + { + public IEnumerable 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(IToolchain toolchain) => CanExecute(CreateSimpleConfig(job: Job.Dry.WithToolchain(toolchain))); } } \ No newline at end of file From 5b77161b6e10af53417a35042f2bc790db3cb6d9 Mon Sep 17 00:00:00 2001 From: Adam Sitnik Date: Fri, 23 Oct 2020 14:55:09 +0200 Subject: [PATCH 2/7] dispose unused dispsable parameters --- .../Parameters/SmartParamBuilder.cs | 41 ++++++++++++++++--- 1 file changed, 36 insertions(+), 5 deletions(-) diff --git a/src/BenchmarkDotNet/Parameters/SmartParamBuilder.cs b/src/BenchmarkDotNet/Parameters/SmartParamBuilder.cs index 8a1b3f2dd3..2605bd65a7 100644 --- a/src/BenchmarkDotNet/Parameters/SmartParamBuilder.cs +++ b/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 : string.Empty; // IEnumerable - // 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(IEnumerable 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!"); } } } From 7514f482e085228d9d5b374ea8646933c21eb5b9 Mon Sep 17 00:00:00 2001 From: Adam Sitnik Date: Fri, 23 Oct 2020 15:53:48 +0200 Subject: [PATCH 3/7] stop the benchmark process output stream processing after receiving the last signal --- .../Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/src/BenchmarkDotNet/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs b/src/BenchmarkDotNet/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs index 3e25afc007..8ed5c8f612 100644 --- a/src/BenchmarkDotNet/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs +++ b/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)) { From 2f2f49033c890895d9658d0e99165213fad7fd3e Mon Sep 17 00:00:00 2001 From: Adam Sitnik Date: Fri, 23 Oct 2020 15:56:30 +0200 Subject: [PATCH 4/7] 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) --- .../Toolchains/DotNetCli/DotNetCliExecutor.cs | 6 ------ 1 file changed, 6 deletions(-) diff --git a/src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs b/src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs index be06def6e5..aeeb06e899 100644 --- a/src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs +++ b/src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs @@ -86,7 +86,6 @@ private ExecuteResult Execute(BenchmarkCase benchmarkCase, } loggerWithDiagnoser.ProcessInput(); - string standardError = process.StandardError.ReadToEnd(); process.WaitForExit(); // should we add timeout here? @@ -95,11 +94,6 @@ private ExecuteResult Execute(BenchmarkCase benchmarkCase, return new ExecuteResult(true, process.ExitCode, process.Id, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput); } - if (!string.IsNullOrEmpty(standardError)) - { - logger.WriteError(standardError); - } - return new ExecuteResult(true, process.ExitCode, process.Id, Array.Empty(), Array.Empty()); } } From b6023a06f832f28f1604630733677108b61a1986 Mon Sep 17 00:00:00 2001 From: Adam Sitnik Date: Fri, 23 Oct 2020 16:14:02 +0200 Subject: [PATCH 5/7] kill benchmarking process if it does not quit within 250ms after finishing benchmarking --- .../Helpers/ConsoleExitHandler.cs | 2 +- .../Toolchains/DotNetCli/DotNetCliExecutor.cs | 12 ++++++------ src/BenchmarkDotNet/Toolchains/Executor.cs | 16 ++++++++-------- 3 files changed, 15 insertions(+), 15 deletions(-) diff --git a/src/BenchmarkDotNet/Helpers/ConsoleExitHandler.cs b/src/BenchmarkDotNet/Helpers/ConsoleExitHandler.cs index 6321e3e130..3d0d903b81 100644 --- a/src/BenchmarkDotNet/Helpers/ConsoleExitHandler.cs +++ b/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 { diff --git a/src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs b/src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs index aeeb06e899..62ef814253 100644 --- a/src/BenchmarkDotNet/Toolchains/DotNetCli/DotNetCliExecutor.cs +++ b/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); @@ -87,14 +87,14 @@ private ExecuteResult Execute(BenchmarkCase benchmarkCase, 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(); } - return new ExecuteResult(true, process.ExitCode, process.Id, Array.Empty(), Array.Empty()); + return new ExecuteResult(true, process.ExitCode, process.Id, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput); } } } diff --git a/src/BenchmarkDotNet/Toolchains/Executor.cs b/src/BenchmarkDotNet/Toolchains/Executor.cs index a1f3ab51e4..61d7ebfe36 100644 --- a/src/BenchmarkDotNet/Toolchains/Executor.cs +++ b/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 AnyCPU in your .csproj file."); - return new ExecuteResult(true, process.ExitCode, process.Id, Array.Empty(), Array.Empty()); + return new ExecuteResult(true, process.ExitCode, process.Id, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput); } private ProcessStartInfo CreateStartInfo(BenchmarkCase benchmarkCase, ArtifactsPaths artifactsPaths, string args, IResolver resolver) From 503adcc9fad21a472fbd60808cd50f5ca5a8fdc9 Mon Sep 17 00:00:00 2001 From: Adam Sitnik Date: Fri, 23 Oct 2020 16:33:14 +0200 Subject: [PATCH 6/7] exit code can be != 0 for benchmarks that have executed fine but hanged after printing the results --- src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs b/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs index 66ab60b07d..bd23a20b0b 100644 --- a/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs +++ b/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs @@ -501,10 +501,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; From 57bf3bbd16c2d43a275b4c1c3b237323db9ba5bd Mon Sep 17 00:00:00 2001 From: Adam Sitnik Date: Fri, 23 Oct 2020 16:33:56 +0200 Subject: [PATCH 7/7] 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 --- src/BenchmarkDotNet/Parameters/ParameterInstance.cs | 4 +++- .../Parameters/ParameterInstances.cs | 13 +++++++++++-- src/BenchmarkDotNet/Running/BenchmarkCase.cs | 4 +++- src/BenchmarkDotNet/Running/BenchmarkRunInfo.cs | 10 +++++++++- src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs | 8 ++++++++ 5 files changed, 34 insertions(+), 5 deletions(-) diff --git a/src/BenchmarkDotNet/Parameters/ParameterInstance.cs b/src/BenchmarkDotNet/Parameters/ParameterInstance.cs index 5b35ac0351..b0f1678684 100644 --- a/src/BenchmarkDotNet/Parameters/ParameterInstance.cs +++ b/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; diff --git a/src/BenchmarkDotNet/Parameters/ParameterInstances.cs b/src/BenchmarkDotNet/Parameters/ParameterInstances.cs index ffaae928a8..1e1bed2cbf 100644 --- a/src/BenchmarkDotNet/Parameters/ParameterInstances.cs +++ b/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 Items { get; } public int Count => Items.Count; @@ -18,6 +19,14 @@ public ParameterInstances(IReadOnlyList 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()}")) + "]" : ""; diff --git a/src/BenchmarkDotNet/Running/BenchmarkCase.cs b/src/BenchmarkDotNet/Running/BenchmarkCase.cs index 8aab26ba4c..90b65c5840 100644 --- a/src/BenchmarkDotNet/Running/BenchmarkCase.cs +++ b/src/BenchmarkDotNet/Running/BenchmarkCase.cs @@ -6,7 +6,7 @@ namespace BenchmarkDotNet.Running { - public class BenchmarkCase : IComparable + public class BenchmarkCase : IComparable, 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(); diff --git a/src/BenchmarkDotNet/Running/BenchmarkRunInfo.cs b/src/BenchmarkDotNet/Running/BenchmarkRunInfo.cs index 2818a1f833..e12543cc59 100644 --- a/src/BenchmarkDotNet/Running/BenchmarkRunInfo.cs +++ b/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; } diff --git a/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs b/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs index bd23a20b0b..299904db43 100644 --- a/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs +++ b/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(artifactsToCleanup.Distinct())); compositeLogger.Flush();