Changed diagnosers flow, reduced heap allocations in Engine to 0 #277

adamsitnik · 2016-10-05T17:24:20Z

I wanted to implement a tail call diagnoser with my friends for #273 but we got stucked. We signed up for a jit event but we were never getting it, most probably because the method was already jitted before we even started the ETW session. But I am not sure, it's a guess.

The diagnosers flow was quite complicated and not very flexible. So I have changed it a little.

How it works now (Auto-generated program.cs):

The first thing to do is to notify master process that diagnoser can attach.
The JIT based diagnosers can attach at this moment, and we are sure that no jitting was done.
When Engine is created and prepared, we run Setup once and notify the diagnosers that this can happen. The GC diagnoser can attach at this moment and avoid the problem of including [Setup] allocations GC Diagnoser should not include allocations done by Setup method #186 .
Engine runs, but it does not call Setup and/or Cleanup anymore
We notify diagnosers that we are going to call Cleanup, so for example GC Diagnoser can detach at this moment, and don't include Cleanup allocations.
Call Cleanup

@AndreyAkinshin @mattwarren could you guys take a look at the code? I created a PR to start the discussion.

If you like this solution then I would like to continue the work:

reduce the number of heap allocations in Engine to 0 to give better accuracy for Memory Diagnoser.
And improve allocated bytes calculation per operation to get better accuracy, for example 100 bytes for following benchmark:

[Benchmark]
public void New() => new byte[100];

@AndreyAkinshin what do you think about setup/cleanup changes I made?

… setup and after run

AndreyAkinshin · 2016-10-06T20:49:49Z

@adamsitnik, I like your changes, we are definitely on the right way. Will do a code review on the weekend.

adamsitnik · 2016-10-07T13:08:14Z

I like your changes, we are definitely on the right way. Will do a code review on the weekend.

@AndreyAkinshin cool!

Now I am profiling the Engine to reduce the number of allocations. Currently when I run a benchmark with empty method (does nothing, 0 allocations) with TargetCount = 5000 the results are : 7x GC 0, 2.302,08 Bytes Allocated/Op. Let's see how far I can get ;)

…ser accuracy

adamsitnik · 2016-10-07T17:02:46Z

Ok, little update. I was able to get 0 GCs for empty method, the overhead went from 2000 bytes to 20 bytes per target invocation. My current problem is that Visual Studio Profiler can not tell me where the 20 bytes are ;) So I will have to try another tool.

@AndreyAkinshin Most of the changes so far were not ugly. The only ugly thing was to pre-allocate List<Measurement> that contains the results.

The breaking change is to not display results during run, but display them all at the end of benchmark run. But I hope it's not a problem.

AndreyAkinshin · 2016-10-07T17:16:36Z

The breaking change is to not display results during run, but display them all at the end of benchmark run. But I hope it's not a problem.

Could we keep the old behavior? It's really nice to look at results one by one during benchmarking. Moreover, it allows to understand what's going on right now and check how long single iteration takes (so, it's possible to detect mistakes in the benchmark design on early stages).

P.S. Probably, we have some allocations because of the Statistics instances. In this case, we could implement incremental logic.

adamsitnik · 2016-10-07T19:37:06Z

I have one idea: there is always a separate run when any diagnoser is attached, so I could print results immediately by default and in the diagnosers run delay the prining.

AndreyAkinshin · 2016-10-07T19:56:51Z

LGTM.

adamsitnik · 2016-10-07T22:02:21Z

Ok, I updated the code.

My To do list:

find the missing 18-22 bytes for most simple scenario: no warmup, no pilot, fixed target count
analyse and improve for scenarion with warmup and pilot

…t saves memory ;/

adamsitnik · 2016-10-09T15:00:24Z

@AndreyAkinshin Ok, I updated the code once again. I am very close to getting it done ;)

I also tried to set InvocationCount to some value, but then realized it was not passed to engine. Is this commit correct fix?

The results are getting more stable and accurate, but 100KB limitation of ETW allocation event is still a problem.

Default Config + MemoryDiagnoser:

Keep in mind that 10 bytes array = 10 bytes for bytes, 8 + 8 bytes for extra object fields and + 8 byte for the reference to array.

mattwarren · 2016-10-10T12:29:02Z

The results are getting more stable and accurate, but 100KB limitation of ETW allocation event is still a problem.

Yeah that's always going to be a fundamental problem with ETW events, maybe it's time to look at using AppDomain.MonitoringTotalAllocatedMemorySize instead?

adamsitnik · 2016-10-10T13:43:28Z

Yeah that's always going to be a fundamental problem with ETW events, maybe it's time to look at using AppDomain.MonitoringTotalAllocatedMemorySize instead?

I like this idea, I will do some PoC.

adamsitnik · 2016-10-11T12:36:50Z

Ok, I am done. All possible heap allocations were eliminated from Engine.Run()

Memory profiling results of auto-genearated benchmark runner process for benchmark:

[Benchmark(Description = "new byte[10]")]
public byte[] TenBytes() => new byte[10];

Next steps:

@AndreyAkinshin could you do the code review?
When the code passes code review Itry to make the Memory Diagnostics a build in part of BDN. For classic toolchain I want to use AppDomain.MonitoringTotalAllocatedMemorySize as @mattwarren suggested, for Core I want to use GC.GetAllocatedBytesForCurrentThread which got exposed 2 days ago

AndreyAkinshin · 2016-10-11T12:50:58Z

@adamsitnik, great! Could you also fix failed test? I will do the full review in a few days.

AndreyAkinshin

Awesome pull request. It needs some minor changes and it could be merged into master.

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.InliningDiagnoserConfig]


src/BenchmarkDotNet.Core/Engines/RunResults.cs

+        {
+            // 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;


src/BenchmarkDotNet.Core/Mathematics/MeasurementsStatistics.cs

+
+            double variance = 0;
+            for (int i = 0; i < measurements.Count; i++)
+                variance += Math.Pow(measurements[i].Nanoseconds - mean, 2) / (N - 1);


src/BenchmarkDotNet.Core/Templates/BenchmarkProgram.txt

@@ -17,50 +19,87 @@ $AdditionalLogic$

 namespace BenchmarkDotNet.Autogenerated
 {
-    public class Program : global::$TargetTypeName$
+    public class Program


src/BenchmarkDotNet.Diagnostics.Windows/Configs/InliningDiagnoserConfigAttribute.cs

+
+namespace BenchmarkDotNet.Diagnostics.Windows.Configs
+{
+    public class InliningDiagnoserConfigAttribute : Attribute, IConfigSource


src/BenchmarkDotNet.Diagnostics.Windows/Configs/MemoryDiagnoserConfigAttribute.cs

+
+namespace BenchmarkDotNet.Diagnostics.Windows.Configs
+{
+    public class MemoryDiagnoserConfigAttribute : Attribute, IConfigSource


src/BenchmarkDotNet.Diagnostics.Windows/EtwDiagnoser.cs

+            // 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));


src/BenchmarkDotNet.Diagnostics.Windows/InliningDiagnoser.cs

-            logger.WriteLineInfo($"{benchmark.DisplayInfo}");
-            logger.WriteLineHeader(new string('-', 20));
+            Logger.WriteLine();
+            Logger.WriteLineHeader(new string('-', 20));


tests/BenchmarkDotNet.IntegrationTests/MemoryDiagnoserTests.cs

+        private void Blackhole<T>(T input) { }
+
+        [MethodImpl(MethodImplOptions.NoInlining)]
+        private unsafe void Blackhole(byte* input) { }


tests/BenchmarkDotNet.IntegrationTests/MemoryDiagnoserTests.cs

+        private IConfig CreateConfig(IDiagnoser diagnoser, int targetCount)
+        {
+            return ManualConfig.CreateEmpty()
+                               .With(Job.Dry.WithLaunchCount(1).WithWarmupCount(1).WithTargetCount(targetCount).With(GcMode.Default.WithForce(false)))


adamsitnik · 2016-10-11T19:58:35Z

@AndreyAkinshin Thanks! I updated the code.

src/BenchmarkDotNet.Core/Mathematics/MeasurementsStatistics.cs

+
+            var InterquartileRange = Q3 - Q1;
+            var LowerFence = Q1 - 1.5 * InterquartileRange;
+            var UpperFence = Q3 + 1.5 * InterquartileRange;


mattwarren · 2016-10-12T11:24:40Z

@adamsitnik Great job, you've given the Diagnosers a long overdue and sorely needed fix/tidy-up thanks for doing that and the new IDiagnoser API looks really nice.

Plus the work on reducing the BenchmarkDotNet memory allocations is really cool, I like this approach of forcing allocations to happen up-front

Just one small thing I noticed, we now have quite a few warnings messages when you build the code (which don't seem to be there on master), can some/all of these be removed or suppressed?

mattwarren · 2016-10-12T11:28:02Z

Slight tongue-in-cheek but also slightly serious, should we ban using System.Linq from certain parts of BenchmarkDotNet? Like the Roslyn code-guidelines do

Avoid allocations in compiler hot paths:

Avoid LINQ.

Avoid using foreach over collections that do not have a struct enumerator.

Consider using an object pool. There are many usages of object pools in the compiler to see an example.

That always makes me laugh as the people who designed/wrote LINQ are banned from using it (admittedly only in certain parts of their code)

adamsitnik · 2016-10-12T11:52:41Z

@mattwarren Thanks! It was a lot of fun to me to track even the smallest allocations. Btw. first call to list.Sort was allocating 1740 bytes!! That's insane

As for the LINQ I was wondering if we could somehow ban it on unit-test level.

Pseudocode: Assert.False(typeof(Engine).References.Any(reference => reference.Name == "System.Linq"))

Anyway I will most probably check for heap allocations in engine before each BDN release.

mattwarren · 2016-10-12T12:06:15Z

Anyway I will most probably check for heap allocations in engine before each BDN release.

Maybe we should dog-food our own product and use BenchmarkDotNet to automate this for us? I.e. a unit test that runs on each build and fails if we allocate too much or certain code paths?

adamsitnik · 2016-10-12T12:07:07Z

Maybe we should dog-food our own product and use BenchmarkDotNet to automate this for us? I.e. a unit test that runs on each build and fails if we allocate too much or certain code paths?

Good idea! I could cover that with integration tests

adamsitnik · 2016-10-14T22:18:19Z

@AndreyAkinshin I have pushed the last commit with rename + I added and verified possibility to use custom Engine.

Next week I should be able to implement universal Memory Diagnoser, so if you could wait with 0.10.0 until then it would be great!

AndreyAkinshin · 2016-10-15T06:18:33Z

@adamsitnik,

Could we merge this PR into master right now? Or should we wait for the universal Memory Diagnoser?
I'm going to release v0.10.0 at the end of October.

adamsitnik · 2016-10-15T12:58:47Z

@AndreyAkinshin I will do separate PR with universal Memory Diagnoser within next week.

adamsitnik added 2 commits October 5, 2016 18:55

changed diagnosers flow, possibility to hook up before jitting, after…

8d65fe2

… setup and after run

added predefined attributes for diagnosers

f346ffa

reduce memory allocated by Engine during run to increase MemoryDiagno…

376bd86

…ser accuracy

display results when runing when no diagnoser is attached

b5ab556

adamsitnik added 3 commits October 8, 2016 20:53

preload all settings in ctors, introduced IEngineFactory

4070a1c

make Engine use InvocationCount

2f0df72

calculate Statistics without allocations! makes the code look bad, bu…

8a7a12d

…t saves memory ;/

remove last allocations from Engine.Run

d8fa70a

perform Jitting after first Setup call, better naming, test fix

f2a1063

AndreyAkinshin requested changes Oct 11, 2016

View reviewed changes

post code review changes

3c5e70a

AndreyAkinshin reviewed Oct 12, 2016

View reviewed changes

AndreyAkinshin added enhancement Area:Diagnosers labels Oct 12, 2016

AndreyAkinshin assigned adamsitnik Oct 12, 2016

AndreyAkinshin added this to the v0.10.0 milestone Oct 12, 2016

possibility to define custom Engine

16e258e

AndreyAkinshin approved these changes Oct 15, 2016

View reviewed changes

adamsitnik changed the title ~~Changed diagnosers flow~~ Changed diagnosers flow, reduced heap allocations in Engine to 0 Oct 15, 2016

adamsitnik merged commit afa5865 into master Oct 15, 2016

adamsitnik deleted the diagnosersFlow branch October 15, 2016 12:57

adamsitnik mentioned this pull request Oct 16, 2016

built-in accurate and cross platform Memory Diagnoser #284

Merged

Changed diagnosers flow, reduced heap allocations in Engine to 0 #277

Changed diagnosers flow, reduced heap allocations in Engine to 0 #277

Conversation

adamsitnik commented Oct 5, 2016

AndreyAkinshin commented Oct 6, 2016

adamsitnik commented Oct 7, 2016

adamsitnik commented Oct 7, 2016

AndreyAkinshin commented Oct 7, 2016

adamsitnik commented Oct 7, 2016

AndreyAkinshin commented Oct 7, 2016

adamsitnik commented Oct 7, 2016 • edited Loading

adamsitnik commented Oct 9, 2016 • edited Loading

mattwarren commented Oct 10, 2016

adamsitnik commented Oct 10, 2016

adamsitnik commented Oct 11, 2016

AndreyAkinshin commented Oct 11, 2016

AndreyAkinshin left a comment

Choose a reason for hiding this comment

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

adamsitnik commented Oct 11, 2016

This comment was marked as spam.

This comment was marked as spam.

This comment was marked as spam.

mattwarren commented Oct 12, 2016

mattwarren commented Oct 12, 2016

adamsitnik commented Oct 12, 2016

mattwarren commented Oct 12, 2016

adamsitnik commented Oct 12, 2016

adamsitnik commented Oct 14, 2016

AndreyAkinshin commented Oct 15, 2016

adamsitnik commented Oct 15, 2016

adamsitnik commented Oct 7, 2016 •

edited

Loading

adamsitnik commented Oct 9, 2016 •

edited

Loading