Don't run the benchmark once per iteration if only the first ivocation lasts longer than IterationTime

src/BenchmarkDotNet/Engines/EngineFactory.cs

@@ -44,6 +44,14 @@ public IEngine CreateReadyToRun(EngineParameters engineParameters)
             var singleActionEngine = CreateSingleActionEngine(engineParameters);
             var singleInvocationTime = Jit(singleActionEngine, ++jitIndex, invokeCount: 1, unrollFactor: 1);
 
+            if (singleInvocationTime > engineParameters.IterationTime && singleInvocationTime < TimeInterval.FromSeconds(1.0))
+            {
+                // if the Jitting took more than IterationTime but still less than 1s (a magic number based on observations of the reported bug)
+                // we call it one more time to see if Jitting itself has not dominated the first invocation
+                // if it did, it shoud NOT be a single invocation engine (see #837, #1337 and #1338)
+                singleInvocationTime = Jit(singleActionEngine, ++jitIndex, invokeCount: 1, unrollFactor: 1);
+            }
+
             if (singleInvocationTime > engineParameters.IterationTime)
                 return singleActionEngine; // executing once takes longer than iteration time => long running benchmark, needs no pilot and no overhead
 

src/BenchmarkDotNet/Engines/EngineResolver.cs

@@ -10,6 +10,7 @@ public class EngineResolver : Resolver
     {
         internal const int DefaultMinWorkloadIterationCount = 15;
         internal const int DefaultMaxWorkloadIterationCount = 100;
+        internal const int DefaultIterationTime = 500;
 
         internal const int ForceAutoWarmup = -1;
         internal const int DefaultMinWarmupIterationCount = 6;
@@ -20,7 +21,7 @@ public class EngineResolver : Resolver
         private EngineResolver()
         {
             Register(RunMode.RunStrategyCharacteristic, () => RunStrategy.Throughput);
-            Register(RunMode.IterationTimeCharacteristic, () => TimeInterval.Millisecond * 500);
+            Register(RunMode.IterationTimeCharacteristic, () => TimeInterval.Millisecond * DefaultIterationTime);
 
             Register(RunMode.MinIterationCountCharacteristic, () => DefaultMinWorkloadIterationCount);
             Register(RunMode.MaxIterationCountCharacteristic, () => DefaultMaxWorkloadIterationCount);

tests/BenchmarkDotNet.Tests/Engine/EngineFactoryTests.cs

@@ -7,6 +7,7 @@
 using BenchmarkDotNet.Jobs;
 using BenchmarkDotNet.Running;
 using JetBrains.Annotations;
+using Perfolizer.Horology;
 using Xunit;
 
 namespace BenchmarkDotNet.Tests.Engine
@@ -33,6 +34,14 @@ private void VeryTimeConsumingSingle(long _)
             Thread.Sleep(IterationTime);
         }
 
+        private void TimeConsumingOnlyForTheFirstCall(long _)
+        {
+            if (timesBenchmarkCalled++ == 0)
+            {
+                Thread.Sleep(IterationTime);
+            }
+        }
+
         private void InstantNoUnroll(long invocationCount) => timesBenchmarkCalled += (int) invocationCount;
         private void InstantUnroll(long _) => timesBenchmarkCalled += 16;
 
@@ -78,10 +87,10 @@ public void ForDefaultSettingsVeryTimeConsumingBenchmarksAreExecutedOncePerItera
             var engine = new EngineFactory().CreateReadyToRun(engineParameters);
 
             Assert.Equal(1, timesGlobalSetupCalled);
-            Assert.Equal(1, timesIterationSetupCalled); // 1x for Target
-            Assert.Equal(1, timesBenchmarkCalled);
-            Assert.Equal(1, timesOverheadCalled);
-            Assert.Equal(1, timesIterationCleanupCalled); // 1x for Target
+            Assert.Equal(2, timesIterationSetupCalled); // 2x for Target
+            Assert.Equal(2, timesBenchmarkCalled);
+            Assert.Equal(2, timesOverheadCalled);
+            Assert.Equal(2, timesIterationCleanupCalled); // 2x for Target
             Assert.Equal(0, timesGlobalCleanupCalled); // cleanup is called as part of dispose
 
             Assert.Equal(1, engine.TargetJob.Run.InvocationCount); // call the benchmark once per iteration
@@ -95,6 +104,39 @@ public void ForDefaultSettingsVeryTimeConsumingBenchmarksAreExecutedOncePerItera
             Assert.Equal(1, timesGlobalCleanupCalled);
         }
 
+        [Theory]
+        [InlineData(120)] // 120 ms as in the bug report
+        [InlineData(250)] // 250 ms as configured in dotnet/performance repo
+        [InlineData(EngineResolver.DefaultIterationTime)] // 500 ms - the default BDN setting
+        public void BenchmarksThatRunLongerThanIterationTimeOnlyDuringFirstInvocationAreNotInvokedOncePerIteration(int iterationTime)
+        {
+            var engineParameters = CreateEngineParameters(
+                mainNoUnroll: TimeConsumingOnlyForTheFirstCall,
+                mainUnroll: InstantUnroll,
+                job: Job.Default.WithIterationTime(TimeInterval.FromMilliseconds(iterationTime)));
+
+            var engine = new EngineFactory().CreateReadyToRun(engineParameters);
+
+            Assert.Equal(1, timesGlobalSetupCalled);
+            // the factory should call the benchmark:
+            // 1st time with unroll factor to JIT the code
+            // one more to check that the Jitting has not dominated the reported time
+            // and one more time to JIT the 16 unroll factor case as it turned out that Jitting has dominated the time
+            Assert.Equal(1 + 1 + 1, timesIterationSetupCalled);
+            Assert.Equal(1 + 1 + 16, timesBenchmarkCalled);
+            Assert.Equal(1 + 1 + 16, timesOverheadCalled);
+            Assert.Equal(1 + 1 + 1, timesIterationCleanupCalled); // 2x for Target
+            Assert.Equal(0, timesGlobalCleanupCalled); // cleanup is called as part of dispose
+
+            Assert.False(engine.TargetJob.Run.HasValue(RunMode.InvocationCountCharacteristic)); // we need pilot stage
+
+            Assert.False(engine.TargetJob.Run.HasValue(AccuracyMode.EvaluateOverheadCharacteristic));
+
+            engine.Dispose(); // cleanup is called as part of dispose
+
+            Assert.Equal(1, timesGlobalCleanupCalled);
+        }
+
         [Fact]
         public void ForJobsWithExplicitUnrollFactorTheGlobalSetupIsCalledAndMultiActionCodeGetsJitted()
             => AssertGlobalSetupWasCalledAndMultiActionGotJitted(Job.Default.WithUnrollFactor(16));