Dry jobs can eat iteration failures

[danmoseley]

BDN Version

Benchmarks 0.1.1-preview2-190203-1

Repro

Consider a benchmark where the method under test sets some result which the [GlobalCleanup] examines. If the result is not set, [GlobalCleanup] will throw. Assume the test method itself has a bug, and throws an exception:

using System;
using System.IO;
using System.Text;
using System.Linq;
using System.Reflection;
using System.Collections.Generic;
using System.Threading.Tasks;
using BenchmarkDotNet.Attributes;
using BenchmarkDotNet.Running;

namespace Foo
{
    [DryJob] // Important!
    public class BarBaz
    {
        string _result;

        public static void Main(string[] args)
            => BenchmarkRunner.Run(typeof(BarBaz));

        [GlobalCleanup]
        public void CheckResults()
        {
            Console.WriteLine("global cleanup");
            Console.WriteLine("result " + _result.Length);
        }

        [Benchmark]
        public void BizBoz()
        {`
            Console.WriteLine("starting iteration");
            if ((new Random()).Next(2) < 100) throw new Exception("bad iteration");
            _result = "foo";
            Console.WriteLine("finishing iteration");
        }
    }
}

Run with
dotnet run -c Release

Expected

The callstack for the test method exception, possibly followed by the callstack for the cleanup exception. BDN should not hide a test method failure.

Actual

The callstack for the cleanup exception.

...
// BeforeActualRun
starting iteration
global cleanup

System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.NullReferenceException: Object reference not set to an instance of an object.
   at Foo.BarBaz.CheckResults() in /home/dan/git/corefxlab/tfoo.cs:line 29
   at BenchmarkDotNet.Engines.Engine.Dispose()
   at BenchmarkDotNet.Autogenerated.Runnable_0.Run(IHost host, String benchmarkName) in /home/dan/git/corefxlab/tests/Benchmarks/bin/Release/netcoreapp3.0/41182a39-ec98-4e84-a2ad-bc9ea467e163/41182a39-ec98-4e84-a2ad-bc9ea467e163.notcs:line 157
   --- End of inner exception stack trace ---
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor, Boolean wrapExceptions)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at System.Reflection.MethodBase.Invoke(Object obj, Object[] parameters)
   at BenchmarkDotNet.Autogenerated.UniqueProgramName.AfterAssemblyLoadingAttached(String[] args) in /home/dan/git/corefxlab/tests/Benchmarks/bin/Release/netcoreapp3.0/41182a39-ec98-4e84-a2ad-bc9ea467e163/41182a39-ec98-4e84-a2ad-bc9ea467e163.notcs:line 60
// AfterAll
...

This caused me confusion for some time, as I thought the test method was somehow not completing before the cleanup ran (the actual method made a lot of use of asynchrony, I assumed I was not correctly waiting on it to complete, and that explained why I did not see my "finishing iteration" message) when actually it was simply throwing an exception due to a bug in the code under test.

If I remove [DryJob] I get the expected result.

[adamsitnik]

This was tricky, we execute GlobalCleanup in a finally block and when a finally block throws it overwrites the source exception ;)

The output after my fix:

// BeforeActualRun
starting iteration
global cleanup
// ERROR:  Exception during GlobalCleanup!
// ERROR:  Object reference not set to an instance of an object.

System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.Exception: bad iteration
   at BenchmarkDotNet.Samples.BarBaz.BizBoz() in C:\Projects\BenchmarkDotNet\samples\BenchmarkDotNet.Samples\Program.cs:line 28
   at BenchmarkDotNet.Autogenerated.Runnable_0.WorkloadActionUnroll(Int64 invokeCount)
   at BenchmarkDotNet.Engines.Engine.RunIteration(IterationData data)
   at BenchmarkDotNet.Engines.EngineStage.RunIteration(IterationMode mode, IterationStage stage, Int32 index, Int64 invokeCount, Int32 unrollFactor)
   at BenchmarkDotNet.Engines.EngineActualStage.RunSpecific(Int64 invokeCount, IterationMode iterationMode, Int32 iterationCount, Int32 unrollFactor)
   at BenchmarkDotNet.Engines.EngineActualStage.Run(Int64 invokeCount, IterationMode iterationMode, Boolean runAuto, Int32 unrollFactor, Boolean forceSpecific)
   at BenchmarkDotNet.Engines.Engine.Run()
   at BenchmarkDotNet.Autogenerated.Runnable_0.Run(IHost host, String benchmarkName)
   --- End of inner exception stack trace ---
   at System.RuntimeMethodHandle.InvokeMethod(Object target, Object[] arguments, Signature sig, Boolean constructor)
   at System.Reflection.RuntimeMethodInfo.UnsafeInvokeInternal(Object obj, Object[] parameters, Object[] arguments)
   at System.Reflection.RuntimeMethodInfo.Invoke(Object obj, BindingFlags invokeAttr, Binder binder, Object[] parameters, CultureInfo culture)
   at BenchmarkDotNet.Autogenerated.UniqueProgramName.AfterAssemblyLoadingAttached(String[] args)
// AfterAll
ExitCode != 0
No more Benchmark runs will be launched as NO measurements were obtained from the previous run!

[danmoseley]

Thanks @adamsitnik

there is a BindingFlag to avoid the TargetInvocationException wrapping but I guess it is only in.NET Core. Not a big deal