Eliminate tuple allocations in seekReadCustomAttributeRow via a custom reader for attribute rows #9218

cartermp · 2020-05-17T23:13:38Z

This PR is more for folks like @dsyme and @TIHan to look at and see what they think.

From this issue: https://developercommunity.visualstudio.com/content/problem/1035124/trace-of-editing-experience-with-in-memory-cross-p-1.html

The submitted trace showed 120MB of allocations coming from this function, most of which are 3-tuples (~5.7% of all allocations in the sample):

It's also 0.7% of total CPU time:

Since the data being generated is all small value types, maybe a struct tuple would be better here.

Looking through what all calls this and the frequency, it looks like it's just a part of normal compiler routines so if we think this would speed things up a bit then that'd be nice.

TIHan

Simply changing this to a struct may be ok, but to make a better impact, you could do what I did here:
#4716

TIHan · 2020-05-18T01:25:08Z

I think we should fix this despite not pushing the SRM PR.

I don't think we can switch to a SRM implementation because of the risk involved. We need to have a huge suite of tests that directly test our IL metadata reader.

cartermp · 2020-05-18T01:35:51Z

Yeah, #4716 would be good. I just scoped this (and some other PRs) to address only one specific thing to keep them as small as possible rather than go through and convert a lot of the obvious ones to use structs (like this little chungus: https://github.com/dotnet/fsharp/blob/master/src/absil/ilread.fs#L256)

cartermp · 2020-05-18T17:20:35Z

I took a trace from using VS after editing the compiler codebase for an hour and this is basically near the top in terms of allocations

While #4716 would also improve things this is a bit more targeted. @TIHan is there a good set of benchmarks we could potentially use here? I'd like to see if switching to a string tuple does help since it's shown up in two separate traces as a top thing

TIHan · 2020-05-26T23:26:13Z

@cartermp You could try using this benchmark. https://github.com/dotnet/fsharp/blob/master/benchmarks/CompilerServiceBenchmarks/Program.fs#L194

Maybe tweak it to read all the attributes in an assembly?

cartermp · 2020-05-29T17:56:39Z

This one was a little iffy for me (parentIdx and typeIdx are a struct of two ints), hence the original message. As expected, allocations are reduced noticeably, but CPU time did go up slightly in ILReading.

BenchmarkDotNet=v0.11.3, OS=Windows 10.0.19041
Intel Core i7-6700K CPU 4.00GHz (Skylake), 1 CPU, 8 logical and 4 physical cores
  [Host]     : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit LegacyJIT-v4.8.4180.0 DEBUG
  Job-FEFVFA : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0

InvocationCount=1  UnrollFactor=1

Before:

Method	Mean	Error	StdDev	Median	Gen 0/1k Op	Gen 1/1k Op	Gen 2/1k Op	Allocated Memory/Op
ParsingTypeCheckerFs	191.39 ms	1.893 ms	1.678 ms	190.873 ms	7000.0000	2000.0000	-	42.77 MB
ILReading	1,529.46 ms	30.370 ms	49.041 ms	1,527.549 ms	191000.0000	63000.0000	6000.0000	1112.69 MB
TypeCheckFileWith100ReferencedProjects	13.11 ms	1.543 ms	4.550 ms	9.731 ms	1000.0000	1000.0000	-	7.38 MB

After:

Method	Mean	Error	StdDev	Gen 0/1k Op	Gen 1/1k Op	Gen 2/1k Op	Allocated Memory/Op
ParsingTypeCheckerFs	206.865 ms	3.6175 ms	3.3838 ms	7000.0000	2000.0000	-	42.77 MB
ILReading	1,585.444 ms	11.3409 ms	10.0534 ms	174000.0000	57000.0000	5000.0000	1037.59 MB
TypeCheckFileWith100ReferencedProjects	9.480 ms	0.1684 ms	0.1493 ms	1000.0000	1000.0000	-	7.4 MB

So if we consider allocations and mean CPU time with the worst-case of being at the upper end of the error, this appears to be a tradeoff of 75MB less allocations per op vs. ~0.2ms per op

cartermp · 2020-06-27T17:34:51Z

@TIHan what are your thoughts here? I think 75MB less allocations per operation outweighs the slight increase in CPU time. It's also worth noting that the measured CPU time now also has less variance than before.

cartermp · 2020-08-05T01:39:09Z

Okay, I tried this with @TIHan's proposed approach in #4716 and these were the results of the compiler service benchmarks:

BenchmarkDotNet=v0.11.3, OS=Windows 10.0.19041
Intel Core i7-6700K CPU 4.00GHz (Skylake), 1 CPU, 8 logical and 4 physical cores
  [Host]     : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit LegacyJIT-v4.8.4180.0 DEBUG
  Job-FEFVFA : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0

InvocationCount=1  UnrollFactor=1

Method	Mean	Error	StdDev	Median	Gen 0/1k Op	Gen 1/1k Op	Gen 2/1k Op	Allocated Memory/Op
ParsingTypeCheckerFs	193.71 ms	1.846 ms	1.726 ms	193.127 ms	6000.0000	2000.0000	-	40.41 MB
ILReading	1,485.79 ms	26.141 ms	24.452 ms	1,486.826 ms	149000.0000	51000.0000	6000.0000	899.01 MB
TypeCheckFileWith100ReferencedProjects	11.73 ms	1.503 ms	4.431 ms	8.845 ms	1000.0000	1000.0000	-	7.34 MB

CPU time is improved over the current and new implementation by ~2%.

Memory usage per op is 19% better than the current implementation, and 13% better than the change I made.

So that's what I'll go with.

cartermp · 2020-08-05T03:33:20Z

Might be worth trying to unify on this? https://github.com/dotnet/fsharp/blob/master/src/absil/ilread.fs#L746

cartermp · 2020-08-05T04:52:28Z

I wont bother trying to consolidate with https://github.com/dotnet/fsharp/blob/master/src/absil/ilread.fs#L746

It's a bit of additional churn and I haven't seen evidence from trace data that the tuples the functions that call this thing have an impact.

cartermp · 2020-08-05T04:53:02Z

@TIHan @dsyme @KevinRansom this one is ready for review - should be pretty easy considering the improvement IMO

abelbraaksma · 2020-08-05T10:24:04Z

InvocationCount=1 UnrollFactor=1

The numbers look intriguing, but with a single invocation, I'm not sure they proof anything (and may be better, or worse, than what you're seeing). Maybe you ran into a bug of BDN that I reported there (and isn't fixed yet), which chooses 1 invocation when there's a lot secundairy jitting going on.

Can you share the BDN code, or force it with higher invocation count?

cartermp · 2020-08-05T14:21:35Z

@abelbraaksma I'm not sure if those values are referring to the actual number of times something is executed. As you can see in the log, each benchmark was executed many times to for the report:

// Validating benchmarks:
// ***** BenchmarkRunner: Start   *****
// ***** Building 1 exe(s) in Parallel: Start   *****
BuildScript: C:\Users\phcart\source\repos\fsharp\artifacts\bin\CompilerServiceBenchmarks\Release\net472\4a1bca45-3cc6-432b-bd1c-cc50ff5d3ffb.bat
// ***** Done, took 00:00:02 (2.56 sec)   *****
// Found benchmarks:
//   CompilerService.ParsingTypeCheckerFs: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
//   CompilerService.ILReading: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
//   CompilerService.TypeCheckFileWith100ReferencedProjects: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)

// **************************
// Benchmark: CompilerService.ParsingTypeCheckerFs: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
// *** Execute ***
// Launch: 1 / 1
// Execute: C:\Users\phcart\source\repos\fsharp\artifacts\bin\CompilerServiceBenchmarks\Release\net472\4a1bca45-3cc6-432b-bd1c-cc50ff5d3ffb.exe --benchmarkName "Program+CompilerService.ParsingTypeCheckerFs" --job "InvocationCount=1, UnrollFactor=1" --benchmarkId 0
// BeforeAnythingElse

// Benchmark Process Environment Information:
// Runtime=.NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0
// GC=Concurrent Workstation
// Job: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)

OverheadJitting  1: 1 op, 211900.00 ns, 211.9000 us/op
WorkloadJitting  1: 1 op, 721977600.00 ns, 721.9776 ms/op

OverheadWarmup   1: 1 op, 1400.00 ns, 1.4000 us/op
OverheadWarmup   2: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   3: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   4: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   5: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   6: 1 op, 100.00 ns, 100.0000 ns/op

OverheadActual   1: 1 op, 600.00 ns, 600.0000 ns/op
OverheadActual   2: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   3: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual   4: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   5: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual   6: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   7: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   8: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual   9: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  10: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  11: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  12: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  13: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  14: 1 op, 300.00 ns, 300.0000 ns/op
OverheadActual  15: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  16: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  17: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  18: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  19: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  20: 1 op, 200.00 ns, 200.0000 ns/op

WorkloadWarmup   1: 1 op, 194578500.00 ns, 194.5785 ms/op
WorkloadWarmup   2: 1 op, 192831300.00 ns, 192.8313 ms/op
WorkloadWarmup   3: 1 op, 192461400.00 ns, 192.4614 ms/op
WorkloadWarmup   4: 1 op, 197476300.00 ns, 197.4763 ms/op
WorkloadWarmup   5: 1 op, 196189700.00 ns, 196.1897 ms/op
WorkloadWarmup   6: 1 op, 193281600.00 ns, 193.2816 ms/op
WorkloadWarmup   7: 1 op, 193447800.00 ns, 193.4478 ms/op
WorkloadWarmup   8: 1 op, 192468200.00 ns, 192.4682 ms/op

// BeforeActualRun
WorkloadActual   1: 1 op, 193526100.00 ns, 193.5261 ms/op
WorkloadActual   2: 1 op, 195609100.00 ns, 195.6091 ms/op
WorkloadActual   3: 1 op, 193025200.00 ns, 193.0252 ms/op
WorkloadActual   4: 1 op, 192969700.00 ns, 192.9697 ms/op
WorkloadActual   5: 1 op, 197949400.00 ns, 197.9494 ms/op
WorkloadActual   6: 1 op, 191726300.00 ns, 191.7263 ms/op
WorkloadActual   7: 1 op, 196102900.00 ns, 196.1029 ms/op
WorkloadActual   8: 1 op, 193127600.00 ns, 193.1276 ms/op
WorkloadActual   9: 1 op, 192522500.00 ns, 192.5225 ms/op
WorkloadActual  10: 1 op, 192377800.00 ns, 192.3778 ms/op
WorkloadActual  11: 1 op, 191905200.00 ns, 191.9052 ms/op
WorkloadActual  12: 1 op, 195029400.00 ns, 195.0294 ms/op
WorkloadActual  13: 1 op, 192819300.00 ns, 192.8193 ms/op
WorkloadActual  14: 1 op, 193565700.00 ns, 193.5657 ms/op
WorkloadActual  15: 1 op, 193401200.00 ns, 193.4012 ms/op

// AfterActualRun
WorkloadResult   1: 1 op, 193525920.00 ns, 193.5259 ms/op
WorkloadResult   2: 1 op, 195608920.00 ns, 195.6089 ms/op
WorkloadResult   3: 1 op, 193025020.00 ns, 193.0250 ms/op
WorkloadResult   4: 1 op, 192969520.00 ns, 192.9695 ms/op
WorkloadResult   5: 1 op, 197949220.00 ns, 197.9492 ms/op
WorkloadResult   6: 1 op, 191726120.00 ns, 191.7261 ms/op
WorkloadResult   7: 1 op, 196102720.00 ns, 196.1027 ms/op
WorkloadResult   8: 1 op, 193127420.00 ns, 193.1274 ms/op
WorkloadResult   9: 1 op, 192522320.00 ns, 192.5223 ms/op
WorkloadResult  10: 1 op, 192377620.00 ns, 192.3776 ms/op
WorkloadResult  11: 1 op, 191905020.00 ns, 191.9050 ms/op
WorkloadResult  12: 1 op, 195029220.00 ns, 195.0292 ms/op
WorkloadResult  13: 1 op, 192819120.00 ns, 192.8191 ms/op
WorkloadResult  14: 1 op, 193565520.00 ns, 193.5655 ms/op
WorkloadResult  15: 1 op, 193401020.00 ns, 193.4010 ms/op
GC:  6 2 0 42374296 1

// AfterAll

Mean = 193.7103 ms, StdErr = 0.4457 ms (0.23%); N = 15, StdDev = 1.7263 ms
Min = 191.7261 ms, Q1 = 192.5223 ms, Median = 193.1274 ms, Q3 = 195.0292 ms, Max = 197.9492 ms
IQR = 2.5069 ms, LowerFence = 188.7620 ms, UpperFence = 198.7896 ms
ConfidenceInterval = [191.8648 ms; 195.5559 ms] (CI 99.9%), Margin = 1.8455 ms (0.95% of Mean)
Skewness = 1.03, Kurtosis = 3.03, MValue = 2

// **************************
// Benchmark: CompilerService.ILReading: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
// *** Execute ***
// Launch: 1 / 1
// Execute: C:\Users\phcart\source\repos\fsharp\artifacts\bin\CompilerServiceBenchmarks\Release\net472\4a1bca45-3cc6-432b-bd1c-cc50ff5d3ffb.exe --benchmarkName "Program+CompilerService.ILReading" --job "InvocationCount=1, UnrollFactor=1" --benchmarkId 1
// BeforeAnythingElse

// Benchmark Process Environment Information:
// Runtime=.NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0
// GC=Concurrent Workstation
// Job: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)

OverheadJitting  1: 1 op, 211300.00 ns, 211.3000 us/op
WorkloadJitting  1: 1 op, 1734652500.00 ns, 1.7347 s/op

OverheadWarmup   1: 1 op, 1100.00 ns, 1.1000 us/op
OverheadWarmup   2: 1 op, 200.00 ns, 200.0000 ns/op
OverheadWarmup   3: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   4: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   5: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   6: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   7: 1 op, 100.00 ns, 100.0000 ns/op

OverheadActual   1: 1 op, 300.00 ns, 300.0000 ns/op
OverheadActual   2: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual   3: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual   4: 1 op, 300.00 ns, 300.0000 ns/op
OverheadActual   5: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   6: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   7: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   8: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   9: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  10: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  11: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  12: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  13: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  14: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  15: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  16: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  17: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  18: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  19: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  20: 1 op, 100.00 ns, 100.0000 ns/op

WorkloadWarmup   1: 1 op, 1470202100.00 ns, 1.4702 s/op
WorkloadWarmup   2: 1 op, 1522668500.00 ns, 1.5227 s/op
WorkloadWarmup   3: 1 op, 1453996400.00 ns, 1.4540 s/op
WorkloadWarmup   4: 1 op, 1479402600.00 ns, 1.4794 s/op
WorkloadWarmup   5: 1 op, 1471907200.00 ns, 1.4719 s/op
WorkloadWarmup   6: 1 op, 1528030700.00 ns, 1.5280 s/op

// BeforeActualRun
WorkloadActual   1: 1 op, 1483243000.00 ns, 1.4832 s/op
WorkloadActual   2: 1 op, 1467437700.00 ns, 1.4674 s/op
WorkloadActual   3: 1 op, 1458429500.00 ns, 1.4584 s/op
WorkloadActual   4: 1 op, 1460660000.00 ns, 1.4607 s/op
WorkloadActual   5: 1 op, 1495388400.00 ns, 1.4954 s/op
WorkloadActual   6: 1 op, 1448301100.00 ns, 1.4483 s/op
WorkloadActual   7: 1 op, 1514927000.00 ns, 1.5149 s/op
WorkloadActual   8: 1 op, 1453419700.00 ns, 1.4534 s/op
WorkloadActual   9: 1 op, 1509483800.00 ns, 1.5095 s/op
WorkloadActual  10: 1 op, 1515277600.00 ns, 1.5153 s/op
WorkloadActual  11: 1 op, 1486826300.00 ns, 1.4868 s/op
WorkloadActual  12: 1 op, 1487791000.00 ns, 1.4878 s/op
WorkloadActual  13: 1 op, 1527629700.00 ns, 1.5276 s/op
WorkloadActual  14: 1 op, 1493785100.00 ns, 1.4938 s/op
WorkloadActual  15: 1 op, 1484200900.00 ns, 1.4842 s/op

// AfterActualRun
WorkloadResult   1: 1 op, 1483242855.00 ns, 1.4832 s/op
WorkloadResult   2: 1 op, 1467437555.00 ns, 1.4674 s/op
WorkloadResult   3: 1 op, 1458429355.00 ns, 1.4584 s/op
WorkloadResult   4: 1 op, 1460659855.00 ns, 1.4607 s/op
WorkloadResult   5: 1 op, 1495388255.00 ns, 1.4954 s/op
WorkloadResult   6: 1 op, 1448300955.00 ns, 1.4483 s/op
WorkloadResult   7: 1 op, 1514926855.00 ns, 1.5149 s/op
WorkloadResult   8: 1 op, 1453419555.00 ns, 1.4534 s/op
WorkloadResult   9: 1 op, 1509483655.00 ns, 1.5095 s/op
WorkloadResult  10: 1 op, 1515277455.00 ns, 1.5153 s/op
WorkloadResult  11: 1 op, 1486826155.00 ns, 1.4868 s/op
WorkloadResult  12: 1 op, 1487790855.00 ns, 1.4878 s/op
WorkloadResult  13: 1 op, 1527629555.00 ns, 1.5276 s/op
WorkloadResult  14: 1 op, 1493784955.00 ns, 1.4938 s/op
WorkloadResult  15: 1 op, 1484200755.00 ns, 1.4842 s/op
GC:  149 51 6 942676608 1

// AfterAll

Mean = 1.4858 s, StdErr = 0.0063 s (0.42%); N = 15, StdDev = 0.0245 s
Min = 1.4483 s, Q1 = 1.4607 s, Median = 1.4868 s, Q3 = 1.5095 s, Max = 1.5276 s
IQR = 0.0488 s, LowerFence = 1.3874 s, UpperFence = 1.5827 s
ConfidenceInterval = [1.4596 s; 1.5119 s] (CI 99.9%), Margin = 0.0261 s (1.76% of Mean)
Skewness = 0.04, Kurtosis = 1.68, MValue = 2

// **************************
// Benchmark: CompilerService.TypeCheckFileWith100ReferencedProjects: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
// *** Execute ***
// Launch: 1 / 1
// Execute: C:\Users\phcart\source\repos\fsharp\artifacts\bin\CompilerServiceBenchmarks\Release\net472\4a1bca45-3cc6-432b-bd1c-cc50ff5d3ffb.exe --benchmarkName "Program+CompilerService.TypeCheckFileWith100ReferencedProjects" --job "InvocationCount=1, UnrollFactor=1" --benchmarkId 2
// BeforeAnythingElse

// Benchmark Process Environment Information:
// Runtime=.NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0
// GC=Concurrent Workstation
// Job: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)

OverheadJitting  1: 1 op, 220900.00 ns, 220.9000 us/op
WorkloadJitting  1: 1 op, 11647900.00 ns, 11.6479 ms/op

OverheadWarmup   1: 1 op, 1100.00 ns, 1.1000 us/op
OverheadWarmup   2: 1 op, 100.00 ns, 100.0000 ns/op
OverheadWarmup   3: 1 op, 200.00 ns, 200.0000 ns/op
OverheadWarmup   4: 1 op, 200.00 ns, 200.0000 ns/op
OverheadWarmup   5: 1 op, 200.00 ns, 200.0000 ns/op
OverheadWarmup   6: 1 op, 100.00 ns, 100.0000 ns/op

OverheadActual   1: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   2: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual   3: 1 op, 300.00 ns, 300.0000 ns/op
OverheadActual   4: 1 op, 300.00 ns, 300.0000 ns/op
OverheadActual   5: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   6: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   7: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual   8: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual   9: 1 op, 300.00 ns, 300.0000 ns/op
OverheadActual  10: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  11: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  12: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  13: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  14: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  15: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  16: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  17: 1 op, 100.00 ns, 100.0000 ns/op
OverheadActual  18: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  19: 1 op, 200.00 ns, 200.0000 ns/op
OverheadActual  20: 1 op, 200.00 ns, 200.0000 ns/op

WorkloadWarmup   1: 1 op, 8496400.00 ns, 8.4964 ms/op
WorkloadWarmup   2: 1 op, 9621800.00 ns, 9.6218 ms/op
WorkloadWarmup   3: 1 op, 13183100.00 ns, 13.1831 ms/op
WorkloadWarmup   4: 1 op, 8895300.00 ns, 8.8953 ms/op
WorkloadWarmup   5: 1 op, 8761700.00 ns, 8.7617 ms/op
WorkloadWarmup   6: 1 op, 8186900.00 ns, 8.1869 ms/op
WorkloadWarmup   7: 1 op, 8214200.00 ns, 8.2142 ms/op
WorkloadWarmup   8: 1 op, 8900900.00 ns, 8.9009 ms/op
WorkloadWarmup   9: 1 op, 8800700.00 ns, 8.8007 ms/op

// BeforeActualRun
WorkloadActual   1: 1 op, 8248800.00 ns, 8.2488 ms/op
WorkloadActual   2: 1 op, 8740300.00 ns, 8.7403 ms/op
WorkloadActual   3: 1 op, 8158800.00 ns, 8.1588 ms/op
WorkloadActual   4: 1 op, 8699500.00 ns, 8.6995 ms/op
WorkloadActual   5: 1 op, 8505000.00 ns, 8.5050 ms/op
WorkloadActual   6: 1 op, 9869200.00 ns, 9.8692 ms/op
WorkloadActual   7: 1 op, 18837400.00 ns, 18.8374 ms/op
WorkloadActual   8: 1 op, 8692600.00 ns, 8.6926 ms/op
WorkloadActual   9: 1 op, 8756200.00 ns, 8.7562 ms/op
WorkloadActual  10: 1 op, 8754300.00 ns, 8.7543 ms/op
WorkloadActual  11: 1 op, 8056400.00 ns, 8.0564 ms/op
WorkloadActual  12: 1 op, 8600600.00 ns, 8.6006 ms/op
WorkloadActual  13: 1 op, 18662500.00 ns, 18.6625 ms/op
WorkloadActual  14: 1 op, 9349000.00 ns, 9.3490 ms/op
WorkloadActual  15: 1 op, 9636600.00 ns, 9.6366 ms/op
WorkloadActual  16: 1 op, 8288100.00 ns, 8.2881 ms/op
WorkloadActual  17: 1 op, 8692300.00 ns, 8.6923 ms/op
WorkloadActual  18: 1 op, 8682600.00 ns, 8.6826 ms/op
WorkloadActual  19: 1 op, 8678500.00 ns, 8.6785 ms/op
WorkloadActual  20: 1 op, 17586400.00 ns, 17.5864 ms/op
WorkloadActual  21: 1 op, 18557700.00 ns, 18.5577 ms/op
WorkloadActual  22: 1 op, 13383400.00 ns, 13.3834 ms/op
WorkloadActual  23: 1 op, 8659900.00 ns, 8.6599 ms/op
WorkloadActual  24: 1 op, 8320300.00 ns, 8.3203 ms/op
WorkloadActual  25: 1 op, 8353800.00 ns, 8.3538 ms/op
WorkloadActual  26: 1 op, 8702100.00 ns, 8.7021 ms/op
WorkloadActual  27: 1 op, 19707200.00 ns, 19.7072 ms/op
WorkloadActual  28: 1 op, 18685300.00 ns, 18.6853 ms/op
WorkloadActual  29: 1 op, 8942100.00 ns, 8.9421 ms/op
WorkloadActual  30: 1 op, 18071000.00 ns, 18.0710 ms/op
WorkloadActual  31: 1 op, 8160600.00 ns, 8.1606 ms/op
WorkloadActual  32: 1 op, 8742800.00 ns, 8.7428 ms/op
WorkloadActual  33: 1 op, 18356900.00 ns, 18.3569 ms/op
WorkloadActual  34: 1 op, 8879000.00 ns, 8.8790 ms/op
WorkloadActual  35: 1 op, 18449700.00 ns, 18.4497 ms/op
WorkloadActual  36: 1 op, 8132700.00 ns, 8.1327 ms/op
WorkloadActual  37: 1 op, 8700600.00 ns, 8.7006 ms/op
WorkloadActual  38: 1 op, 8353800.00 ns, 8.3538 ms/op
WorkloadActual  39: 1 op, 8798400.00 ns, 8.7984 ms/op
WorkloadActual  40: 1 op, 8078100.00 ns, 8.0781 ms/op
WorkloadActual  41: 1 op, 18541400.00 ns, 18.5414 ms/op
WorkloadActual  42: 1 op, 18272100.00 ns, 18.2721 ms/op
WorkloadActual  43: 1 op, 8641400.00 ns, 8.6414 ms/op
WorkloadActual  44: 1 op, 8618000.00 ns, 8.6180 ms/op
WorkloadActual  45: 1 op, 8820900.00 ns, 8.8209 ms/op
WorkloadActual  46: 1 op, 8165500.00 ns, 8.1655 ms/op
WorkloadActual  47: 1 op, 8717800.00 ns, 8.7178 ms/op
WorkloadActual  48: 1 op, 8727700.00 ns, 8.7277 ms/op
WorkloadActual  49: 1 op, 17433600.00 ns, 17.4336 ms/op
WorkloadActual  50: 1 op, 18447900.00 ns, 18.4479 ms/op
WorkloadActual  51: 1 op, 8249600.00 ns, 8.2496 ms/op
WorkloadActual  52: 1 op, 8841700.00 ns, 8.8417 ms/op
WorkloadActual  53: 1 op, 8752700.00 ns, 8.7527 ms/op
WorkloadActual  54: 1 op, 8722000.00 ns, 8.7220 ms/op
WorkloadActual  55: 1 op, 8706000.00 ns, 8.7060 ms/op
WorkloadActual  56: 1 op, 8760700.00 ns, 8.7607 ms/op
WorkloadActual  57: 1 op, 8832900.00 ns, 8.8329 ms/op
WorkloadActual  58: 1 op, 20248800.00 ns, 20.2488 ms/op
WorkloadActual  59: 1 op, 18276900.00 ns, 18.2769 ms/op
WorkloadActual  60: 1 op, 18102600.00 ns, 18.1026 ms/op
WorkloadActual  61: 1 op, 18338200.00 ns, 18.3382 ms/op
WorkloadActual  62: 1 op, 8197800.00 ns, 8.1978 ms/op
WorkloadActual  63: 1 op, 8945800.00 ns, 8.9458 ms/op
WorkloadActual  64: 1 op, 17455900.00 ns, 17.4559 ms/op
WorkloadActual  65: 1 op, 8826300.00 ns, 8.8263 ms/op
WorkloadActual  66: 1 op, 18467100.00 ns, 18.4671 ms/op
WorkloadActual  67: 1 op, 18807800.00 ns, 18.8078 ms/op
WorkloadActual  68: 1 op, 11468900.00 ns, 11.4689 ms/op
WorkloadActual  69: 1 op, 9501900.00 ns, 9.5019 ms/op
WorkloadActual  70: 1 op, 8711100.00 ns, 8.7111 ms/op
WorkloadActual  71: 1 op, 8111500.00 ns, 8.1115 ms/op
WorkloadActual  72: 1 op, 8706100.00 ns, 8.7061 ms/op
WorkloadActual  73: 1 op, 8771700.00 ns, 8.7717 ms/op
WorkloadActual  74: 1 op, 18440000.00 ns, 18.4400 ms/op
WorkloadActual  75: 1 op, 8684800.00 ns, 8.6848 ms/op
WorkloadActual  76: 1 op, 18364100.00 ns, 18.3641 ms/op
WorkloadActual  77: 1 op, 8914600.00 ns, 8.9146 ms/op
WorkloadActual  78: 1 op, 8699900.00 ns, 8.6999 ms/op
WorkloadActual  79: 1 op, 8609300.00 ns, 8.6093 ms/op
WorkloadActual  80: 1 op, 8640900.00 ns, 8.6409 ms/op
WorkloadActual  81: 1 op, 8644200.00 ns, 8.6442 ms/op
WorkloadActual  82: 1 op, 18909900.00 ns, 18.9099 ms/op
WorkloadActual  83: 1 op, 10954000.00 ns, 10.9540 ms/op
WorkloadActual  84: 1 op, 12619000.00 ns, 12.6190 ms/op
WorkloadActual  85: 1 op, 9260400.00 ns, 9.2604 ms/op
WorkloadActual  86: 1 op, 8849000.00 ns, 8.8490 ms/op
WorkloadActual  87: 1 op, 8769700.00 ns, 8.7697 ms/op
WorkloadActual  88: 1 op, 17614500.00 ns, 17.6145 ms/op
WorkloadActual  89: 1 op, 18704700.00 ns, 18.7047 ms/op
WorkloadActual  90: 1 op, 9812400.00 ns, 9.8124 ms/op
WorkloadActual  91: 1 op, 17448100.00 ns, 17.4481 ms/op
WorkloadActual  92: 1 op, 9109600.00 ns, 9.1096 ms/op
WorkloadActual  93: 1 op, 10150400.00 ns, 10.1504 ms/op
WorkloadActual  94: 1 op, 18408000.00 ns, 18.4080 ms/op
WorkloadActual  95: 1 op, 9461900.00 ns, 9.4619 ms/op
WorkloadActual  96: 1 op, 18239400.00 ns, 18.2394 ms/op
WorkloadActual  97: 1 op, 9650800.00 ns, 9.6508 ms/op
WorkloadActual  98: 1 op, 10295100.00 ns, 10.2951 ms/op
WorkloadActual  99: 1 op, 20813600.00 ns, 20.8136 ms/op
WorkloadActual  100: 1 op, 9111600.00 ns, 9.1116 ms/op

// AfterActualRun
WorkloadResult   1: 1 op, 8248610.00 ns, 8.2486 ms/op
WorkloadResult   2: 1 op, 8740110.00 ns, 8.7401 ms/op
WorkloadResult   3: 1 op, 8158610.00 ns, 8.1586 ms/op
WorkloadResult   4: 1 op, 8699310.00 ns, 8.6993 ms/op
WorkloadResult   5: 1 op, 8504810.00 ns, 8.5048 ms/op
WorkloadResult   6: 1 op, 9869010.00 ns, 9.8690 ms/op
WorkloadResult   7: 1 op, 18837210.00 ns, 18.8372 ms/op
WorkloadResult   8: 1 op, 8692410.00 ns, 8.6924 ms/op
WorkloadResult   9: 1 op, 8756010.00 ns, 8.7560 ms/op
WorkloadResult  10: 1 op, 8754110.00 ns, 8.7541 ms/op
WorkloadResult  11: 1 op, 8056210.00 ns, 8.0562 ms/op
WorkloadResult  12: 1 op, 8600410.00 ns, 8.6004 ms/op
WorkloadResult  13: 1 op, 18662310.00 ns, 18.6623 ms/op
WorkloadResult  14: 1 op, 9348810.00 ns, 9.3488 ms/op
WorkloadResult  15: 1 op, 9636410.00 ns, 9.6364 ms/op
WorkloadResult  16: 1 op, 8287910.00 ns, 8.2879 ms/op
WorkloadResult  17: 1 op, 8692110.00 ns, 8.6921 ms/op
WorkloadResult  18: 1 op, 8682410.00 ns, 8.6824 ms/op
WorkloadResult  19: 1 op, 8678310.00 ns, 8.6783 ms/op
WorkloadResult  20: 1 op, 17586210.00 ns, 17.5862 ms/op
WorkloadResult  21: 1 op, 18557510.00 ns, 18.5575 ms/op
WorkloadResult  22: 1 op, 13383210.00 ns, 13.3832 ms/op
WorkloadResult  23: 1 op, 8659710.00 ns, 8.6597 ms/op
WorkloadResult  24: 1 op, 8320110.00 ns, 8.3201 ms/op
WorkloadResult  25: 1 op, 8353610.00 ns, 8.3536 ms/op
WorkloadResult  26: 1 op, 8701910.00 ns, 8.7019 ms/op
WorkloadResult  27: 1 op, 19707010.00 ns, 19.7070 ms/op
WorkloadResult  28: 1 op, 18685110.00 ns, 18.6851 ms/op
WorkloadResult  29: 1 op, 8941910.00 ns, 8.9419 ms/op
WorkloadResult  30: 1 op, 18070810.00 ns, 18.0708 ms/op
WorkloadResult  31: 1 op, 8160410.00 ns, 8.1604 ms/op
WorkloadResult  32: 1 op, 8742610.00 ns, 8.7426 ms/op
WorkloadResult  33: 1 op, 18356710.00 ns, 18.3567 ms/op
WorkloadResult  34: 1 op, 8878810.00 ns, 8.8788 ms/op
WorkloadResult  35: 1 op, 18449510.00 ns, 18.4495 ms/op
WorkloadResult  36: 1 op, 8132510.00 ns, 8.1325 ms/op
WorkloadResult  37: 1 op, 8700410.00 ns, 8.7004 ms/op
WorkloadResult  38: 1 op, 8353610.00 ns, 8.3536 ms/op
WorkloadResult  39: 1 op, 8798210.00 ns, 8.7982 ms/op
WorkloadResult  40: 1 op, 8077910.00 ns, 8.0779 ms/op
WorkloadResult  41: 1 op, 18541210.00 ns, 18.5412 ms/op
WorkloadResult  42: 1 op, 18271910.00 ns, 18.2719 ms/op
WorkloadResult  43: 1 op, 8641210.00 ns, 8.6412 ms/op
WorkloadResult  44: 1 op, 8617810.00 ns, 8.6178 ms/op
WorkloadResult  45: 1 op, 8820710.00 ns, 8.8207 ms/op
WorkloadResult  46: 1 op, 8165310.00 ns, 8.1653 ms/op
WorkloadResult  47: 1 op, 8717610.00 ns, 8.7176 ms/op
WorkloadResult  48: 1 op, 8727510.00 ns, 8.7275 ms/op
WorkloadResult  49: 1 op, 17433410.00 ns, 17.4334 ms/op
WorkloadResult  50: 1 op, 18447710.00 ns, 18.4477 ms/op
WorkloadResult  51: 1 op, 8249410.00 ns, 8.2494 ms/op
WorkloadResult  52: 1 op, 8841510.00 ns, 8.8415 ms/op
WorkloadResult  53: 1 op, 8752510.00 ns, 8.7525 ms/op
WorkloadResult  54: 1 op, 8721810.00 ns, 8.7218 ms/op
WorkloadResult  55: 1 op, 8705810.00 ns, 8.7058 ms/op
WorkloadResult  56: 1 op, 8760510.00 ns, 8.7605 ms/op
WorkloadResult  57: 1 op, 8832710.00 ns, 8.8327 ms/op
WorkloadResult  58: 1 op, 20248610.00 ns, 20.2486 ms/op
WorkloadResult  59: 1 op, 18276710.00 ns, 18.2767 ms/op
WorkloadResult  60: 1 op, 18102410.00 ns, 18.1024 ms/op
WorkloadResult  61: 1 op, 18338010.00 ns, 18.3380 ms/op
WorkloadResult  62: 1 op, 8197610.00 ns, 8.1976 ms/op
WorkloadResult  63: 1 op, 8945610.00 ns, 8.9456 ms/op
WorkloadResult  64: 1 op, 17455710.00 ns, 17.4557 ms/op
WorkloadResult  65: 1 op, 8826110.00 ns, 8.8261 ms/op
WorkloadResult  66: 1 op, 18466910.00 ns, 18.4669 ms/op
WorkloadResult  67: 1 op, 18807610.00 ns, 18.8076 ms/op
WorkloadResult  68: 1 op, 11468710.00 ns, 11.4687 ms/op
WorkloadResult  69: 1 op, 9501710.00 ns, 9.5017 ms/op
WorkloadResult  70: 1 op, 8710910.00 ns, 8.7109 ms/op
WorkloadResult  71: 1 op, 8111310.00 ns, 8.1113 ms/op
WorkloadResult  72: 1 op, 8705910.00 ns, 8.7059 ms/op
WorkloadResult  73: 1 op, 8771510.00 ns, 8.7715 ms/op
WorkloadResult  74: 1 op, 18439810.00 ns, 18.4398 ms/op
WorkloadResult  75: 1 op, 8684610.00 ns, 8.6846 ms/op
WorkloadResult  76: 1 op, 18363910.00 ns, 18.3639 ms/op
WorkloadResult  77: 1 op, 8914410.00 ns, 8.9144 ms/op
WorkloadResult  78: 1 op, 8699710.00 ns, 8.6997 ms/op
WorkloadResult  79: 1 op, 8609110.00 ns, 8.6091 ms/op
WorkloadResult  80: 1 op, 8640710.00 ns, 8.6407 ms/op
WorkloadResult  81: 1 op, 8644010.00 ns, 8.6440 ms/op
WorkloadResult  82: 1 op, 18909710.00 ns, 18.9097 ms/op
WorkloadResult  83: 1 op, 10953810.00 ns, 10.9538 ms/op
WorkloadResult  84: 1 op, 12618810.00 ns, 12.6188 ms/op
WorkloadResult  85: 1 op, 9260210.00 ns, 9.2602 ms/op
WorkloadResult  86: 1 op, 8848810.00 ns, 8.8488 ms/op
WorkloadResult  87: 1 op, 8769510.00 ns, 8.7695 ms/op
WorkloadResult  88: 1 op, 17614310.00 ns, 17.6143 ms/op
WorkloadResult  89: 1 op, 18704510.00 ns, 18.7045 ms/op
WorkloadResult  90: 1 op, 9812210.00 ns, 9.8122 ms/op
WorkloadResult  91: 1 op, 17447910.00 ns, 17.4479 ms/op
WorkloadResult  92: 1 op, 9109410.00 ns, 9.1094 ms/op
WorkloadResult  93: 1 op, 10150210.00 ns, 10.1502 ms/op
WorkloadResult  94: 1 op, 18407810.00 ns, 18.4078 ms/op
WorkloadResult  95: 1 op, 9461710.00 ns, 9.4617 ms/op
WorkloadResult  96: 1 op, 18239210.00 ns, 18.2392 ms/op
WorkloadResult  97: 1 op, 9650610.00 ns, 9.6506 ms/op
WorkloadResult  98: 1 op, 10294910.00 ns, 10.2949 ms/op
WorkloadResult  99: 1 op, 20813410.00 ns, 20.8134 ms/op
WorkloadResult  100: 1 op, 9111410.00 ns, 9.1114 ms/op
GC:  1 1 0 7694544 1

// AfterAll

Mean = 11.7288 ms, StdErr = 0.4431 ms (3.78%); N = 100, StdDev = 4.4313 ms
Min = 8.0562 ms, Q1 = 8.6884 ms, Median = 8.8452 ms, Q3 = 17.6003 ms, Max = 20.8134 ms
IQR = 8.9119 ms, LowerFence = -4.6795 ms, UpperFence = 30.9681 ms
ConfidenceInterval = [10.2259 ms; 13.2317 ms] (CI 99.9%), Margin = 1.5029 ms (12.81% of Mean)
Skewness = 0.86, Kurtosis = 1.85, MValue = 2.83

// ***** BenchmarkRunner: Finish  *****

// * Export *
  BenchmarkDotNet.Artifacts\results\Program.CompilerService-report.csv
  BenchmarkDotNet.Artifacts\results\Program.CompilerService-report-github.md
  BenchmarkDotNet.Artifacts\results\Program.CompilerService-report.html

// * Detailed results *
CompilerService.ParsingTypeCheckerFs: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
Runtime = .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0; GC = Concurrent Workstation
Mean = 193.7103 ms, StdErr = 0.4457 ms (0.23%); N = 15, StdDev = 1.7263 ms
Min = 191.7261 ms, Q1 = 192.5223 ms, Median = 193.1274 ms, Q3 = 195.0292 ms, Max = 197.9492 ms
IQR = 2.5069 ms, LowerFence = 188.7620 ms, UpperFence = 198.7896 ms
ConfidenceInterval = [191.8648 ms; 195.5559 ms] (CI 99.9%), Margin = 1.8455 ms (0.95% of Mean)
Skewness = 1.03, Kurtosis = 3.03, MValue = 2
-------------------- Histogram --------------------
[191.114 ms ; 198.562 ms) | @@@@@@@@@@@@@@@
---------------------------------------------------

CompilerService.ILReading: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
Runtime = .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0; GC = Concurrent Workstation
Mean = 1.4858 s, StdErr = 0.0063 s (0.42%); N = 15, StdDev = 0.0245 s
Min = 1.4483 s, Q1 = 1.4607 s, Median = 1.4868 s, Q3 = 1.5095 s, Max = 1.5276 s
IQR = 0.0488 s, LowerFence = 1.3874 s, UpperFence = 1.5827 s
ConfidenceInterval = [1.4596 s; 1.5119 s] (CI 99.9%), Margin = 0.0261 s (1.76% of Mean)
Skewness = 0.04, Kurtosis = 1.68, MValue = 2
-------------------- Histogram --------------------
[1.440 s ; 1.474 s) | @@@@@
[1.474 s ; 1.536 s) | @@@@@@@@@@
---------------------------------------------------

CompilerService.TypeCheckFileWith100ReferencedProjects: Job-FEFVFA(InvocationCount=1, UnrollFactor=1)
Runtime = .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0; GC = Concurrent Workstation
Mean = 11.7288 ms, StdErr = 0.4431 ms (3.78%); N = 100, StdDev = 4.4313 ms
Min = 8.0562 ms, Q1 = 8.6884 ms, Median = 8.8452 ms, Q3 = 17.6003 ms, Max = 20.8134 ms
IQR = 8.9119 ms, LowerFence = -4.6795 ms, UpperFence = 30.9681 ms
ConfidenceInterval = [10.2259 ms; 13.2317 ms] (CI 99.9%), Margin = 1.5029 ms (12.81% of Mean)
Skewness = 0.86, Kurtosis = 1.85, MValue = 2.83
-------------------- Histogram --------------------
[ 8.018 ms ;  9.689 ms) | @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
[ 9.689 ms ; 11.476 ms) | @@@@@@
[11.476 ms ; 13.836 ms) | @@
[13.836 ms ; 15.507 ms) | 
[15.507 ms ; 17.336 ms) | 
[17.336 ms ; 19.007 ms) | @@@@@@@@@@@@@@@@@@@@@@@@@@
[19.007 ms ; 21.096 ms) | @@@
---------------------------------------------------

// * Summary *

BenchmarkDotNet=v0.11.3, OS=Windows 10.0.19041
Intel Core i7-6700K CPU 4.00GHz (Skylake), 1 CPU, 8 logical and 4 physical cores
  [Host]     : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit LegacyJIT-v4.8.4180.0 DEBUG
  Job-FEFVFA : .NET Framework 4.7.2 (CLR 4.0.30319.42000), 64bit RyuJIT-v4.8.4180.0

InvocationCount=1  UnrollFactor=1  

                                 Method |        Mean |     Error |    StdDev |       Median | Gen 0/1k Op | Gen 1/1k Op | Gen 2/1k Op | Allocated Memory/Op |
--------------------------------------- |------------:|----------:|----------:|-------------:|------------:|------------:|------------:|--------------------:|
                   ParsingTypeCheckerFs |   193.71 ms |  1.846 ms |  1.726 ms |   193.127 ms |   6000.0000 |   2000.0000 |           - |            40.41 MB |
                              ILReading | 1,485.79 ms | 26.141 ms | 24.452 ms | 1,486.826 ms | 149000.0000 |  51000.0000 |   6000.0000 |           899.01 MB |
 TypeCheckFileWith100ReferencedProjects |    11.73 ms |  1.503 ms |  4.431 ms |     8.845 ms |   1000.0000 |   1000.0000 |           - |             7.34 MB |

// * Warnings *
MinIterationTime
  CompilerService.TypeCheckFileWith100ReferencedProjects: InvocationCount=1, UnrollFactor=1 -> MinIterationTime = 8.0564 ms which is very small. It's recommended to increase it.
MultimodalDistribution
  CompilerService.TypeCheckFileWith100ReferencedProjects: InvocationCount=1, UnrollFactor=1 -> It seems that the distribution can have several modes (mValue = 2.83)

// * Legends *
  Mean                : Arithmetic mean of all measurements
  Error               : Half of 99.9% confidence interval
  StdDev              : Standard deviation of all measurements
  Median              : Value separating the higher half of all measurements (50th percentile)
  Gen 0/1k Op         : GC Generation 0 collects per 1k Operations
  Gen 1/1k Op         : GC Generation 1 collects per 1k Operations
  Gen 2/1k Op         : GC Generation 2 collects per 1k Operations
  Allocated Memory/Op : Allocated memory per single operation (managed only, inclusive, 1KB = 1024B)
  1 ms                : 1 Millisecond (0.001 sec)

// * Diagnostic Output - MemoryDiagnoser *


// ***** BenchmarkRunner: End *****
Run time: 00:03:55 (235.53 sec), executed benchmarks: 3

// * Artifacts cleanup *

The benchmark is here: https://github.com/dotnet/fsharp/tree/master/benchmarks/CompilerServiceBenchmarks

abelbraaksma · 2020-08-05T17:34:59Z

As you can see in the log, each benchmark was executed many times to for the report:

@cartermp Actually, the log shows the opposite, each run has only 1 op. This number should be much higher, in your case 50 - 70 op with default settings. Which is precisely what you don't want. This means, that the overhead has a large influence.

It's a known bug, quite recently introduced in BDN dotnet/BenchmarkDotNet#1338. I'll have a look at the code.

abelbraaksma · 2020-08-05T17:52:55Z

This kind of timings, plus that it reaches the max of 100 runs are also indicative of a problem with the benchmark:

WorkloadResult  94: 1 op, 18407810.00 ns, 18.4078 ms/op
WorkloadResult  95: 1 op, 9461710.00 ns, 9.4617 ms/op

cartermp · 2020-08-05T18:46:04Z

Gotcha, I see. Well I don't think that this should stop progress on this though. The chief concern here is memory usage, and both switching to a struct tuple or this different approach are an obvious win.

abelbraaksma · 2020-08-05T19:25:36Z

Oh yes, absolutely, I didn't mean to block progress in any way, it's certainly an improvement :).

…m reader for attribute rows (dotnet#9218) * seekReadCustomAttributeRow as a struct 3-tuple * Read custom attributes via a specialized reader

cartermp force-pushed the struct-seekreadcustomattrs branch from df057a1 to da6df7f Compare May 17, 2020 23:15

TIHan suggested changes May 18, 2020

View reviewed changes

KevinRansom approved these changes May 26, 2020

View reviewed changes

dsyme approved these changes Jul 22, 2020

View reviewed changes

cartermp force-pushed the struct-seekreadcustomattrs branch from da6df7f to 70c2c20 Compare August 5, 2020 02:12

cartermp changed the title ~~Struct tuple for seekReadCustomAttributeRow~~ Eliminate tuple allocations in seekReadCustomAttributeRow via a custom reader for attribute rows Aug 5, 2020

cartermp added 2 commits August 4, 2020 22:24

seekReadCustomAttributeRow as a struct 3-tuple

1d1df66

Read custom attributes via a specialized reader

206607a

cartermp force-pushed the struct-seekreadcustomattrs branch from 70c2c20 to 206607a Compare August 5, 2020 05:25

abelbraaksma mentioned this pull request Aug 5, 2020

Issue with "run one iteration for long operations", it's flaky and considers many nano-operations as "long", leading to one op per cycle dotnet/BenchmarkDotNet#1338

Closed

brettfo changed the base branch from master to main August 19, 2020 20:02

TIHan approved these changes Aug 25, 2020

View reviewed changes

TIHan merged commit f92efef into dotnet:main Aug 25, 2020

cartermp mentioned this pull request Sep 2, 2020

discussion: impact of using exceptions on memory traffic to hold info in ConstraintSolver.ResolveOverloading #8260

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Eliminate tuple allocations in seekReadCustomAttributeRow via a custom reader for attribute rows #9218

Eliminate tuple allocations in seekReadCustomAttributeRow via a custom reader for attribute rows #9218

cartermp commented May 17, 2020

TIHan left a comment

TIHan commented May 18, 2020

cartermp commented May 18, 2020

cartermp commented May 18, 2020

TIHan commented May 26, 2020

cartermp commented May 29, 2020 •

edited

Loading

cartermp commented Jun 27, 2020 •

edited

Loading

cartermp commented Aug 5, 2020

cartermp commented Aug 5, 2020

cartermp commented Aug 5, 2020

cartermp commented Aug 5, 2020

abelbraaksma commented Aug 5, 2020

cartermp commented Aug 5, 2020

abelbraaksma commented Aug 5, 2020 •

edited

Loading

abelbraaksma commented Aug 5, 2020 •

edited

Loading

cartermp commented Aug 5, 2020

abelbraaksma commented Aug 5, 2020

Eliminate tuple allocations in seekReadCustomAttributeRow via a custom reader for attribute rows #9218

Eliminate tuple allocations in seekReadCustomAttributeRow via a custom reader for attribute rows #9218

Conversation

cartermp commented May 17, 2020

TIHan left a comment

Choose a reason for hiding this comment

TIHan commented May 18, 2020

cartermp commented May 18, 2020

cartermp commented May 18, 2020

TIHan commented May 26, 2020

cartermp commented May 29, 2020 • edited Loading

cartermp commented Jun 27, 2020 • edited Loading

cartermp commented Aug 5, 2020

cartermp commented Aug 5, 2020

cartermp commented Aug 5, 2020

cartermp commented Aug 5, 2020

abelbraaksma commented Aug 5, 2020

cartermp commented Aug 5, 2020

abelbraaksma commented Aug 5, 2020 • edited Loading

abelbraaksma commented Aug 5, 2020 • edited Loading

cartermp commented Aug 5, 2020

abelbraaksma commented Aug 5, 2020

cartermp commented May 29, 2020 •

edited

Loading

cartermp commented Jun 27, 2020 •

edited

Loading

abelbraaksma commented Aug 5, 2020 •

edited

Loading

abelbraaksma commented Aug 5, 2020 •

edited

Loading