Fix native memory profiler (#1451)

WojciechNagorski · web-flow · commit e4d37d03c0b1 · 2020-09-02T13:12:20.000+02:00
* Add BuildResult to DiagnoserResults

* Update Microsoft.Diagnostics.Tracing.TraceEvent

* Improve common.props

* Fix NativeMemoryProfiler for .Net Framework

* Fix NativeMemoryProfiler for .Net Core
diff --git a/build/common.props b/build/common.props
@@ -28,7 +28,7 @@
   </PropertyGroup>
 
   <PropertyGroup Condition=" '$(Configuration)' == 'Release' ">
-    <AssemblyOriginatorKeyFile>..\..\build\strongNameKey.snk</AssemblyOriginatorKeyFile>
+    <AssemblyOriginatorKeyFile>$(MSBuildThisFileDirectory)strongNameKey.snk</AssemblyOriginatorKeyFile>
     <SignAssembly>true</SignAssembly>
     <PublicSign Condition=" '$(OS)' != 'Windows_NT' ">true</PublicSign>
     <GenerateDocumentationFile>true</GenerateDocumentationFile>
@@ -73,4 +73,4 @@
       <PrivateAssets>all</PrivateAssets>
     </PackageReference>
   </ItemGroup>
-</Project>
+</Project>
diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/BenchmarkDotNet.Diagnostics.Windows.csproj b/src/BenchmarkDotNet.Diagnostics.Windows/BenchmarkDotNet.Diagnostics.Windows.csproj
@@ -12,6 +12,6 @@
     <ProjectReference Include="..\BenchmarkDotNet\BenchmarkDotNet.csproj" />
   </ItemGroup>
   <ItemGroup>
-    <PackageReference Include="Microsoft.Diagnostics.Tracing.TraceEvent" Version="2.0.49" PrivateAssets="contentfiles;analyzers" />
+    <PackageReference Include="Microsoft.Diagnostics.Tracing.TraceEvent" Version="2.0.57" PrivateAssets="contentfiles;analyzers" />
   </ItemGroup>
-</Project>
+</Project>
diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/EtwProfilerConfig.cs b/src/BenchmarkDotNet.Diagnostics.Windows/EtwProfilerConfig.cs
@@ -62,6 +62,7 @@ public EtwProfilerConfig(
                              | ClrTraceEventParser.Keywords.GC
                              | ClrTraceEventParser.Keywords.Jit
                              | ClrTraceEventParser.Keywords.JitTracing // for the inlining events
+                             | ClrTraceEventParser.Keywords.JittedMethodILToNativeMap // Fix NativeMemoryProfiler for .Net Framework
                              | ClrTraceEventParser.Keywords.Loader
                              | ClrTraceEventParser.Keywords.NGen),
                     new TraceEventProviderOptions { StacksEnabled = false }), // stacks are too expensive for our purposes
diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/NativeMemoryProfiler.cs b/src/BenchmarkDotNet.Diagnostics.Windows/NativeMemoryProfiler.cs
@@ -55,7 +55,7 @@ public IEnumerable<Metric> ProcessResults(DiagnoserResults results)
             if (!etwProfiler.BenchmarkToEtlFile.TryGetValue(results.BenchmarkCase, out var traceFilePath))
                 return Enumerable.Empty<Metric>();
 
-            return new NativeMemoryLogParser(traceFilePath, results.BenchmarkCase, logger).Parse();
+            return new NativeMemoryLogParser(traceFilePath, results.BenchmarkCase, logger, results.BuildResult.ArtifactsPaths.ProgramName).Parse();
         }
 
         public IEnumerable<ValidationError> Validate(ValidationParameters validationParameters) => etwProfiler.Validate(validationParameters);
@@ -67,7 +67,6 @@ private static EtwProfilerConfig CreateDefaultConfig()
             var kernelKeywords = KernelTraceEventParser.Keywords.VirtualAlloc | KernelTraceEventParser.Keywords.VAMap;
 
             return new EtwProfilerConfig(
-                providers: Enumerable.Empty<(Guid providerGuid, TraceEventLevel providerLevel, ulong keywords, TraceEventProviderOptions options)>().ToList(),
                 performExtraBenchmarksRun: true,
                 kernelKeywords: kernelKeywords,
                 createHeapSession: true);
diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/Sessions.cs b/src/BenchmarkDotNet.Diagnostics.Windows/Sessions.cs
@@ -22,7 +22,7 @@ public HeapSession(DiagnoserActionParameters details, EtwProfilerConfig config,
         {
         }
 
-        protected override string FileExtension => ".userheap.etl";
+        protected override string FileExtension => "userheap.etl";
 
         internal override Session EnableProviders()
         {
@@ -39,7 +39,7 @@ public UserSession(DiagnoserActionParameters details, EtwProfilerConfig config,
         {
         }
 
-        protected override string FileExtension => ".etl";
+        protected override string FileExtension => "etl";
 
         internal override Session EnableProviders()
         {
@@ -61,7 +61,7 @@ public KernelSession(DiagnoserActionParameters details, EtwProfilerConfig config
         {
         }
 
-        protected override string FileExtension => ".kernel.etl";
+        protected override string FileExtension => "kernel.etl";
 
         internal override Session EnableProviders()
         {
@@ -72,6 +72,8 @@ internal override Session EnableProviders()
             if (Details.Config.GetHardwareCounters().Any())
                 keywords |= KernelTraceEventParser.Keywords.PMCProfile; // Precise Machine Counters
 
+            TraceEventSession.StackCompression = true;
+
             try
             {
                 TraceEventSession.EnableKernelProvider(keywords, KernelTraceEventParser.Keywords.Profile);
diff --git a/src/BenchmarkDotNet.Diagnostics.Windows/Tracing/NativeMemoryLogParser.cs b/src/BenchmarkDotNet.Diagnostics.Windows/Tracing/NativeMemoryLogParser.cs
@@ -1,13 +1,16 @@
-﻿using System.Collections.Generic;
+﻿using System;
+using System.Collections.Generic;
 using System.Diagnostics.CodeAnalysis;
 using System.Linq;
 using BenchmarkDotNet.Columns;
 using BenchmarkDotNet.Diagnosers;
+using BenchmarkDotNet.Engines;
 using BenchmarkDotNet.Loggers;
 using BenchmarkDotNet.Reports;
 using BenchmarkDotNet.Running;
 using Microsoft.Diagnostics.Tracing.Etlx;
 using Microsoft.Diagnostics.Tracing.Parsers.Kernel;
+using Microsoft.Diagnostics.Tracing.Stacks;
 using Address = System.UInt64;
 
 namespace BenchmarkDotNet.Diagnostics.Windows.Tracing
@@ -23,18 +26,27 @@ public class NativeMemoryLogParser
 
         private readonly ILogger logger;
 
-        public NativeMemoryLogParser(string etlFilePath, BenchmarkCase benchmarkCase, ILogger logger)
+        private readonly string moduleName;
+
+        private readonly string functionName;
+
+        public NativeMemoryLogParser(string etlFilePath, BenchmarkCase benchmarkCase, ILogger logger,
+            string programName)
         {
             this.etlFilePath = etlFilePath;
             this.benchmarkCase = benchmarkCase;
             this.logger = logger;
+
+            moduleName = programName;
+            functionName = nameof(EngineParameters.WorkloadActionUnroll);
         }
 
         //Code is inspired by https://github.com/Microsoft/perfview/blob/master/src/PerfView/PerfViewData.cs#L5719-L5944
         public IEnumerable<Metric> Parse()
         {
             using (var traceLog = new TraceLog(TraceLog.CreateFromEventTraceLogFile(etlFilePath)))
             {
+                var stackSource = new MutableTraceEventStackSource(traceLog);
                 var eventSource = traceLog.Events.GetSource();
 
                 var bdnEventsParser = new EngineEventLogParser(eventSource);
@@ -77,6 +89,14 @@ public IEnumerable<Metric> Parse()
                         return;
                     }
 
+                    var call = data.CallStackIndex();
+                    var frameIndex = stackSource.GetCallStack(call, data);
+
+                    if (!IsCallStackIn(frameIndex))
+                    {
+                        return;
+                    }
+
                     var allocs = lastHeapAllocs;
                     if (data.HeapHandle != lastHeapHandle)
                     {
@@ -91,7 +111,27 @@ public IEnumerable<Metric> Parse()
                         nativeLeakSize += data.AllocSize;
                         totalAllocation += data.AllocSize;
                     }
+
+                    bool IsCallStackIn(StackSourceCallStackIndex index)
+                    {
+                        while (index != StackSourceCallStackIndex.Invalid)
+                        {
+                            var frame = stackSource.GetFrameIndex(index);
+                            var name = stackSource.GetFrameName(frame, false);
+
+                            if (name.StartsWith(moduleName, StringComparison.Ordinal) &&
+                                name.IndexOf(functionName, StringComparison.Ordinal) > 0)
+                            {
+                                return true;
+                            }
+
+                            index = stackSource.GetCallerIndex(index);
+                        }
+
+                        return false;
+                    }
                 };
+
                 heapParser.HeapTraceFree += delegate(HeapFreeTraceData data)
                 {
                     if (!start)
@@ -112,6 +152,7 @@ public IEnumerable<Metric> Parse()
                         allocs.Remove(data.FreeAddress);
                     }
                 };
+
                 heapParser.HeapTraceReAlloc += delegate(HeapReallocTraceData data)
                 {
                     if (!start)
@@ -132,22 +173,23 @@ public IEnumerable<Metric> Parse()
                         allocs = CreateHeapCache(data.HeapHandle, heaps, ref lastHeapAllocs, ref lastHeapHandle);
                     }
 
-                    // This is a clone of the Free code
                     if (allocs.TryGetValue(data.OldAllocAddress, out long alloc))
                     {
+                        // Free
                         nativeLeakSize -= alloc;
 
                         allocs.Remove(data.OldAllocAddress);
-                    }
 
-                    // This is a clone of the Alloc code (sigh don't clone code)
-                    allocs[data.NewAllocAddress] = data.NewAllocSize;
+                        // Alloc
+                        allocs[data.NewAllocAddress] = data.NewAllocSize;
 
-                    checked
-                    {
-                        nativeLeakSize += data.NewAllocSize;
+                        checked
+                        {
+                            nativeLeakSize += data.NewAllocSize;
+                        }
                     }
                 };
+
                 heapParser.HeapTraceDestroy += delegate(HeapTraceData data)
                 {
                     if (!start)
diff --git a/src/BenchmarkDotNet/BenchmarkDotNet.csproj b/src/BenchmarkDotNet/BenchmarkDotNet.csproj
@@ -27,7 +27,7 @@
     <PackageReference Include="System.Threading.Tasks.Extensions" Version="4.5.2" />
     <PackageReference Include="Microsoft.CodeAnalysis.CSharp" Version="2.10.0" />
     <PackageReference Include="Microsoft.Diagnostics.NETCore.Client" Version="0.2.61701" />
-    <PackageReference Include="Microsoft.Diagnostics.Tracing.TraceEvent" Version="2.0.49" PrivateAssets="contentfiles;analyzers" />
+    <PackageReference Include="Microsoft.Diagnostics.Tracing.TraceEvent" Version="2.0.57" PrivateAssets="contentfiles;analyzers" />
   </ItemGroup>
   <ItemGroup Condition="'$(OS)' == 'Windows_NT'">
     <ProjectReference Include="..\BenchmarkDotNet.Disassembler.x64\BenchmarkDotNet.Disassembler.x64.csproj">
diff --git a/src/BenchmarkDotNet/Diagnosers/DiagnoserResults.cs b/src/BenchmarkDotNet/Diagnosers/DiagnoserResults.cs
@@ -1,16 +1,19 @@
 ﻿using BenchmarkDotNet.Engines;
 using BenchmarkDotNet.Running;
+using BenchmarkDotNet.Toolchains.Results;
 
 namespace BenchmarkDotNet.Diagnosers
 {
     public class DiagnoserResults
     {
-        public DiagnoserResults(BenchmarkCase benchmarkCase, long totalOperations, GcStats gcStats, ThreadingStats threadingStats)
+        public DiagnoserResults(BenchmarkCase benchmarkCase, long totalOperations, GcStats gcStats,
+            ThreadingStats threadingStats, BuildResult buildResult)
         {
             BenchmarkCase = benchmarkCase;
             TotalOperations = totalOperations;
             GcStats = gcStats;
             ThreadingStats = threadingStats;
+            BuildResult = buildResult;
         }
 
         public BenchmarkCase BenchmarkCase { get; }
@@ -20,5 +23,7 @@ public DiagnoserResults(BenchmarkCase benchmarkCase, long totalOperations, GcSta
         public GcStats GcStats { get; }
 
         public ThreadingStats ThreadingStats { get; }
+
+        public BuildResult BuildResult { get; }
     }
 }
diff --git a/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs b/src/BenchmarkDotNet/Running/BenchmarkRunnerClean.cs
@@ -428,7 +428,7 @@ private static (bool success, List<ExecuteResult> executeResults, GcStats gcStat
 
                     metrics.AddRange(
                         noOverheadCompositeDiagnoser.ProcessResults(
-                            new DiagnoserResults(benchmarkCase, measurements.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats)));
+                            new DiagnoserResults(benchmarkCase, measurements.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats, buildResult)));
                 }
 
                 if (autoLaunchCount && launchIndex == 2 && analyzeRunToRunVariance)
@@ -467,7 +467,7 @@ private static (bool success, List<ExecuteResult> executeResults, GcStats gcStat
 
                 metrics.AddRange(
                     extraRunCompositeDiagnoser.ProcessResults(
-                        new DiagnoserResults(benchmarkCase, allRuns.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats)));
+                        new DiagnoserResults(benchmarkCase, allRuns.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats, buildResult)));
 
                 logger.WriteLine();
             }
diff --git a/tests/BenchmarkDotNet.IntegrationTests/ExporterIOTests.cs b/tests/BenchmarkDotNet.IntegrationTests/ExporterIOTests.cs
@@ -134,7 +134,7 @@ private Summary GetMockSummary(string resultsDirectoryPath, IConfig config, para
 
         private class MockExporter : ExporterBase
         {
-            public int ExportCount = 0;
+            public int ExportCount;
 
             public override void ExportToLog(Summary summary, ILogger logger)
             {

Original file line number	Diff line number	Diff line change
`@@ -22,7 +22,7 @@ public HeapSession(DiagnoserActionParameters details, EtwProfilerConfig config,`
`22`	`22`	`{`
`23`	`23`	`}`
`24`	`24`
`25`		`- protected override string FileExtension => ".userheap.etl";`
	`25`	`+ protected override string FileExtension => "userheap.etl";`
`26`	`26`
`27`	`27`	`internal override Session EnableProviders()`
`28`	`28`	`{`
`@@ -39,7 +39,7 @@ public UserSession(DiagnoserActionParameters details, EtwProfilerConfig config,`
`39`	`39`	`{`
`40`	`40`	`}`
`41`	`41`
`42`		`- protected override string FileExtension => ".etl";`
	`42`	`+ protected override string FileExtension => "etl";`
`43`	`43`
`44`	`44`	`internal override Session EnableProviders()`
`45`	`45`	`{`
`@@ -61,7 +61,7 @@ public KernelSession(DiagnoserActionParameters details, EtwProfilerConfig config`
`61`	`61`	`{`
`62`	`62`	`}`
`63`	`63`
`64`		`- protected override string FileExtension => ".kernel.etl";`
	`64`	`+ protected override string FileExtension => "kernel.etl";`
`65`	`65`
`66`	`66`	`internal override Session EnableProviders()`
`67`	`67`	`{`
`@@ -72,6 +72,8 @@ internal override Session EnableProviders()`
`72`	`72`	`if (Details.Config.GetHardwareCounters().Any())`
`73`	`73`	`keywords \|= KernelTraceEventParser.Keywords.PMCProfile; // Precise Machine Counters`
`74`	`74`
	`75`	`+ TraceEventSession.StackCompression = true;`
	`76`	`+`
`75`	`77`	`try`
`76`	`78`	`{`
`77`	`79`	`TraceEventSession.EnableKernelProvider(keywords, KernelTraceEventParser.Keywords.Profile);`
Original file line number	Diff line number	Diff line change
`@@ -1,16 +1,19 @@`
`1`	`1`	`using BenchmarkDotNet.Engines;`
`2`	`2`	`using BenchmarkDotNet.Running;`
	`3`	`+using BenchmarkDotNet.Toolchains.Results;`
`3`	`4`
`4`	`5`	`namespace BenchmarkDotNet.Diagnosers`
`5`	`6`	`{`
`6`	`7`	`public class DiagnoserResults`
`7`	`8`	`{`
`8`		`- public DiagnoserResults(BenchmarkCase benchmarkCase, long totalOperations, GcStats gcStats, ThreadingStats threadingStats)`
	`9`	`+ public DiagnoserResults(BenchmarkCase benchmarkCase, long totalOperations, GcStats gcStats,`
	`10`	`+ ThreadingStats threadingStats, BuildResult buildResult)`
`9`	`11`	`{`
`10`	`12`	`BenchmarkCase = benchmarkCase;`
`11`	`13`	`TotalOperations = totalOperations;`
`12`	`14`	`GcStats = gcStats;`
`13`	`15`	`ThreadingStats = threadingStats;`
	`16`	`+ BuildResult = buildResult;`
`14`	`17`	`}`
`15`	`18`
`16`	`19`	`public BenchmarkCase BenchmarkCase { get; }`
`@@ -20,5 +23,7 @@ public DiagnoserResults(BenchmarkCase benchmarkCase, long totalOperations, GcSta`
`20`	`23`	`public GcStats GcStats { get; }`
`21`	`24`
`22`	`25`	`public ThreadingStats ThreadingStats { get; }`
	`26`	`+`
	`27`	`+ public BuildResult BuildResult { get; }`
`23`	`28`	`}`
`24`	`29`	`}`
Original file line number	Diff line number	Diff line change
`@@ -428,7 +428,7 @@ private static (bool success, List<ExecuteResult> executeResults, GcStats gcStat`
`428`	`428`
`429`	`429`	`metrics.AddRange(`
`430`	`430`	`noOverheadCompositeDiagnoser.ProcessResults(`
`431`		`- new DiagnoserResults(benchmarkCase, measurements.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats)));`
	`431`	`+ new DiagnoserResults(benchmarkCase, measurements.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats, buildResult)));`
`432`	`432`	`}`
`433`	`433`
`434`	`434`	`if (autoLaunchCount && launchIndex == 2 && analyzeRunToRunVariance)`
`@@ -467,7 +467,7 @@ private static (bool success, List<ExecuteResult> executeResults, GcStats gcStat`
`467`	`467`
`468`	`468`	`metrics.AddRange(`
`469`	`469`	`extraRunCompositeDiagnoser.ProcessResults(`
`470`		`- new DiagnoserResults(benchmarkCase, allRuns.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats)));`
	`470`	`+ new DiagnoserResults(benchmarkCase, allRuns.Where(measurement => measurement.IsWorkload()).Sum(m => m.Operations), gcStats, threadingStats, buildResult)));`
`471`	`471`
`472`	`472`	`logger.WriteLine();`
`473`	`473`	`}`
Original file line number	Diff line number	Diff line change
`@@ -134,7 +134,7 @@ private Summary GetMockSummary(string resultsDirectoryPath, IConfig config, para`
`134`	`134`
`135`	`135`	`private class MockExporter : ExporterBase`
`136`	`136`	`{`
`137`		`- public int ExportCount = 0;`
	`137`	`+ public int ExportCount;`
`138`	`138`
`139`	`139`	`public override void ExportToLog(Summary summary, ILogger logger)`
`140`	`140`	`{`