diff --git a/samples/BenchmarkDotNet.Samples/Intro/IntroGcMode.cs b/samples/BenchmarkDotNet.Samples/Intro/IntroGcMode.cs index ba5d723c44..33982dbbbf 100644 --- a/samples/BenchmarkDotNet.Samples/Intro/IntroGcMode.cs +++ b/samples/BenchmarkDotNet.Samples/Intro/IntroGcMode.cs @@ -14,10 +14,13 @@ private class Config : ManualConfig { public Config() { - Add(Job.Dry.WithGcServer(true).WithGcForce(true).WithId("ServerForce")); - Add(Job.Dry.WithGcServer(true).WithGcForce(false).WithId("Server")); - Add(Job.Dry.WithGcServer(false).WithGcForce(true).WithId("Workstation")); - Add(Job.Dry.WithGcServer(false).WithGcForce(false).WithId("WorkstationForce")); + Add(Job.MediumRun.WithGcServer(true).WithGcForce(true).WithId("ServerForce")); + Add(Job.MediumRun.WithGcServer(true).WithGcForce(false).WithId("Server")); + Add(Job.MediumRun.WithGcServer(false).WithGcForce(true).WithId("Workstation")); + Add(Job.MediumRun.WithGcServer(false).WithGcForce(false).WithId("WorkstationForce")); +#if !CORE + Add(new Diagnostics.Windows.MemoryDiagnoser()); +#endif } } diff --git a/samples/BenchmarkDotNet.Samples/JIT/Jit_Inlining.cs b/samples/BenchmarkDotNet.Samples/JIT/Jit_Inlining.cs index 76ae9bb74f..e48b43a2de 100644 --- a/samples/BenchmarkDotNet.Samples/JIT/Jit_Inlining.cs +++ b/samples/BenchmarkDotNet.Samples/JIT/Jit_Inlining.cs @@ -5,6 +5,9 @@ namespace BenchmarkDotNet.Samples.JIT { // See http://en.wikipedia.org/wiki/Inline_expansion // See http://aakinshin.net/en/blog/dotnet/inlining-and-starg/ +#if !CORE + [Diagnostics.Windows.Configs.InliningDiagnoser] +#endif [LegacyJitX86Job, LegacyJitX64Job, RyuJitX64Job] public class Jit_Inlining { diff --git a/samples/BenchmarkDotNet.Samples/Program.cs b/samples/BenchmarkDotNet.Samples/Program.cs index f45bceca60..15d1856f24 100644 --- a/samples/BenchmarkDotNet.Samples/Program.cs +++ b/samples/BenchmarkDotNet.Samples/Program.cs @@ -1,7 +1,5 @@ -using System; -using System.Reflection; +using System.Reflection; using BenchmarkDotNet.Running; -using BenchmarkDotNet.Attributes; namespace BenchmarkDotNet.Samples { diff --git a/src/BenchmarkDotNet.Core/Code/CodeGenerator.cs b/src/BenchmarkDotNet.Core/Code/CodeGenerator.cs index dd13198d22..e1b3112974 100644 --- a/src/BenchmarkDotNet.Core/Code/CodeGenerator.cs +++ b/src/BenchmarkDotNet.Core/Code/CodeGenerator.cs @@ -37,6 +37,7 @@ internal static string Generate(Benchmark benchmark) Replace("$JobSetDefinition$", GetJobsSetDefinition(benchmark)). Replace("$ParamsContent$", GetParamsContent(benchmark)). Replace("$ExtraAttribute$", GetExtraAttributes(benchmark.Target)). + Replace("$EngineFactoryType$", GetEngineFactoryTypeName(benchmark)). ToString(); text = Unroll(text, benchmark.Job.Run.UnrollFactor.Resolve(EnvResolver.Instance)); @@ -124,6 +125,20 @@ private static string GetExtraAttributes(Target target) return string.Empty; } + private static string GetEngineFactoryTypeName(Benchmark benchmark) + { + var factory = benchmark.Job.Infrastructure.EngineFactory.Resolve(InfrastructureResolver.Instance); + var factoryType = factory.GetType(); + + if (!factoryType.GetTypeInfo().DeclaredConstructors.Any(ctor => ctor.IsPublic && !ctor.GetParameters().Any())) + { + throw new NotSupportedException("Custom factory must have a public parameterless constructor"); + } + + return factoryType.GetCorrectTypeName(); + } + + private class SmartStringBuilder { private readonly string originalText; diff --git a/src/BenchmarkDotNet.Core/Diagnosers/CompositeDiagnoser.cs b/src/BenchmarkDotNet.Core/Diagnosers/CompositeDiagnoser.cs index 6e8edba07b..464fce63ce 100644 --- a/src/BenchmarkDotNet.Core/Diagnosers/CompositeDiagnoser.cs +++ b/src/BenchmarkDotNet.Core/Diagnosers/CompositeDiagnoser.cs @@ -4,6 +4,7 @@ using BenchmarkDotNet.Loggers; using BenchmarkDotNet.Running; using BenchmarkDotNet.Reports; +using BenchmarkDotNet.Extensions; namespace BenchmarkDotNet.Diagnosers { @@ -16,35 +17,19 @@ public CompositeDiagnoser(params IDiagnoser[] diagnosers) this.diagnosers = diagnosers; } - public void Start(Benchmark benchmark) - { - foreach (var diagnoser in diagnosers) - diagnoser.Start(benchmark); - } + public IColumnProvider GetColumnProvider() + => new CompositeColumnProvider(diagnosers.Select(d => d.GetColumnProvider()).ToArray()); - public void Stop(Benchmark benchmark, BenchmarkReport report) - { - foreach (var diagnoser in diagnosers) - diagnoser.Stop(benchmark, report); - } + public void BeforeAnythingElse(Process process, Benchmark benchmark) + => diagnosers.ForEach(diagnoser => diagnoser.BeforeAnythingElse(process, benchmark)); - public void ProcessStarted(Process process) - { - foreach (var diagnoser in diagnosers) - diagnoser.ProcessStarted(process); - } + public void AfterSetup(Process process, Benchmark benchmark) + => diagnosers.ForEach(diagnoser => diagnoser.AfterSetup(process, benchmark)); - public void AfterBenchmarkHasRun(Benchmark benchmark, Process process) - { - foreach (var diagnoser in diagnosers) - diagnoser.AfterBenchmarkHasRun(benchmark, process); - } + public void BeforeCleanup() => diagnosers.ForEach(diagnoser => diagnoser.BeforeCleanup()); - public void ProcessStopped(Process process) - { - foreach (var diagnoser in diagnosers) - diagnoser.ProcessStopped(process); - } + public void ProcessResults(Benchmark benchmark, BenchmarkReport report) + => diagnosers.ForEach(diagnoser => diagnoser.ProcessResults(benchmark, report)); public void DisplayResults(ILogger logger) { @@ -57,7 +42,5 @@ public void DisplayResults(ILogger logger) logger.WriteLine(); } } - - public IColumnProvider GetColumnProvider() => new CompositeColumnProvider(diagnosers.Select(d => d.GetColumnProvider()).ToArray()); } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Diagnosers/IDiagnoser.cs b/src/BenchmarkDotNet.Core/Diagnosers/IDiagnoser.cs index 94c64f13b7..66fe23d677 100644 --- a/src/BenchmarkDotNet.Core/Diagnosers/IDiagnoser.cs +++ b/src/BenchmarkDotNet.Core/Diagnosers/IDiagnoser.cs @@ -6,28 +6,27 @@ namespace BenchmarkDotNet.Diagnosers { - /// The events are guaranteed to happen in the following sequence: - /// Start // When the Benchmark run is started and most importantly BEFORE the process has been launched - /// ProcessStarted // After the Process (in a "Diagnostic" run) has been launched - /// AfterBenchmarkHasRun // After a "Warmup" iteration of the Benchmark has run, i.e. we know the [Benchmark] method has been - /// // executed and JITted, this is important if the Diagnoser needs to know when it can do a Memory Dump. - /// ProcessStopped // Once the Process (in a "Diagnostic" run) has stopped/completed - /// Stop // At the end, when the entire Benchmark run has complete - /// DisplayResults // When the results/output should be displayed public interface IDiagnoser { - void Start(Benchmark benchmark); + IColumnProvider GetColumnProvider(); - void Stop(Benchmark benchmark, BenchmarkReport report); + /// + /// before jitting, warmup + /// + void BeforeAnythingElse(Process process, Benchmark benchmark); - void ProcessStarted(Process process); + /// + /// after setup, before run + /// + void AfterSetup(Process process, Benchmark benchmark); - void AfterBenchmarkHasRun(Benchmark benchmark, Process process); + /// + /// after run, before cleanup + /// + void BeforeCleanup(); - void ProcessStopped(Process process); + void ProcessResults(Benchmark benchmark, BenchmarkReport report); void DisplayResults(ILogger logger); - - IColumnProvider GetColumnProvider(); } } diff --git a/src/BenchmarkDotNet.Core/Engines/Engine.cs b/src/BenchmarkDotNet.Core/Engines/Engine.cs index 85cb4896d8..2a86eed96a 100644 --- a/src/BenchmarkDotNet.Core/Engines/Engine.cs +++ b/src/BenchmarkDotNet.Core/Engines/Engine.cs @@ -1,10 +1,8 @@ using System; using System.Collections.Generic; -using System.Linq; using BenchmarkDotNet.Characteristics; using BenchmarkDotNet.Horology; using BenchmarkDotNet.Jobs; -using BenchmarkDotNet.Mathematics; using BenchmarkDotNet.Reports; using BenchmarkDotNet.Running; using JetBrains.Annotations; @@ -17,82 +15,92 @@ public class Engine : IEngine public const int MinInvokeCount = 4; public static readonly TimeInterval MinIterationTime = 200 * TimeInterval.Millisecond; - public Job TargetJob { get; set; } = Job.Default; - public long OperationsPerInvoke { get; set; } = 1; - public Action SetupAction { get; set; } = null; - public Action CleanupAction { get; set; } = null; public Action MainAction { get; } public Action IdleAction { get; } + public Job TargetJob { get; } + public long OperationsPerInvoke { get; } + public Action SetupAction { get; } + public Action CleanupAction { get; } + public bool IsDiagnoserAttached { get; } + public IResolver Resolver { get; } + + private IClock Clock { get; } + private bool ForceAllocations { get; } + private int UnrollFactor { get; } + private RunStrategy Strategy { get; } + private bool EvaluateOverhead { get; } + private int InvocationCount { get; } private readonly EnginePilotStage pilotStage; private readonly EngineWarmupStage warmupStage; private readonly EngineTargetStage targetStage; + private bool isJitted, isPreAllocated; - public IResolver Resolver { get; } - - public Engine([NotNull] Action idleAction, [NotNull] Action mainAction) + internal Engine(Action idleAction, Action mainAction, Job targetJob, Action setupAction, Action cleanupAction, long operationsPerInvoke, bool isDiagnoserAttached) { IdleAction = idleAction; MainAction = mainAction; - pilotStage = new EnginePilotStage(this); + TargetJob = targetJob; + SetupAction = setupAction; + CleanupAction = cleanupAction; + OperationsPerInvoke = operationsPerInvoke; + IsDiagnoserAttached = isDiagnoserAttached; + + Resolver = new CompositeResolver(BenchmarkRunnerCore.DefaultResolver, EngineResolver.Instance); + + Clock = targetJob.Infrastructure.Clock.Resolve(Resolver); + ForceAllocations = targetJob.Env.Gc.Force.Resolve(Resolver); + UnrollFactor = targetJob.Run.UnrollFactor.Resolve(Resolver); + Strategy = targetJob.Run.RunStrategy.Resolve(Resolver); + EvaluateOverhead = targetJob.Accuracy.EvaluateOverhead.Resolve(Resolver); + InvocationCount = targetJob.Run.InvocationCount.Resolve(Resolver); + warmupStage = new EngineWarmupStage(this); + pilotStage = new EnginePilotStage(this); targetStage = new EngineTargetStage(this); - Resolver = new CompositeResolver(BenchmarkRunnerCore.DefaultResolver, EngineResolver.Instance); } - // TODO: return all measurements - [UsedImplicitly] - public void Run() + public void PreAllocate() { - Jitting(); + var list = new List { new Measurement(), new Measurement() }; + list.Sort(); // provoke JIT, static ctors etc (was allocating 1740 bytes with first call) + if (TimeUnit.All == null || list[0].Nanoseconds != default(double)) + throw new Exception("just use this things here to provoke static ctor"); + isPreAllocated = true; + } - long invokeCount = 1; - int unrollFactor = TargetJob.Run.UnrollFactor.Resolve(Resolver); - IList idle = null; + public void Jitting() + { + // first signal about jitting is raised from auto-generated Program.cs, look at BenchmarkProgram.txt + MainAction.Invoke(1); + IdleAction.Invoke(1); + isJitted = true; + } + + public RunResults Run() + { + if (!isJitted || !isPreAllocated) + throw new Exception("You must call PreAllocate() and Jitting() first!"); - if (TargetJob.Run.RunStrategy.Resolve(Resolver) != RunStrategy.ColdStart) + long invokeCount = InvocationCount; + List idle = null; + + if (Strategy != RunStrategy.ColdStart) { invokeCount = pilotStage.Run(); - if (TargetJob.Accuracy.EvaluateOverhead.Resolve(Resolver)) + if (EvaluateOverhead) { - warmupStage.RunIdle(invokeCount, unrollFactor); - idle = targetStage.RunIdle(invokeCount, unrollFactor); + warmupStage.RunIdle(invokeCount, UnrollFactor); + idle = targetStage.RunIdle(invokeCount, UnrollFactor); } - warmupStage.RunMain(invokeCount, unrollFactor); + warmupStage.RunMain(invokeCount, UnrollFactor); } - var main = targetStage.RunMain(invokeCount, unrollFactor); - - // TODO: Move calculation of the result measurements to a separated class - PrintResult(idle, main); - } - private void Jitting() - { - SetupAction?.Invoke(); - MainAction.Invoke(1); - IdleAction.Invoke(1); - CleanupAction?.Invoke(); - } + var main = targetStage.RunMain(invokeCount, UnrollFactor); - private void PrintResult(IList idle, IList main) - { - // TODO: use Accuracy.RemoveOutliers - // TODO: check if resulted measurements are too small (like < 0.1ns) - double overhead = idle == null ? 0.0 : new Statistics(idle.Select(m => m.Nanoseconds)).Median; - int resultIndex = 0; - foreach (var measurement in main) - { - var resultMeasurement = new Measurement( - measurement.LaunchIndex, - IterationMode.Result, - ++resultIndex, - measurement.Operations, - Math.Max(0, measurement.Nanoseconds - overhead)); - WriteLine(resultMeasurement.ToOutputLine()); - } - WriteLine(); + return new RunResults(idle, main); } public Measurement RunIteration(IterationData data) @@ -103,38 +111,66 @@ public Measurement RunIteration(IterationData data) long totalOperations = invokeCount * OperationsPerInvoke; var action = data.IterationMode.IsIdle() ? IdleAction : MainAction; - // Setup - SetupAction?.Invoke(); GcCollect(); // Measure - var clock = TargetJob.Infrastructure.Clock.Resolve(Resolver).Start(); + var clock = Clock.Start(); action(invokeCount / unrollFactor); var clockSpan = clock.Stop(); - // Cleanup - CleanupAction?.Invoke(); GcCollect(); // Results var measurement = new Measurement(0, data.IterationMode, data.Index, totalOperations, clockSpan.GetNanoseconds()); - WriteLine(measurement.ToOutputLine()); + if (!IsDiagnoserAttached) WriteLine(measurement.ToOutputLine()); + return measurement; } - private void GcCollect() => GcCollect(TargetJob.Env.Gc.Force.Resolve(Resolver)); - - private static void GcCollect(bool isForce) + private void GcCollect() { - if (!isForce) + if (!ForceAllocations) return; + ForceGcCollect(); + } + + private static void ForceGcCollect() + { GC.Collect(); GC.WaitForPendingFinalizers(); GC.Collect(); } - public void WriteLine() => Console.WriteLine(); - public void WriteLine(string line) => Console.WriteLine(line); + public void WriteLine(string text) + { + EnsureNothingIsPrintedWhenDiagnoserIsAttached(); + + Console.WriteLine(text); + } + + public void WriteLine() + { + EnsureNothingIsPrintedWhenDiagnoserIsAttached(); + + Console.WriteLine(); + } + + private void EnsureNothingIsPrintedWhenDiagnoserIsAttached() + { + if (IsDiagnoserAttached) + { + throw new InvalidOperationException("to avoid memory allocations we must not print anything when diagnoser is still attached"); + } + } + + [UsedImplicitly] + public class Signals + { + public const string BeforeAnythingElse = "// BeforeAnythingElse"; + public const string AfterSetup = "// AfterSetup"; + public const string BeforeCleanup = "// BeforeCleanup"; + public const string DiagnoserIsAttachedParam = "diagnoserAttached"; + } } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/EngineFactory.cs b/src/BenchmarkDotNet.Core/Engines/EngineFactory.cs new file mode 100644 index 0000000000..fa6828c75d --- /dev/null +++ b/src/BenchmarkDotNet.Core/Engines/EngineFactory.cs @@ -0,0 +1,26 @@ +using System; + +namespace BenchmarkDotNet.Engines +{ + public class EngineFactory : IEngineFactory + { + public IEngine Create(EngineParameters engineParameters) + { + if (engineParameters.MainAction == null) + throw new ArgumentNullException(nameof(engineParameters.MainAction)); + if (engineParameters.IdleAction == null) + throw new ArgumentNullException(nameof(engineParameters.IdleAction)); + if(engineParameters.TargetJob == null) + throw new ArgumentNullException(nameof(engineParameters.TargetJob)); + + return new Engine( + engineParameters.IdleAction, + engineParameters.MainAction, + engineParameters.TargetJob, + engineParameters.SetupAction, + engineParameters.CleanupAction, + engineParameters.OperationsPerInvoke, + engineParameters.IsDiagnoserAttached); + } + } +} \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/EngineParameters.cs b/src/BenchmarkDotNet.Core/Engines/EngineParameters.cs new file mode 100644 index 0000000000..31901e373b --- /dev/null +++ b/src/BenchmarkDotNet.Core/Engines/EngineParameters.cs @@ -0,0 +1,18 @@ +using System; +using BenchmarkDotNet.Characteristics; +using BenchmarkDotNet.Jobs; + +namespace BenchmarkDotNet.Engines +{ + public class EngineParameters + { + public Action MainAction { get; set; } + public Action IdleAction { get; set; } + public Job TargetJob { get; set; } = Job.Default; + public long OperationsPerInvoke { get; set; } = 1; + public Action SetupAction { get; set; } = null; + public Action CleanupAction { get; set; } = null; + public bool IsDiagnoserAttached { get; set; } + public IResolver Resolver { get; set; } + } +} \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/EnginePilotStage.cs b/src/BenchmarkDotNet.Core/Engines/EnginePilotStage.cs index ea2ee4dd21..a9d56af2f0 100644 --- a/src/BenchmarkDotNet.Core/Engines/EnginePilotStage.cs +++ b/src/BenchmarkDotNet.Core/Engines/EnginePilotStage.cs @@ -1,6 +1,7 @@ using System; using BenchmarkDotNet.Characteristics; using BenchmarkDotNet.Horology; +using BenchmarkDotNet.Jobs; namespace BenchmarkDotNet.Engines { @@ -8,8 +9,20 @@ internal class EnginePilotStage : EngineStage { internal const long MaxInvokeCount = (long.MaxValue / 2 + 1) / 2; + private readonly int unrollFactor; + private readonly int minInvokeCount; + private readonly double maxStdErrRelative; + private readonly double targetIterationTime; + private readonly TimeInterval clockResolution; + private readonly double resolution; + public EnginePilotStage(IEngine engine) : base(engine) { + unrollFactor = engine.TargetJob.Run.UnrollFactor.Resolve(engine.Resolver); + minInvokeCount = engine.TargetJob.Accuracy.MinInvokeCount.Resolve(engine.Resolver); + maxStdErrRelative = engine.TargetJob.Accuracy.MaxStdErrRelative.Resolve(engine.Resolver); + targetIterationTime = engine.TargetJob.Run.IterationTime.Resolve(engine.Resolver).ToNanoseconds(); + resolution = engine.TargetJob.Infrastructure.Clock.Resolve(engine.Resolver).GetResolution().Nanoseconds; } /// Perfect invocation count @@ -28,15 +41,10 @@ public long Run() /// private long RunAuto() { - int unrollFactor = TargetJob.Run.UnrollFactor.Resolve(Resolver); - Func autocorrect = count => (count + unrollFactor - 1) / unrollFactor * unrollFactor; - - long invokeCount = autocorrect(TargetAccuracy.MinInvokeCount.Resolve(Resolver)); - double maxError = TargetAccuracy.MaxStdErrRelative.Resolve(Resolver); // TODO: introduce a StdErr factor + long invokeCount = Autocorrect(minInvokeCount); + double maxError = maxStdErrRelative; // TODO: introduce a StdErr factor double minIterationTime = Engine.MinIterationTime.Nanoseconds; - double resolution = TargetClock.GetResolution().Nanoseconds; - int iterationCounter = 0; while (true) { @@ -54,7 +62,7 @@ private long RunAuto() invokeCount *= 2; } - WriteLine(); + if (!IsDiagnoserAttached) WriteLine(); return invokeCount; } @@ -64,11 +72,8 @@ private long RunAuto() /// private long RunSpecific() { - int unrollFactor = TargetJob.Run.UnrollFactor.Resolve(Resolver); - Func autocorrect = count => (count + unrollFactor - 1) / unrollFactor * unrollFactor; + long invokeCount = Autocorrect(Engine.MinInvokeCount); - long invokeCount = autocorrect(Engine.MinInvokeCount); - double targetIterationTime = TargetJob.Run.IterationTime.Resolve(Resolver).ToNanoseconds(); int iterationCounter = 0; int downCount = 0; // Amount of iterations where newInvokeCount < invokeCount @@ -77,7 +82,7 @@ private long RunSpecific() iterationCounter++; var measurement = RunIteration(IterationMode.Pilot, iterationCounter, invokeCount, unrollFactor); double actualIterationTime = measurement.Nanoseconds; - long newInvokeCount = autocorrect(Math.Max(TargetAccuracy.MinInvokeCount.Resolve(Resolver), (long) Math.Round(invokeCount * targetIterationTime / actualIterationTime))); + long newInvokeCount = Autocorrect(Math.Max(minInvokeCount, (long)Math.Round(invokeCount * targetIterationTime / actualIterationTime))); if (newInvokeCount < invokeCount) downCount++; @@ -87,9 +92,11 @@ private long RunSpecific() invokeCount = newInvokeCount; } - WriteLine(); + if (!IsDiagnoserAttached) WriteLine(); return invokeCount; } + + private long Autocorrect(long count) => (count + unrollFactor - 1) / unrollFactor * unrollFactor; } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/EngineStage.cs b/src/BenchmarkDotNet.Core/Engines/EngineStage.cs index 3781deab07..a5d7f75e4c 100644 --- a/src/BenchmarkDotNet.Core/Engines/EngineStage.cs +++ b/src/BenchmarkDotNet.Core/Engines/EngineStage.cs @@ -1,6 +1,5 @@ using System; using BenchmarkDotNet.Characteristics; -using BenchmarkDotNet.Horology; using BenchmarkDotNet.Jobs; using BenchmarkDotNet.Reports; @@ -16,9 +15,7 @@ protected EngineStage(IEngine engine) } protected Job TargetJob => engine.TargetJob; - protected AccuracyMode TargetAccuracy => TargetJob.Accuracy; - protected IClock TargetClock => engine.Resolver.Resolve(TargetJob.Infrastructure.Clock); - protected IResolver Resolver => engine.Resolver; + protected bool IsDiagnoserAttached => engine.IsDiagnoserAttached; protected Measurement RunIteration(IterationMode mode, int index, long invokeCount, int unrollFactor) { @@ -27,8 +24,9 @@ protected Measurement RunIteration(IterationMode mode, int index, long invokeCou return engine.RunIteration(new IterationData(mode, index, invokeCount, unrollFactor)); } - protected void WriteLine() => engine.WriteLine(); + protected bool ShouldRunAuto(ICharacteristic iterationCount) => iterationCount.IsDefault; + protected void WriteLine() => engine.WriteLine(); protected void WriteLine(string line) => engine.WriteLine(line); } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/EngineTargetStage.cs b/src/BenchmarkDotNet.Core/Engines/EngineTargetStage.cs index 4ce891b5be..89cf3231a1 100644 --- a/src/BenchmarkDotNet.Core/Engines/EngineTargetStage.cs +++ b/src/BenchmarkDotNet.Core/Engines/EngineTargetStage.cs @@ -1,7 +1,6 @@ using System.Collections.Generic; using System.Linq; using BenchmarkDotNet.Characteristics; -using BenchmarkDotNet.Jobs; using BenchmarkDotNet.Mathematics; using BenchmarkDotNet.Reports; @@ -12,37 +11,45 @@ public class EngineTargetStage : EngineStage internal const int MinIterationCount = 15; internal const int MaxIterationCount = 100; internal const int MaxIdleIterationCount = 20; - private const double MaxIdleStdErrRelative = 0.05; + internal const double MaxIdleStdErrRelative = 0.05; + + private readonly ICharacteristic targetCount; + private readonly double maxStdErrRelative; + private readonly bool removeOutliers; + private readonly List measurements; public EngineTargetStage(IEngine engine) : base(engine) { + targetCount = engine.TargetJob.Run.TargetCount; + maxStdErrRelative = engine.Resolver.Resolve(engine.TargetJob.Accuracy.MaxStdErrRelative); + removeOutliers = engine.Resolver.Resolve(engine.TargetJob.Accuracy.RemoveOutliers); + var maxSize = ShouldRunAuto(targetCount) ? MaxIterationCount : targetCount.SpecifiedValue; + measurements = new List(maxSize); } - public List Run(long invokeCount, IterationMode iterationMode, ICharacteristic iterationCount, int unrollFactor) - { - return iterationCount.IsDefault + public List RunIdle(long invokeCount, int unrollFactor) + => RunAuto(invokeCount, IterationMode.IdleTarget, unrollFactor); + + public List RunMain(long invokeCount, int unrollFactor) + => Run(invokeCount, IterationMode.MainTarget, targetCount, unrollFactor); + + internal List Run(long invokeCount, IterationMode iterationMode, ICharacteristic iterationCount, int unrollFactor) + => ShouldRunAuto(iterationCount) ? RunAuto(invokeCount, iterationMode, unrollFactor) : RunSpecific(invokeCount, iterationMode, iterationCount.SpecifiedValue, unrollFactor); - } - - public List RunIdle(long invokeCount, int unrollFactor) => Run(invokeCount, IterationMode.IdleTarget, TargetJob.Run.TargetCount.MakeDefault(), unrollFactor); - public List RunMain(long invokeCount, int unrollFactor) => Run(invokeCount, IterationMode.MainTarget, TargetJob.Run.TargetCount, unrollFactor); private List RunAuto(long invokeCount, IterationMode iterationMode, int unrollFactor) { - var measurements = new List(); int iterationCounter = 0; bool isIdle = iterationMode.IsIdle(); - double maxErrorRelative = isIdle ? MaxIdleStdErrRelative : Resolver.Resolve(TargetAccuracy.MaxStdErrRelative); + double maxErrorRelative = isIdle ? MaxIdleStdErrRelative : maxStdErrRelative; while (true) { iterationCounter++; var measurement = RunIteration(iterationMode, iterationCounter, invokeCount, unrollFactor); measurements.Add(measurement); - var statistics = new Statistics(measurements.Select(m => m.Nanoseconds)); - if (Resolver.Resolve(TargetAccuracy.RemoveOutliers)) - statistics = new Statistics(statistics.WithoutOutliers()); + var statistics = MeasurementsStatistics.Calculate(measurements, removeOutliers); double actualError = statistics.StandardError; double maxError = maxErrorRelative * statistics.Mean; @@ -52,16 +59,17 @@ private List RunAuto(long invokeCount, IterationMode iterationMode, if (iterationCounter >= MaxIterationCount || (isIdle && iterationCounter >= MaxIdleIterationCount)) break; } - WriteLine(); + if (!IsDiagnoserAttached) WriteLine(); return measurements; } private List RunSpecific(long invokeCount, IterationMode iterationMode, int iterationCount, int unrollFactor) { - var measurements = new List(); for (int i = 0; i < iterationCount; i++) measurements.Add(RunIteration(iterationMode, i + 1, invokeCount, unrollFactor)); - WriteLine(); + + if (!IsDiagnoserAttached) WriteLine(); + return measurements; } } diff --git a/src/BenchmarkDotNet.Core/Engines/EngineWarmupStage.cs b/src/BenchmarkDotNet.Core/Engines/EngineWarmupStage.cs index 767fe72bd3..15270d0dad 100644 --- a/src/BenchmarkDotNet.Core/Engines/EngineWarmupStage.cs +++ b/src/BenchmarkDotNet.Core/Engines/EngineWarmupStage.cs @@ -11,24 +11,32 @@ internal class EngineWarmupStage : EngineStage internal const int MaxIterationCount = 50; internal const int MaxIdleItertaionCount = 10; + private readonly ICharacteristic warmupCount; + private readonly List measurements; + public EngineWarmupStage(IEngine engine) : base(engine) { + warmupCount = engine.TargetJob.Run.WarmupCount; + var maxSize = ShouldRunAuto(warmupCount) ? MaxIterationCount : warmupCount.SpecifiedValue; + measurements = new List(maxSize); } - public List Run(long invokeCount, IterationMode iterationMode, ICharacteristic iterationCount, int unrollFactor) + public void RunIdle(long invokeCount, int unrollFactor) + => RunAuto(invokeCount, IterationMode.IdleWarmup, unrollFactor); + + public void RunMain(long invokeCount, int unrollFactor) + => Run(invokeCount, IterationMode.MainWarmup, warmupCount, unrollFactor); + + internal List Run(long invokeCount, IterationMode iterationMode, ICharacteristic iterationCount, int unrollFactor) { - return iterationCount.IsDefault + return ShouldRunAuto(iterationCount) ? RunAuto(invokeCount, iterationMode, unrollFactor) : RunSpecific(invokeCount, iterationMode, iterationCount.SpecifiedValue, unrollFactor); } - public void RunIdle(long invokeCount, int unrollFactor) => Run(invokeCount, IterationMode.IdleWarmup, TargetJob.Run.WarmupCount.MakeDefault(), unrollFactor); - public void RunMain(long invokeCount, int unrollFactor) => Run(invokeCount, IterationMode.MainWarmup, TargetJob.Run.WarmupCount, unrollFactor); - private List RunAuto(long invokeCount, IterationMode iterationMode, int unrollFactor) { int iterationCounter = 0; - var measurements = new List(MaxIterationCount); while (true) { iterationCounter++; @@ -36,16 +44,18 @@ private List RunAuto(long invokeCount, IterationMode iterationMode, if (IsWarmupFinished(measurements, iterationMode)) break; } - WriteLine(); + if (!IsDiagnoserAttached) WriteLine(); + return measurements; } private List RunSpecific(long invokeCount, IterationMode iterationMode, int iterationCount, int unrollFactor) { - var measurements = new List(iterationCount); for (int i = 0; i < iterationCount; i++) measurements.Add(RunIteration(iterationMode, i + 1, invokeCount, unrollFactor)); - WriteLine(); + + if (!IsDiagnoserAttached) WriteLine(); + return measurements; } diff --git a/src/BenchmarkDotNet.Core/Engines/IEngine.cs b/src/BenchmarkDotNet.Core/Engines/IEngine.cs index db9a9f7978..935364b276 100644 --- a/src/BenchmarkDotNet.Core/Engines/IEngine.cs +++ b/src/BenchmarkDotNet.Core/Engines/IEngine.cs @@ -9,15 +9,15 @@ namespace BenchmarkDotNet.Engines public interface IEngine { [NotNull] - Job TargetJob { get; set; } + Job TargetJob { get; } - long OperationsPerInvoke { get; set; } + long OperationsPerInvoke { get; } [CanBeNull] - Action SetupAction { get; set; } + Action SetupAction { get; } [CanBeNull] - Action CleanupAction { get; set; } + Action CleanupAction { get; } [NotNull] Action MainAction { get; } @@ -25,11 +25,27 @@ public interface IEngine [NotNull] Action IdleAction { get; } + bool IsDiagnoserAttached { get; } + + IResolver Resolver { get; } + Measurement RunIteration(IterationData data); void WriteLine(); void WriteLine(string line); - IResolver Resolver { get; } + /// + /// must provoke all static ctors and perform any other necessary allocations + /// so Run() has 0 exclusive allocations and our Memory Diagnostics is 100% accurate! + /// + void PreAllocate(); + + /// + /// must perform jitting via warmup calls + /// is called after first call to Setup, from the auto-generated benchmark process + /// + void Jitting(); + + RunResults Run(); } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/IEngineFactory.cs b/src/BenchmarkDotNet.Core/Engines/IEngineFactory.cs new file mode 100644 index 0000000000..89dfb14eb3 --- /dev/null +++ b/src/BenchmarkDotNet.Core/Engines/IEngineFactory.cs @@ -0,0 +1,7 @@ +namespace BenchmarkDotNet.Engines +{ + public interface IEngineFactory + { + IEngine Create(EngineParameters engineParameters); + } +} \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/IterationModeExtensions.cs b/src/BenchmarkDotNet.Core/Engines/IterationModeExtensions.cs index 5329e3b79f..88cb925ef9 100644 --- a/src/BenchmarkDotNet.Core/Engines/IterationModeExtensions.cs +++ b/src/BenchmarkDotNet.Core/Engines/IterationModeExtensions.cs @@ -1,9 +1,8 @@ -using BenchmarkDotNet.Extensions; - -namespace BenchmarkDotNet.Engines +namespace BenchmarkDotNet.Engines { public static class IterationModeExtensions { - public static bool IsIdle(this IterationMode mode) => mode.IsOneOf(IterationMode.IdleWarmup, IterationMode.IdleTarget); + public static bool IsIdle(this IterationMode mode) + => mode == IterationMode.IdleWarmup || mode == IterationMode.IdleTarget; } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Engines/RunResults.cs b/src/BenchmarkDotNet.Core/Engines/RunResults.cs new file mode 100644 index 0000000000..bf63ee846d --- /dev/null +++ b/src/BenchmarkDotNet.Core/Engines/RunResults.cs @@ -0,0 +1,42 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using BenchmarkDotNet.Mathematics; +using BenchmarkDotNet.Reports; + +namespace BenchmarkDotNet.Engines +{ + public struct RunResults + { + public List Idle { get; } + public List Main { get; } + + public RunResults(List idle, List main) + { + Idle = idle; + Main = main; + } + + public void Print() + { + // TODO: use Accuracy.RemoveOutliers + // TODO: check if resulted measurements are too small (like < 0.1ns) + double overhead = Idle == null ? 0.0 : new Statistics(Idle.Select(m => m.Nanoseconds)).Mean; + int resultIndex = 0; + foreach (var measurement in Main) + { + var resultMeasurement = new Measurement( + measurement.LaunchIndex, + IterationMode.Result, + ++resultIndex, + measurement.Operations, + Math.Max(0, measurement.Nanoseconds - overhead)); + WriteLine(resultMeasurement.ToOutputLine()); + } + WriteLine(); + } + + private void WriteLine() => Console.WriteLine(); + private void WriteLine(string line) => Console.WriteLine(line); + } +} \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Environments/EnvResolver.cs b/src/BenchmarkDotNet.Core/Environments/EnvResolver.cs index 8842396328..d209ddd312 100644 --- a/src/BenchmarkDotNet.Core/Environments/EnvResolver.cs +++ b/src/BenchmarkDotNet.Core/Environments/EnvResolver.cs @@ -21,6 +21,7 @@ private EnvResolver() Register(acc.AnaylyzeLaunchVariance, () => false); var run = Job.Default.Run; Register(run.UnrollFactor, () => 16); + Register(run.InvocationCount, () => 1); } } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Environments/InfrastructureResolver.cs b/src/BenchmarkDotNet.Core/Environments/InfrastructureResolver.cs index 97daf8ee73..75ae6bae14 100644 --- a/src/BenchmarkDotNet.Core/Environments/InfrastructureResolver.cs +++ b/src/BenchmarkDotNet.Core/Environments/InfrastructureResolver.cs @@ -1,4 +1,5 @@ using BenchmarkDotNet.Characteristics; +using BenchmarkDotNet.Engines; using BenchmarkDotNet.Horology; using BenchmarkDotNet.Jobs; @@ -12,6 +13,7 @@ private InfrastructureResolver() { var infra = Job.Default.Infrastructure; Register(infra.Clock, () => Chronometer.BestClock); + Register(infra.EngineFactory, () => new EngineFactory()); } } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Extensions/CommonExtensions.cs b/src/BenchmarkDotNet.Core/Extensions/CommonExtensions.cs index 25763a3816..379fc63148 100644 --- a/src/BenchmarkDotNet.Core/Extensions/CommonExtensions.cs +++ b/src/BenchmarkDotNet.Core/Extensions/CommonExtensions.cs @@ -2,7 +2,6 @@ using System.Collections.Generic; using System.Linq; using BenchmarkDotNet.Environments; -using BenchmarkDotNet.Helpers; using BenchmarkDotNet.Horology; namespace BenchmarkDotNet.Extensions @@ -55,5 +54,13 @@ public static TValue GetValueOrDefault(this IDictionary (int) Math.Round(x); public static long RoundToLong(this double x) => (long) Math.Round(x); + + internal static void ForEach(this IList source, Action command) + { + foreach (var item in source) + { + command(item); + } + } } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Jobs/InfrastructureMode.cs b/src/BenchmarkDotNet.Core/Jobs/InfrastructureMode.cs index 5997a42f72..6ade11aa23 100644 --- a/src/BenchmarkDotNet.Core/Jobs/InfrastructureMode.cs +++ b/src/BenchmarkDotNet.Core/Jobs/InfrastructureMode.cs @@ -17,21 +17,26 @@ private InfrastructureMode() public ICharacteristic Toolchain { get; private set; } = Create(nameof(Toolchain)); public ICharacteristic Clock { get; private set; } = Create(nameof(Clock)); - public ICharacteristic Engine { get; private set; } = Create(nameof(Engine)); + + /// + /// this type will be used in the auto-generated program to create engine in separate process + /// it must have parameterless constructor + /// + public ICharacteristic EngineFactory { get; private set; } = Create(nameof(EngineFactory)); public static InfrastructureMode Parse(CharacteristicSet set) { var mode = new InfrastructureMode(); mode.Toolchain = mode.Toolchain.Mutate(set); mode.Clock = mode.Clock.Mutate(set); - mode.Engine = mode.Engine.Mutate(set); + mode.EngineFactory = mode.EngineFactory.Mutate(set); return mode; } public CharacteristicSet ToSet() => new CharacteristicSet( Toolchain, Clock, - Engine + EngineFactory ); } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Jobs/Job.cs b/src/BenchmarkDotNet.Core/Jobs/Job.cs index 2be8fdf863..f4d1dec6cb 100644 --- a/src/BenchmarkDotNet.Core/Jobs/Job.cs +++ b/src/BenchmarkDotNet.Core/Jobs/Job.cs @@ -1,5 +1,4 @@ -using System.Linq; -using BenchmarkDotNet.Characteristics; +using BenchmarkDotNet.Characteristics; namespace BenchmarkDotNet.Jobs { diff --git a/src/BenchmarkDotNet.Core/Jobs/JobExtensions.cs b/src/BenchmarkDotNet.Core/Jobs/JobExtensions.cs index 28ee4a0eb6..b72e3c227b 100644 --- a/src/BenchmarkDotNet.Core/Jobs/JobExtensions.cs +++ b/src/BenchmarkDotNet.Core/Jobs/JobExtensions.cs @@ -36,7 +36,7 @@ public static class JobExtensions // Infrastructure public static Job With(this Job job, IToolchain toolchain) => job.With(job.Infrastructure.Toolchain.Mutate(toolchain)); public static Job With(this Job job, IClock clock) => job.With(job.Infrastructure.Clock.Mutate(clock)); - public static Job With(this Job job, IEngine engine) => job.With(job.Infrastructure.Engine.Mutate(engine)); + public static Job With(this Job job, IEngineFactory engineFactory) => job.With(job.Infrastructure.EngineFactory.Mutate(engineFactory)); // Accuracy public static Job WithMaxStdErrRelative(this Job job, double value) => job.With(job.Accuracy.MaxStdErrRelative.Mutate(value)); diff --git a/src/BenchmarkDotNet.Core/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs b/src/BenchmarkDotNet.Core/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs index 55465823a4..56e798b006 100644 --- a/src/BenchmarkDotNet.Core/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs +++ b/src/BenchmarkDotNet.Core/Loggers/SynchronousProcessOutputLoggerWithDiagnoser.cs @@ -43,28 +43,28 @@ internal void ProcessInput() { logger.WriteLine(LogKind.Default, line); - if (!string.IsNullOrEmpty(line)) + if (string.IsNullOrEmpty(line)) + continue; + + if (!line.StartsWith("//")) { - if (!line.StartsWith("//")) - LinesWithResults.Add(line); - else - LinesWithExtraOutput.Add(line); + LinesWithResults.Add(line); } - - // This is important so the Diagnoser can know the [Benchmark] methods will have run and (e.g.) it can do a Memory Dump - if (diagnosticsAlreadyRun || !line.StartsWith(IterationMode.MainWarmup.ToString())) + else if (line == Engine.Signals.BeforeAnythingElse) { - continue; + diagnoser?.BeforeAnythingElse(process, benchmark); } - - try + else if (line == Engine.Signals.AfterSetup) + { + diagnoser?.AfterSetup(process, benchmark); + } + else if (line == Engine.Signals.BeforeCleanup) { - diagnoser?.AfterBenchmarkHasRun(benchmark, process); + diagnoser?.BeforeCleanup(); } - finally + else { - // Always set this, even if something went wrong, otherwise we will try on every run of a benchmark batch - diagnosticsAlreadyRun = true; + LinesWithExtraOutput.Add(line); } } } diff --git a/src/BenchmarkDotNet.Core/Mathematics/MeasurementsStatistics.cs b/src/BenchmarkDotNet.Core/Mathematics/MeasurementsStatistics.cs new file mode 100644 index 0000000000..596fc32b5a --- /dev/null +++ b/src/BenchmarkDotNet.Core/Mathematics/MeasurementsStatistics.cs @@ -0,0 +1,122 @@ +using BenchmarkDotNet.Reports; +using System; +using System.Collections.Generic; + +namespace BenchmarkDotNet.Mathematics +{ + /// + /// the goal of this struct is to avoid any heap allocations, please keep it in mind + /// + internal struct MeasurementsStatistics + { + public double StandardError { get; } + public double Mean { get; } + + private MeasurementsStatistics(double standardError, double mean) + { + StandardError = standardError; + Mean = mean; + } + + public static MeasurementsStatistics Calculate(List measurements, bool removeOutliers) + { + var n = measurements.Count; + if (n == 0) + throw new InvalidOperationException("StatSummary: Sequence contains no elements"); + + var sum = Sum(measurements); + var mean = sum / n; + + var variance = Variance(measurements, n, mean); + var standardDeviation = Math.Sqrt(variance); + var standardError = standardDeviation / Math.Sqrt(n); + + if (!removeOutliers) // most simple scenario is done without allocations! but this is not the default case + return new MeasurementsStatistics(standardError, mean); + + measurements.Sort(); // sort in place + + double q1, median, q3; + + if (n == 1) + q1 = median = q3 = measurements[0].Nanoseconds; + else + { + q1 = GetQuartile(measurements, measurements.Count / 2); + median = GetQuartile(measurements, measurements.Count); + q3 = GetQuartile(measurements, measurements.Count * 3 / 2); + } + + var interquartileRange = q3 - q1; + var lowerFence = q1 - 1.5 * interquartileRange; + var upperFence = q3 + 1.5 * interquartileRange; + + SumWithoutOutliers(measurements, lowerFence, upperFence, out sum, out n); // updates sum and N + mean = sum / n; + + variance = VarianceWithoutOutliers(measurements, n, mean, lowerFence, upperFence); + standardDeviation = Math.Sqrt(variance); + standardError = standardDeviation / Math.Sqrt(n); + + return new MeasurementsStatistics(standardError, mean); + } + + private static double Sum(List measurements) + { + double sum = 0; + for (int i = 0; i < measurements.Count; i++) + sum += measurements[i].Nanoseconds; + return sum; + } + + private static void SumWithoutOutliers(List measurements, + double lowerFence, double upperFence, out double sum, out int n) + { + sum = 0; + n = 0; + + for (int i = 0; i < measurements.Count; i++) + if (!IsOutlier(measurements[i].Nanoseconds, lowerFence, upperFence)) + { + sum += measurements[i].Nanoseconds; + ++n; + } + } + + private static double Variance(List measurements, int n, double mean) + { + if (n == 1) + return 0; + + double variance = 0; + for (int i = 0; i < measurements.Count; i++) + variance += (measurements[i].Nanoseconds - mean) * (measurements[i].Nanoseconds - mean) / (n - 1); + + return variance; + } + + private static double VarianceWithoutOutliers(List measurements, int n, double mean, double lowerFence, double upperFence) + { + if (n == 1) + return 0; + + double variance = 0; + for (int i = 0; i < measurements.Count; i++) + if (!IsOutlier(measurements[i].Nanoseconds, lowerFence, upperFence)) + variance += (measurements[i].Nanoseconds - mean) * (measurements[i].Nanoseconds - mean) / (n - 1); + + return variance; + } + + private static double GetQuartile(List measurements, int count) + { + if (count % 2 == 0) + return (measurements[count / 2 - 1].Nanoseconds + measurements[count / 2].Nanoseconds) / 2; + + return measurements[count / 2].Nanoseconds; + } + + private static bool IsOutlier(double value, double lowerFence, double upperFence) + => value < lowerFence || value > upperFence; + } +} diff --git a/src/BenchmarkDotNet.Core/Reports/Measurement.cs b/src/BenchmarkDotNet.Core/Reports/Measurement.cs index dde0d47f7a..1b07e8edef 100644 --- a/src/BenchmarkDotNet.Core/Reports/Measurement.cs +++ b/src/BenchmarkDotNet.Core/Reports/Measurement.cs @@ -2,7 +2,6 @@ using BenchmarkDotNet.Engines; using BenchmarkDotNet.Environments; using BenchmarkDotNet.Extensions; -using BenchmarkDotNet.Helpers; using BenchmarkDotNet.Loggers; namespace BenchmarkDotNet.Reports @@ -10,7 +9,7 @@ namespace BenchmarkDotNet.Reports /// /// The basic captured statistics for a benchmark. /// - public struct Measurement + public struct Measurement : IComparable { private static readonly Measurement Error = new Measurement(-1, IterationMode.Unknown, 0, 0, 0); @@ -31,7 +30,7 @@ public struct Measurement public double Nanoseconds { get; } /// - /// Creates an instance of class. + /// Creates an instance of struct. /// /// /// @@ -112,6 +111,8 @@ private static IterationMode ParseIterationMode(string name) return Enum.TryParse(name, out mode) ? mode : IterationMode.Unknown; } + public int CompareTo(Measurement other) => Nanoseconds.CompareTo(other.Nanoseconds); + public override string ToString() => $"#{LaunchIndex}/{IterationMode} {IterationIndex}: {Operations} op, {Nanoseconds.ToTimeStr()}"; } } \ No newline at end of file diff --git a/src/BenchmarkDotNet.Core/Running/BenchmarkRunnerCore.cs b/src/BenchmarkDotNet.Core/Running/BenchmarkRunnerCore.cs index db24962b12..fc60281121 100644 --- a/src/BenchmarkDotNet.Core/Running/BenchmarkRunnerCore.cs +++ b/src/BenchmarkDotNet.Core/Running/BenchmarkRunnerCore.cs @@ -271,14 +271,16 @@ private static List Execute(ILogger logger, Benchmark benchmark, logger.WriteLine(); // Do a "Diagnostic" run, but DISCARD the results, so that the overhead of Diagnostics doesn't skew the overall results - if (config.GetDiagnosers().Count() > 0) + if (config.GetDiagnosers().Any()) { - logger.WriteLineInfo($"// Run, Diagnostic"); - config.GetCompositeDiagnoser().Start(benchmark); - var executeResult = toolchain.Executor.Execute(buildResult, benchmark, logger, resolver, config.GetCompositeDiagnoser()); + logger.WriteLineInfo("// Run, Diagnostic"); + var compositeDiagnoser = config.GetCompositeDiagnoser(); + + var executeResult = toolchain.Executor.Execute(buildResult, benchmark, logger, resolver, compositeDiagnoser); + var allRuns = executeResult.Data.Select(line => Measurement.Parse(logger, line, 0)).Where(r => r.IterationMode != IterationMode.Unknown).ToList(); var report = new BenchmarkReport(benchmark, null, null, new[] { executeResult }, allRuns); - config.GetCompositeDiagnoser().Stop(benchmark, report); + compositeDiagnoser.ProcessResults(benchmark, report); if (!executeResult.FoundExecutable) logger.WriteLineError("Executable not found"); diff --git a/src/BenchmarkDotNet.Core/Templates/BenchmarkProgram.txt b/src/BenchmarkDotNet.Core/Templates/BenchmarkProgram.txt index 4fd4b67e25..df7c3d630d 100644 --- a/src/BenchmarkDotNet.Core/Templates/BenchmarkProgram.txt +++ b/src/BenchmarkDotNet.Core/Templates/BenchmarkProgram.txt @@ -1,6 +1,8 @@ using System; using System.Diagnostics; +using System.Linq; using System.Threading; +using System.Reflection; using System.Runtime.CompilerServices; using BenchmarkDotNet; using BenchmarkDotNet.Characteristics; @@ -17,50 +19,87 @@ $AdditionalLogic$ namespace BenchmarkDotNet.Autogenerated { - public class Program : global::$TargetTypeName$ + public class Program { $ExtraAttribute$ public static int Main(string[] args) { + bool isDiagnoserAttached = args != null && args.Contains(BenchmarkDotNet.Engines.Engine.Signals.DiagnoserIsAttachedParam); + + // the first thing to do is to let diagnosers hook in before anything happens + // so all jit-related diagnosers can catch first jit compilation! + if(isDiagnoserAttached) + System.Console.WriteLine(BenchmarkDotNet.Engines.Engine.Signals.BeforeAnythingElse); + try { - Program instance = new Program(); - $ParamsContent$ - - instance.setupAction(); - instance.mainAction(); - instance.cleanupAction(); - - System.Console.WriteLine(); - foreach (var infoLine in BenchmarkEnvironmentInfo.GetCurrent().ToFormattedString()) - { - System.Console.WriteLine("// {0}", infoLine); - } - var set = $JobSetDefinition$; - var job = Job.Parse(set, false); - System.Console.WriteLine("// Job: {0}", job.DisplayInfo); - System.Console.WriteLine(); - - - var engine = new BenchmarkDotNet.Engines.Engine(instance.IdleMultiAction, instance.MainMultiAction) - { - SetupAction = instance.setupAction, - CleanupAction = instance.cleanupAction, - TargetJob = job, - OperationsPerInvoke = $OperationsPerInvoke$, - }; - engine.Run(); + // we are not using Runnable here in any direct way in order to avoid strong dependency Main<=>Runnable + // which could cause the jitting/assembly loading to happen before we do anything + // we have some jitting diagnosers and we want them to catch all the informations!! + + Type type = typeof(Program).GetTypeInfo().Assembly.GetType("BenchmarkDotNet.Autogenerated.Runnable"); + + type.GetMethod("Run", BindingFlags.Public | BindingFlags.Static).Invoke(null, new object[] { isDiagnoserAttached }); return 0; } - catch (Exception ex) + catch(Exception ex) { System.Console.WriteLine(ex); return -1; } } + } + + public class Runnable : global::$TargetTypeName$ + { + public static void Run(bool isDiagnoserAttached) + { + Runnable instance = new Runnable(); + $ParamsContent$ + + System.Console.WriteLine(); + foreach (var infoLine in BenchmarkEnvironmentInfo.GetCurrent().ToFormattedString()) + { + System.Console.WriteLine("// {0}", infoLine); + } + var set = $JobSetDefinition$; + var job = Job.Parse(set, false); + System.Console.WriteLine("// Job: {0}", job.DisplayInfo); + System.Console.WriteLine(); + + var engineParameters = new BenchmarkDotNet.Engines.EngineParameters() + { + MainAction = instance.MainMultiAction, + IdleAction = instance.IdleMultiAction, + SetupAction = instance.setupAction, + CleanupAction = instance.cleanupAction, + TargetJob = job, + OperationsPerInvoke = $OperationsPerInvoke$, + IsDiagnoserAttached = isDiagnoserAttached + }; + + var engine = new $EngineFactoryType$().Create(engineParameters); + + engine.PreAllocate(); + + instance?.setupAction(); + + engine.Jitting(); // does first call to main action, must be executed after setup()! + + if(isDiagnoserAttached) + System.Console.WriteLine(BenchmarkDotNet.Engines.Engine.Signals.AfterSetup); + + var results = engine.Run(); + + if(isDiagnoserAttached) + System.Console.WriteLine(BenchmarkDotNet.Engines.Engine.Signals.BeforeCleanup); + instance?.cleanupAction(); + + results.Print(); // printing costs memory, do this after runs + } - public Program() + public Runnable() { setupAction = $SetupMethodName$; cleanupAction = $CleanupMethodName$; diff --git a/src/BenchmarkDotNet.Core/Toolchains/Executor.cs b/src/BenchmarkDotNet.Core/Toolchains/Executor.cs index 003566f978..ef57213913 100644 --- a/src/BenchmarkDotNet.Core/Toolchains/Executor.cs +++ b/src/BenchmarkDotNet.Core/Toolchains/Executor.cs @@ -4,6 +4,7 @@ using System.Text; using BenchmarkDotNet.Characteristics; using BenchmarkDotNet.Diagnosers; +using BenchmarkDotNet.Engines; using BenchmarkDotNet.Environments; using BenchmarkDotNet.Extensions; using BenchmarkDotNet.Loggers; @@ -22,7 +23,7 @@ internal class Executor : IExecutor public ExecuteResult Execute(BuildResult buildResult, Benchmark benchmark, ILogger logger, IResolver resolver, IDiagnoser compositeDiagnoser = null) { var exePath = buildResult.ArtifactsPaths.ExecutablePath; - var args = string.Empty; + var args = compositeDiagnoser == null ? string.Empty : Engine.Signals.DiagnoserIsAttachedParam; if (!File.Exists(exePath)) { @@ -46,7 +47,7 @@ private ExecuteResult Execute(Benchmark benchmark, ILogger logger, string exeNam using (var process = new Process { StartInfo = CreateStartInfo(benchmark, exeName, args, workingDirectory, resolver) }) { var loggerWithDiagnoser = new SynchronousProcessOutputLoggerWithDiagnoser(logger, process, diagnoser, benchmark); - + return Execute(process, benchmark, loggerWithDiagnoser, diagnoser, logger); } } @@ -63,8 +64,6 @@ private ExecuteResult Execute(Process process, Benchmark benchmark, SynchronousP process.Start(); - compositeDiagnoser?.ProcessStarted(process); - process.EnsureHighPriority(logger); if (!benchmark.Job.Env.Affinity.IsDefault) { @@ -75,8 +74,6 @@ private ExecuteResult Execute(Process process, Benchmark benchmark, SynchronousP process.WaitForExit(); // should we add timeout here? - compositeDiagnoser?.ProcessStopped(process); - if (process.ExitCode == 0) { return new ExecuteResult(true, process.ExitCode, loggerWithDiagnoser.LinesWithResults, loggerWithDiagnoser.LinesWithExtraOutput); diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/Configs/InliningDiagnoserAttribute.cs b/src/BenchmarkDotNet.Diagnostics.Windows/Configs/InliningDiagnoserAttribute.cs new file mode 100644 index 0000000000..d24dd2c4ac --- /dev/null +++ b/src/BenchmarkDotNet.Diagnostics.Windows/Configs/InliningDiagnoserAttribute.cs @@ -0,0 +1,15 @@ +using System; +using BenchmarkDotNet.Configs; + +namespace BenchmarkDotNet.Diagnostics.Windows.Configs +{ + public class InliningDiagnoserAttribute : Attribute, IConfigSource + { + public IConfig Config { get; } + + public InliningDiagnoserAttribute() + { + Config = ManualConfig.CreateEmpty().With(new InliningDiagnoser()); + } + } +} \ No newline at end of file diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/Configs/MemoryDiagnoserAttribute.cs b/src/BenchmarkDotNet.Diagnostics.Windows/Configs/MemoryDiagnoserAttribute.cs new file mode 100644 index 0000000000..aa03c926cf --- /dev/null +++ b/src/BenchmarkDotNet.Diagnostics.Windows/Configs/MemoryDiagnoserAttribute.cs @@ -0,0 +1,15 @@ +using System; +using BenchmarkDotNet.Configs; + +namespace BenchmarkDotNet.Diagnostics.Windows.Configs +{ + public class MemoryDiagnoserAttribute : Attribute, IConfigSource + { + public IConfig Config { get; } + + public MemoryDiagnoserAttribute() + { + Config = ManualConfig.CreateEmpty().With(new MemoryDiagnoser()); + } + } +} \ No newline at end of file diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/EtwDiagnoser.cs b/src/BenchmarkDotNet.Diagnostics.Windows/EtwDiagnoser.cs index 48702fb3d5..c31b59ae05 100644 --- a/src/BenchmarkDotNet.Diagnostics.Windows/EtwDiagnoser.cs +++ b/src/BenchmarkDotNet.Diagnostics.Windows/EtwDiagnoser.cs @@ -1,18 +1,110 @@ -using BenchmarkDotNet.Parameters; +using System; +using System.Collections.Concurrent; +using BenchmarkDotNet.Parameters; using BenchmarkDotNet.Running; using System.Collections.Generic; +using System.Diagnostics; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.Diagnostics.Tracing; +using Microsoft.Diagnostics.Tracing.Parsers; +using Microsoft.Diagnostics.Tracing.Session; namespace BenchmarkDotNet.Diagnostics.Windows { - public abstract class ETWDiagnoser + public abstract class EtwDiagnoser where TStats : new() { + protected readonly LogCapture Logger = new LogCapture(); protected readonly List ProcessIdsUsedInRuns = new List(); + protected readonly ConcurrentDictionary StatsPerProcess = new ConcurrentDictionary(); - protected string GetSessionName(string prefix, Benchmark benchmark, ParameterInstances parameters = null) + private TraceEventSession session; + + protected abstract ClrTraceEventParser.Keywords EventType { get; } + + protected abstract string SessionNamePrefix { get; } + + protected void Start(Process process, Benchmark benchmark) + { + Cleanup(); + + ProcessIdsUsedInRuns.Add(process.Id); + StatsPerProcess.TryAdd(process.Id, new TStats()); + + AttachToEvents(CreateSession(benchmark), benchmark); + + EnableProvider(); + + // The ETW collection thread starts receiving events immediately, but we only + // start aggregating them after ProcessStarted is called and we know which process + // (or processes) we should be monitoring. Communication between the benchmark thread + // and the ETW collection thread is through the statsPerProcess concurrent dictionary + // and through the TraceEventSession class, which is thread-safe. + var task = Task.Factory.StartNew((Action)(() => session.Source.Process()), TaskCreationOptions.LongRunning); + + // wait until the processing has started, block by then so we don't loose any + // information (very important for jit-related things) + WaitUntilStarted(task); + } + + protected void Stop() + { + WaitForDelayedEvents(); + + session.Dispose(); + } + + protected abstract void AttachToEvents(TraceEventSession traceEventSession, Benchmark benchmark); + + private void Cleanup() + { + ProcessIdsUsedInRuns.Clear(); + StatsPerProcess.Clear(); + } + + private TraceEventSession CreateSession(Benchmark benchmark) + { + var sessionName = GetSessionName(SessionNamePrefix, benchmark, benchmark.Parameters); + + session = new TraceEventSession(sessionName); + + return session; + } + + private void EnableProvider() + { + session.EnableProvider( + ClrTraceEventParser.ProviderGuid, + TraceEventLevel.Verbose, + (ulong)(EventType)); + } + + private static string GetSessionName(string prefix, Benchmark benchmark, ParameterInstances parameters = null) { if (parameters != null && parameters.Items.Count > 0) return $"{prefix}-{benchmark.FolderInfo}-{parameters.FolderInfo}"; return $"{prefix}-{benchmark.FolderInfo}"; } + + private static void WaitUntilStarted(Task task) + { + while (task.Status == TaskStatus.Created + || task.Status == TaskStatus.WaitingForActivation + || task.Status == TaskStatus.WaitingToRun) + { + Thread.Sleep(10); + } + } + + /// + /// ETW real-time sessions receive events with a slight delay. Typically it + /// shouldn't be more than a few seconds. This increases the likelihood that + /// all relevant events are processed by the collection thread by the time we + /// are done with the benchmark. + /// + private static void WaitForDelayedEvents() + { + Thread.Sleep(TimeSpan.FromSeconds(3)); + } } } diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/InliningDiagnoser.cs b/src/BenchmarkDotNet.Diagnostics.Windows/InliningDiagnoser.cs index a510e62612..7cbf50e307 100644 --- a/src/BenchmarkDotNet.Diagnostics.Windows/InliningDiagnoser.cs +++ b/src/BenchmarkDotNet.Diagnostics.Windows/InliningDiagnoser.cs @@ -1,128 +1,58 @@ -using BenchmarkDotNet.Diagnosers; -using BenchmarkDotNet.Loggers; -using BenchmarkDotNet.Reports; +using BenchmarkDotNet.Loggers; using BenchmarkDotNet.Running; -using Microsoft.Diagnostics.Tracing; -using Microsoft.Diagnostics.Tracing.Parsers; using Microsoft.Diagnostics.Tracing.Session; -using System; -using System.Collections.Concurrent; -using System.Diagnostics; -using System.Threading; -using System.Threading.Tasks; -using BenchmarkDotNet.Columns; namespace BenchmarkDotNet.Diagnostics.Windows { - public class InliningDiagnoser : ETWDiagnoser, IDiagnoser + public class InliningDiagnoser : JitDiagnoser { - private readonly LogCapture logger = new LogCapture(); - private readonly ConcurrentDictionary statsPerProcess = new ConcurrentDictionary(); - private TraceEventSession session; + private static readonly string LogSeparator = new string('-', 20); - public void Start(Benchmark benchmark) + protected override void AttachToEvents(TraceEventSession session, Benchmark benchmark) { - ProcessIdsUsedInRuns.Clear(); - statsPerProcess.Clear(); - - var sessionName = GetSessionName("JitTracing", benchmark, benchmark.Parameters); - session = new TraceEventSession(sessionName); - session.EnableProvider(ClrTraceEventParser.ProviderGuid, - TraceEventLevel.Verbose, - (ulong)(ClrTraceEventParser.Keywords.JitTracing)); - - // The ETW collection thread starts receiving events immediately, but we only - // start aggregating them after ProcessStarted is called and we know which process - // (or processes) we should be monitoring. Communication between the benchmark thread - // and the ETW collection thread is through the statsPerProcess concurrent dictionary - // and through the TraceEventSession class, which is thread-safe. - Task.Factory.StartNew(() => StartProcessingEvents(benchmark), TaskCreationOptions.LongRunning); - } - - public void Stop(Benchmark benchmark, BenchmarkReport report) - { - // ETW real-time sessions receive events with a slight delay. Typically it - // shouldn't be more than a few seconds. This increases the likelihood that - // all relevant events are processed by the collection thread by the time we - // are done with the benchmark. - Thread.Sleep(TimeSpan.FromSeconds(3)); - - session.Dispose(); - } - - public void ProcessStarted(Process process) - { - ProcessIdsUsedInRuns.Add(process.Id); - statsPerProcess.TryAdd(process.Id, null); - } - - public void AfterBenchmarkHasRun(Benchmark benchmark, Process process) - { - // Do nothing - } - - public void ProcessStopped(Process process) - { - // Do nothing - } - - public void DisplayResults(ILogger outputLogger) - { - if (logger.CapturedOutput.Count > 0) - outputLogger.WriteLineHeader(new string('-', 20)); - foreach (var line in logger.CapturedOutput) - outputLogger.Write(line.Kind, line.Text); - } - - private void StartProcessingEvents(Benchmark benchmark) - { - var expected = benchmark.Target.Method.DeclaringType.Namespace + "." + + var expected = benchmark.Target.Method.DeclaringType.Namespace + "." + benchmark.Target.Method.DeclaringType.Name; - logger.WriteLine(); - logger.WriteLineHeader(new string('-', 20)); - logger.WriteLineInfo($"{benchmark.DisplayInfo}"); - logger.WriteLineHeader(new string('-', 20)); + Logger.WriteLine(); + Logger.WriteLineHeader(LogSeparator); + Logger.WriteLineInfo($"{benchmark.DisplayInfo}"); + Logger.WriteLineHeader(LogSeparator); session.Source.Clr.MethodInliningSucceeded += jitData => { // Inliner = the parent method (the inliner calls the inlinee) // Inlinee = the method that is going to be "inlined" inside the inliner (it's caller) - object _ignored; - if (statsPerProcess.TryGetValue(jitData.ProcessID, out _ignored)) + object ignored; + if (StatsPerProcess.TryGetValue(jitData.ProcessID, out ignored)) { var shouldPrint = jitData.InlinerNamespace == expected || jitData.InlineeNamespace == expected; if (shouldPrint) { - logger.WriteLineHelp($"Inliner: {jitData.InlinerNamespace}.{jitData.InlinerName} - {jitData.InlinerNameSignature}"); - logger.WriteLineHelp($"Inlinee: {jitData.InlineeNamespace}.{jitData.InlineeName} - {jitData.InlineeNameSignature}"); - logger.WriteLineHeader(new string('-', 20)); + Logger.WriteLineHelp($"Inliner: {jitData.InlinerNamespace}.{jitData.InlinerName} - {jitData.InlinerNameSignature}"); + Logger.WriteLineHelp($"Inlinee: {jitData.InlineeNamespace}.{jitData.InlineeName} - {jitData.InlineeNameSignature}"); + Logger.WriteLineHeader(LogSeparator); } } }; session.Source.Clr.MethodInliningFailed += jitData => { - object _ignored; - if (statsPerProcess.TryGetValue(jitData.ProcessID, out _ignored)) + object ignored; + if (StatsPerProcess.TryGetValue(jitData.ProcessID, out ignored)) { var shouldPrint = jitData.InlinerNamespace == expected || jitData.InlineeNamespace == expected; if (shouldPrint) { - logger.WriteLineError($"Inliner: {jitData.InlinerNamespace}.{jitData.InlinerName} - {jitData.InlinerNameSignature}"); - logger.WriteLineError($"Inlinee: {jitData.InlineeNamespace}.{jitData.InlineeName} - {jitData.InlineeNameSignature}"); + Logger.WriteLineError($"Inliner: {jitData.InlinerNamespace}.{jitData.InlinerName} - {jitData.InlinerNameSignature}"); + Logger.WriteLineError($"Inlinee: {jitData.InlineeNamespace}.{jitData.InlineeName} - {jitData.InlineeNameSignature}"); // See https://blogs.msdn.microsoft.com/clrcodegeneration/2009/10/21/jit-etw-inlining-event-fail-reasons/ - logger.WriteLineError($"Fail Reason: {jitData.FailReason}"); - logger.WriteLineHeader(new string('-', 20)); + Logger.WriteLineError($"Fail Reason: {jitData.FailReason}"); + Logger.WriteLineHeader(LogSeparator); } } }; - - session.Source.Process(); } - - public IColumnProvider GetColumnProvider() => EmptyColumnProvider.Instance; } } diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/JitDiagnoser.cs b/src/BenchmarkDotNet.Diagnostics.Windows/JitDiagnoser.cs new file mode 100644 index 0000000000..0073a3011f --- /dev/null +++ b/src/BenchmarkDotNet.Diagnostics.Windows/JitDiagnoser.cs @@ -0,0 +1,35 @@ +using System.Diagnostics; +using BenchmarkDotNet.Columns; +using BenchmarkDotNet.Diagnosers; +using BenchmarkDotNet.Loggers; +using BenchmarkDotNet.Reports; +using BenchmarkDotNet.Running; +using Microsoft.Diagnostics.Tracing.Parsers; + +namespace BenchmarkDotNet.Diagnostics.Windows +{ + public abstract class JitDiagnoser : EtwDiagnoser, IDiagnoser + { + protected override ClrTraceEventParser.Keywords EventType => ClrTraceEventParser.Keywords.JitTracing; + + protected override string SessionNamePrefix => "JitTracing"; + + public IColumnProvider GetColumnProvider() => EmptyColumnProvider.Instance; + + public void BeforeAnythingElse(Process process, Benchmark benchmark) => Start(process, benchmark); + + public void AfterSetup(Process process, Benchmark benchmark) { } + + public void BeforeCleanup() => Stop(); + + public virtual void ProcessResults(Benchmark benchmark, BenchmarkReport report) { } + + public void DisplayResults(ILogger outputLogger) + { + if (Logger.CapturedOutput.Count > 0) + outputLogger.WriteLineHeader(new string('-', 20)); + foreach (var line in Logger.CapturedOutput) + outputLogger.Write(line.Kind, line.Text); + } + } +} \ No newline at end of file diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/LogCapture.cs b/src/BenchmarkDotNet.Diagnostics.Windows/LogCapture.cs index df04091070..9142304b2b 100644 --- a/src/BenchmarkDotNet.Diagnostics.Windows/LogCapture.cs +++ b/src/BenchmarkDotNet.Diagnostics.Windows/LogCapture.cs @@ -1,10 +1,9 @@ -using System; -using System.Collections.Generic; +using System.Collections.Generic; using BenchmarkDotNet.Loggers; namespace BenchmarkDotNet.Diagnostics.Windows { - internal class LogCapture : ILogger + public class LogCapture : ILogger { public IList CapturedOutput = new List(100); @@ -38,7 +37,7 @@ public void Clear() } } - internal struct OutputLine + public struct OutputLine { public LogKind Kind { get; set; } public string Text { get; set; } diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/MemoryDiagnoser.cs b/src/BenchmarkDotNet.Diagnostics.Windows/MemoryDiagnoser.cs index 0feedb3841..76d20979e8 100644 --- a/src/BenchmarkDotNet.Diagnostics.Windows/MemoryDiagnoser.cs +++ b/src/BenchmarkDotNet.Diagnostics.Windows/MemoryDiagnoser.cs @@ -3,28 +3,20 @@ using BenchmarkDotNet.Loggers; using BenchmarkDotNet.Reports; using BenchmarkDotNet.Running; -using Microsoft.Diagnostics.Tracing; using Microsoft.Diagnostics.Tracing.Parsers; using Microsoft.Diagnostics.Tracing.Parsers.Clr; using Microsoft.Diagnostics.Tracing.Session; -using System; -using System.Collections.Concurrent; using System.Collections.Generic; using System.Diagnostics; using System.Linq; -using System.Threading; -using System.Threading.Tasks; using BenchmarkDotNet.Environments; namespace BenchmarkDotNet.Diagnostics.Windows { - public class MemoryDiagnoser : ETWDiagnoser, IDiagnoser + public class MemoryDiagnoser : EtwDiagnoser, IDiagnoser { private readonly List output = new List(); - private readonly LogCapture logger = new LogCapture(); private readonly Dictionary results = new Dictionary(); - private TraceEventSession session; - private readonly ConcurrentDictionary statsPerProcess = new ConcurrentDictionary(); public IColumnProvider GetColumnProvider() => new SimpleColumnProvider( new GCCollectionColumn(results, 0), @@ -32,52 +24,20 @@ public class MemoryDiagnoser : ETWDiagnoser, IDiagnoser new GCCollectionColumn(results, 2), new AllocationColumn(results)); - public void Start(Benchmark benchmark) - { - ProcessIdsUsedInRuns.Clear(); - statsPerProcess.Clear(); - - var sessionName = GetSessionName("GC", benchmark, benchmark.Parameters); - session = new TraceEventSession(sessionName); - session.EnableProvider(ClrTraceEventParser.ProviderGuid, TraceEventLevel.Verbose, - (ulong) (ClrTraceEventParser.Keywords.GC)); - - // The ETW collection thread starts receiving events immediately, but we only - // start aggregating them after ProcessStarted is called and we know which process - // (or processes) we should be monitoring. Communication between the benchmark thread - // and the ETW collection thread is through the statsPerProcess concurrent dictionary - // and through the TraceEventSession class, which is thread-safe. - Task.Factory.StartNew(StartProcessingEvents, TaskCreationOptions.LongRunning); - } - - public void Stop(Benchmark benchmark, BenchmarkReport report) - { - // ETW real-time sessions receive events with a slight delay. Typically it - // shouldn't be more than a few seconds. This increases the likelihood that - // all relevant events are processed by the collection thread by the time we - // are done with the benchmark. - Thread.Sleep(TimeSpan.FromSeconds(3)); + protected override ClrTraceEventParser.Keywords EventType => ClrTraceEventParser.Keywords.GC; - session.Dispose(); + protected override string SessionNamePrefix => "GC"; - var stats = ProcessEtwEvents(report.AllMeasurements.Sum(m => m.Operations)); - results.Add(benchmark, stats); - } + public void BeforeAnythingElse(Process process, Benchmark benchmark) { } - public void ProcessStarted(Process process) - { - ProcessIdsUsedInRuns.Add(process.Id); - statsPerProcess.TryAdd(process.Id, new Stats()); - } + public void AfterSetup(Process process, Benchmark benchmark) => Start(process, benchmark); - public void AfterBenchmarkHasRun(Benchmark benchmark, Process process) - { - // Do nothing - } + public void BeforeCleanup() => Stop(); - public void ProcessStopped(Process process) + public void ProcessResults(Benchmark benchmark, BenchmarkReport report) { - // Do nothing + var stats = ProcessEtwEvents(report.AllMeasurements.Sum(m => m.Operations)); + results.Add(benchmark, stats); } public void DisplayResults(ILogger logger) @@ -92,7 +52,7 @@ private Stats ProcessEtwEvents(long totalOperations) { var processToReport = ProcessIdsUsedInRuns[0]; Stats stats; - if (statsPerProcess.TryGetValue(processToReport, out stats)) + if (StatsPerProcess.TryGetValue(processToReport, out stats)) { stats.TotalOperations = totalOperations; return stats; @@ -101,19 +61,19 @@ private Stats ProcessEtwEvents(long totalOperations) return null; } - private void StartProcessingEvents() + protected override void AttachToEvents(TraceEventSession session, Benchmark benchmark) { session.Source.Clr.GCAllocationTick += gcData => { Stats stats; - if (statsPerProcess.TryGetValue(gcData.ProcessID, out stats)) + if (StatsPerProcess.TryGetValue(gcData.ProcessID, out stats)) stats.AllocatedBytes += gcData.AllocationAmount64; }; session.Source.Clr.GCStart += gcData => { Stats stats; - if (statsPerProcess.TryGetValue(gcData.ProcessID, out stats)) + if (StatsPerProcess.TryGetValue(gcData.ProcessID, out stats)) { var genCounts = stats.GenCounts; if (gcData.Depth >= 0 && gcData.Depth < genCounts.Length) @@ -124,13 +84,11 @@ private void StartProcessingEvents() } else { - logger.WriteLineError(string.Format("Error Process{0}, Unexpected GC Depth: {1}, Count: {2} -> Reason: {3}", gcData.ProcessID, + Logger.WriteLineError(string.Format("Error Process{0}, Unexpected GC Depth: {1}, Count: {2} -> Reason: {3}", gcData.ProcessID, gcData.Depth, gcData.Count, gcData.Reason)); } } }; - - session.Source.Process(); } public class AllocationColumn : IColumn diff --git a/tests/BenchmarkDotNet.IntegrationTests/CustomEngineTests.cs b/tests/BenchmarkDotNet.IntegrationTests/CustomEngineTests.cs new file mode 100644 index 0000000000..52b5d9c3ab --- /dev/null +++ b/tests/BenchmarkDotNet.IntegrationTests/CustomEngineTests.cs @@ -0,0 +1,93 @@ +using System; +using System.Linq; +using System.Collections.Generic; +using BenchmarkDotNet.Attributes; +using Xunit; +using Xunit.Abstractions; +using BenchmarkDotNet.Running; +using BenchmarkDotNet.Configs; +using BenchmarkDotNet.Jobs; +using BenchmarkDotNet.Engines; +using BenchmarkDotNet.Reports; +using BenchmarkDotNet.Characteristics; + +namespace BenchmarkDotNet.IntegrationTests +{ + public class CustomEngineTests : BenchmarkTestExecutor + { + private const string SetupMessage = "// Setup got called"; + private const string EngineRunMessage = "// EngineRun got called"; + private const string CleanupMessage = "// Cleanup got called"; + + public CustomEngineTests(ITestOutputHelper output) : base(output) + { + } + + [Fact] + public void CustomEnginesAreSupported() + { + var config = ManualConfig.CreateEmpty() + .With(Job.Dry.With(new CustomFactory())); + + var summary = CanExecute(config, fullValidation: false); + + AssertMessageGotDisplayed(summary, SetupMessage); + AssertMessageGotDisplayed(summary, EngineRunMessage); + AssertMessageGotDisplayed(summary, CleanupMessage); + } + + private static void AssertMessageGotDisplayed(Summary summary, string message) + { + Assert.True(summary.Reports.Any(report => report.ExecuteResults.Any(executeResult => executeResult.ExtraOutput.Any(line => line == message))), $"{message} should have been printed by custom Engine"); + } + + public class SimpleBenchmark + { + [Setup] + public void Setup() => Console.WriteLine(SetupMessage); + + [Cleanup] + public void Cleanup() => Console.WriteLine(CleanupMessage); + + [Benchmark] + public void Empty() { } + } + + public class CustomFactory : IEngineFactory + { + public IEngine Create(EngineParameters engineParameters) + => new CustomEngine + { + CleanupAction = engineParameters.CleanupAction, + SetupAction = engineParameters.SetupAction + }; + } + + public class CustomEngine : IEngine + { + public RunResults Run() + { + Console.WriteLine(EngineRunMessage); + + return new RunResults( + new List() { default(Measurement) }, + new List() { default(Measurement) }); + } + + public Job TargetJob { get; } + public long OperationsPerInvoke { get; } + public Action SetupAction { get; set; } + public Action CleanupAction { get; set; } + public Action MainAction { get; } + public Action IdleAction { get; } + public bool IsDiagnoserAttached { get; } + public IResolver Resolver { get; } + + public Measurement RunIteration(IterationData data) { throw new NotImplementedException(); } + public void WriteLine() { } + public void WriteLine(string line) { } + public void PreAllocate() { } + public void Jitting() { } + } + } +} \ No newline at end of file diff --git a/tests/BenchmarkDotNet.IntegrationTests/MemoryDiagnoserTests.cs b/tests/BenchmarkDotNet.IntegrationTests/MemoryDiagnoserTests.cs index db961bab09..7fa2f7f4aa 100644 --- a/tests/BenchmarkDotNet.IntegrationTests/MemoryDiagnoserTests.cs +++ b/tests/BenchmarkDotNet.IntegrationTests/MemoryDiagnoserTests.cs @@ -1,9 +1,13 @@ -using System.Collections.Generic; +#if !CORE +using System; +using System.Collections.Generic; using System.Globalization; using System.Linq; +using System.Runtime.CompilerServices; using BenchmarkDotNet.Attributes; using BenchmarkDotNet.Columns; using BenchmarkDotNet.Configs; +using BenchmarkDotNet.Diagnosers; using BenchmarkDotNet.Engines; using BenchmarkDotNet.Environments; using BenchmarkDotNet.Helpers; @@ -12,44 +16,61 @@ using BenchmarkDotNet.Tests.Loggers; using Xunit; using Xunit.Abstractions; +using BenchmarkDotNet.Reports; +using BenchmarkDotNet.Diagnostics.Windows; namespace BenchmarkDotNet.IntegrationTests { - [Config(typeof(DiagnoserConfig))] - public class ListEnumeratorsBenchmarks + public class NewVsStackalloc { - private List list; + [Benchmark] + public void New() => Consume(new byte[100]); - [Setup] - public void SetUp() + [Benchmark] + public unsafe void Stackalloc() { - list = Enumerable.Range(0, 100).ToList(); + var bytes = stackalloc byte[100]; + Consume(bytes); } + [MethodImpl(MethodImplOptions.NoInlining)] + private void Consume(T input) { } + + [MethodImpl(MethodImplOptions.NoInlining)] + private unsafe void Consume(byte* input) { } + } + + public class AllocatingSetupAndCleanup + { + private List list; + + [Setup] + public void AllocatingSetUp() => AllocateUntilGcWakesUp(); + [Benchmark] - public int ListStructEnumerator() + public void AllocateNothing() { } + + [Cleanup] + public void AllocatingCleanUp() => AllocateUntilGcWakesUp(); + + private void AllocateUntilGcWakesUp() { - int sum = 0; - foreach (var i in list) + int initialCollectionCount = GC.CollectionCount(0); + + while (initialCollectionCount == GC.CollectionCount(0)) { - sum += i; + list = Enumerable.Range(0, 100).ToList(); } - return sum; } + } + [KeepBenchmarkFiles()] + public class NoAllocationsAtAll + { [Benchmark] - public int ListObjectEnumerator() - { - int sum = 0; - foreach (var i in (IEnumerable)list) - { - sum += i; - } - return sum; - } + public void EmptyMethod() { } } -#if !CORE // this class is not compiled for CORE because it is using Diagnosers that currently do not support Core public class MemoryDiagnoserTests { @@ -63,47 +84,94 @@ public MemoryDiagnoserTests(ITestOutputHelper outputHelper) [Fact(Skip = "Temporarily suppressed, see https://github.com/PerfDotNet/BenchmarkDotNet/issues/208")] public void MemoryDiagnoserTracksHeapMemoryAllocation() { - var benchmarks = BenchmarkConverter.TypeToBenchmarks(typeof(ListEnumeratorsBenchmarks)); - var memoryDiagnoser = new Diagnostics.Windows.MemoryDiagnoser(); - - var summary = BenchmarkRunner - .Run(benchmarks, - ManualConfig.CreateEmpty(). - With(Job.Dry.With(Runtime.Core).With(RunStrategy.Throughput).WithWarmupCount(1).WithTargetCount(1)). - With(DefaultConfig.Instance.GetLoggers().ToArray()). - With(DefaultColumnProviders.Instance). - With(memoryDiagnoser). - With(new OutputLogger(output))); - - var gcCollectionColumns = memoryDiagnoser.GetColumnProvider().GetColumns(null).OfType().ToArray(); - var listStructEnumeratorBenchmarks = benchmarks.Where(benchmark => benchmark.DisplayInfo.Contains("ListStructEnumerator")); - var listObjectEnumeratorBenchmarks = benchmarks.Where(benchmark => benchmark.DisplayInfo.Contains("ListObjectEnumerator")); + var memoryDiagnoser = new MemoryDiagnoser(); + var config = CreateConfig(memoryDiagnoser, 50); + var benchmarks = BenchmarkConverter.TypeToBenchmarks(typeof(NewVsStackalloc), config); + + var summary = BenchmarkRunner.Run((Benchmark[])benchmarks, config); + + var gcCollectionColumns = GetColumns(memoryDiagnoser).ToArray(); + var stackallocBenchmarks = benchmarks.Where(benchmark => benchmark.DisplayInfo.Contains("Stackalloc")); + var newArrayBenchmarks = benchmarks.Where(benchmark => benchmark.DisplayInfo.Contains("New")); + const int gen0Index = 0; - foreach (var listStructEnumeratorBenchmark in listStructEnumeratorBenchmarks) + foreach (var benchmark in stackallocBenchmarks) { - var structEnumeratorGen0Collections = gcCollectionColumns[gen0Index].GetValue( - summary, - listStructEnumeratorBenchmark); + var gen0Collections = gcCollectionColumns[gen0Index].GetValue(summary, benchmark); - Assert.Equal("-", structEnumeratorGen0Collections); + Assert.Equal("-", gen0Collections); } - foreach (var listObjectEnumeratorBenchmark in listObjectEnumeratorBenchmarks) + foreach (var benchmark in newArrayBenchmarks) + { + var gen0Str = gcCollectionColumns[gen0Index].GetValue(summary, benchmark); + + AssertParsed(gen0Str, gen0Value => gen0Value > 0); + } + } + + [Fact(Skip = "Temporarily suppressed, see https://github.com/PerfDotNet/BenchmarkDotNet/issues/208")] + public void MemoryDiagnoserDoesNotIncludeAllocationsFromSetupAndCleanup() + { + AssertZeroAllocations(typeof(AllocatingSetupAndCleanup), "AllocateNothing", targetCount: 50); + } + + [Fact(Skip = "Temporarily suppressed, see https://github.com/PerfDotNet/BenchmarkDotNet/issues/208")] + public void EngineShouldNotInterfereAllocationResults() + { + AssertZeroAllocations(typeof(NoAllocationsAtAll), "EmptyMethod", targetCount: 5000); // we need a lot of iterations to be sure!! + } + + public void AssertZeroAllocations(Type benchmarkType, string benchmarkMethodName, int targetCount) + { + var memoryDiagnoser = new MemoryDiagnoser(); + var config = CreateConfig(memoryDiagnoser, targetCount); + var benchmarks = BenchmarkConverter.TypeToBenchmarks(benchmarkType, config); + + var summary = BenchmarkRunner.Run((Benchmark[])benchmarks, config); + + var allocationColumn = GetColumns(memoryDiagnoser).Single(); + var allocateNothingBenchmarks = benchmarks.Where(benchmark => benchmark.DisplayInfo.Contains(benchmarkMethodName)); + + foreach (var benchmark in allocateNothingBenchmarks) + { + var allocations = allocationColumn.GetValue(summary, benchmark); + + AssertParsed(allocations, allocatedBytes => allocatedBytes == 0); + } + } + + private IConfig CreateConfig(IDiagnoser diagnoser, int targetCount) + { + return ManualConfig.CreateEmpty() + .With( + Job.Dry + .WithLaunchCount(1) + .WithWarmupCount(1) + .WithTargetCount(targetCount) + .WithGcForce(false)) + .With(DefaultConfig.Instance.GetLoggers().ToArray()) + .With(DefaultColumnProviders.Instance) + .With(diagnoser) + .With(new OutputLogger(output)); + } + + private static T[] GetColumns(MemoryDiagnoser memoryDiagnoser) + => memoryDiagnoser.GetColumnProvider().GetColumns(null).OfType().ToArray(); + + private static void AssertParsed(string text, Predicate condition) + { + double value; + if (double.TryParse(text, NumberStyles.Number, HostEnvironmentInfo.MainCultureInfo, out value)) + { + Assert.True(condition(value)); + } + else { - var gen0Str = gcCollectionColumns[gen0Index].GetValue( - summary, - listObjectEnumeratorBenchmark); - - double gen0Value; - if (double.TryParse(gen0Str, NumberStyles.Number, HostEnvironmentInfo.MainCultureInfo, out gen0Value)) - Assert.True(gen0Value > 0); - else - { - Assert.True(false, $"Can't parse '{gen0Str}'"); - } + Assert.True(false, $"Can't parse '{text}'"); } } } -#endif -} \ No newline at end of file +} +#endif \ No newline at end of file diff --git a/tests/BenchmarkDotNet.IntegrationTests/TestConfigs.cs b/tests/BenchmarkDotNet.IntegrationTests/TestConfigs.cs index 5f5e52e145..0faa1dfc27 100644 --- a/tests/BenchmarkDotNet.IntegrationTests/TestConfigs.cs +++ b/tests/BenchmarkDotNet.IntegrationTests/TestConfigs.cs @@ -33,7 +33,7 @@ public class DiagnoserConfig : ManualConfig public DiagnoserConfig() { // Diagnosers need enough runs to collects the statistics! - Add(Job.Default.WithLaunchCount(1).WithWarmupCount(5).WithTargetCount(5)); + Add(Job.Default.WithLaunchCount(1).WithWarmupCount(1).WithTargetCount(50)); } } } \ No newline at end of file diff --git a/tests/BenchmarkDotNet.IntegrationTests/project.json b/tests/BenchmarkDotNet.IntegrationTests/project.json index 73193018f2..525d7d205f 100644 --- a/tests/BenchmarkDotNet.IntegrationTests/project.json +++ b/tests/BenchmarkDotNet.IntegrationTests/project.json @@ -17,7 +17,8 @@ }, "testRunner": "xunit", "buildOptions": { - "copyToOutput": [ "xunit.runner.json" ] + "copyToOutput": [ "xunit.runner.json" ], + "allowUnsafe": true }, "frameworks": { "netcoreapp1.0": { diff --git a/tests/BenchmarkDotNet.Tests/Engine/EnginePilotStageTests.cs b/tests/BenchmarkDotNet.Tests/Engine/EnginePilotStageTests.cs index de693699fd..efdd2cf426 100644 --- a/tests/BenchmarkDotNet.Tests/Engine/EnginePilotStageTests.cs +++ b/tests/BenchmarkDotNet.Tests/Engine/EnginePilotStageTests.cs @@ -5,6 +5,8 @@ using BenchmarkDotNet.Tests.Mocks; using Xunit; using Xunit.Abstractions; +using BenchmarkDotNet.Characteristics; +using BenchmarkDotNet.Running; namespace BenchmarkDotNet.Tests.Engine { diff --git a/tests/BenchmarkDotNet.Tests/Engine/EngineTargetStageTests.cs b/tests/BenchmarkDotNet.Tests/Engine/EngineTargetStageTests.cs index 158077faa7..d2ae87fa8f 100644 --- a/tests/BenchmarkDotNet.Tests/Engine/EngineTargetStageTests.cs +++ b/tests/BenchmarkDotNet.Tests/Engine/EngineTargetStageTests.cs @@ -6,6 +6,8 @@ using BenchmarkDotNet.Tests.Mocks; using Xunit; using Xunit.Abstractions; +using BenchmarkDotNet.Characteristics; +using BenchmarkDotNet.Running; namespace BenchmarkDotNet.Tests.Engine { diff --git a/tests/BenchmarkDotNet.Tests/Mocks/MockEngine.cs b/tests/BenchmarkDotNet.Tests/Mocks/MockEngine.cs index 9e181ede00..0abf6661bf 100644 --- a/tests/BenchmarkDotNet.Tests/Mocks/MockEngine.cs +++ b/tests/BenchmarkDotNet.Tests/Mocks/MockEngine.cs @@ -25,8 +25,10 @@ public MockEngine(ITestOutputHelper output, Job job, Func MainAction { get; } = _ => { }; public Action IdleAction { get; } = _ => { }; + public IEngineFactory Factory => null; public Measurement RunIteration(IterationData data) { @@ -36,15 +38,13 @@ public Measurement RunIteration(IterationData data) return measurement; } - public void WriteLine() - { - output.WriteLine(""); - } + public void PreAllocate() { } + public void Jitting() { } - public void WriteLine(string line) - { - output.WriteLine(line); - } + public RunResults Run() => default(RunResults); + + public void WriteLine() => output.WriteLine(""); + public void WriteLine(string line) => output.WriteLine(line); public IResolver Resolver => new CompositeResolver(BenchmarkRunnerCore.DefaultResolver, EngineResolver.Instance); }