[Profiler] Generate heap snapshot

profiler/src/Demos/Samples.BuggyBits/Properties/launchSettings.json

@@ -53,15 +53,17 @@
         "DOTNET_gcServer=": "1",
         "DOTNET_GCHeapCount": "3",
 
+        "DD_PROFILING_MANAGED_ACTIVATION_ENABLED": "0",
         "DD_PROFILING_ENABLED": "1",
         "DD_PROFILING_CPU_ENABLED": "1",
         "DD_PROFILING_WALLTIME_ENABLED": "1",
         "DD_PROFILING_EXCEPTION_ENABLED": "0",
         "DD_PROFILING_LOCK_ENABLED": "1",
         "DD_PROFILING_ALLOCATION_ENABLED": "1",
-        "DD_PROFILING_HEAP_ENABLED": "0",
+        "DD_PROFILING_HEAP_ENABLED": "1",
         "DD_INTERNAL_PROFILING_HTTP_ENABLED": "1",
         "DD_INTERNAL_PROFILING_FORCE_HTTP_SAMPLING": "1",
+        "DD_PROFILING_HEAPSNAPSHOT_ENABLED": "1",
 
         "DD_PROFILING_GC_ENABLED": "1",
         "DD_INTERNAL_PROFILING_TIMESTAMPS_AS_LABEL_ENABLED": "1",

profiler/src/Demos/Samples.Computer01/Properties/launchSettings.json

@@ -8,20 +8,17 @@
     "Computer01+Profiler": {
       "commandName": "Executable",
       "executablePath": "$(BaseOutputPath)\\$(ConfigBasedRelativeOutputPath)\\profiler\\src\\Demos\\Samples.Computer01\\$(TargetFramework)\\Samples.Computer01.exe",
-      "commandLineArgs": "--scenario 10 --threads 4 --param 250",
+      "commandLineArgs": "--scenario 7 --threads 4",
       "environmentVariables": {
         "COR_ENABLE_PROFILING": "1",
         "COR_PROFILER": "{BD1A650D-AC5D-4896-B64F-D6FA25D6B26A}",
         "COR_PROFILER_PATH_64": "$(BuildOutputRoot)\\bin\\$(Configuration)-x64\\profiler\\src\\ProfilerEngine\\Datadog.Profiler.Native.Windows\\Datadog.Profiler.Native.dll",
         "COR_PROFILER_PATH_32": "$(BuildOutputRoot)\\bin\\$(Configuration)-x86\\profiler\\src\\ProfilerEngine\\Datadog.Profiler.Native.Windows\\Datadog.Profiler.Native.dll",
-
         "CORECLR_ENABLE_PROFILING": "1",
         "CORECLR_PROFILER": "{BD1A650D-AC5D-4896-B64F-D6FA25D6B26A}",
         "CORECLR_PROFILER_PATH_64": "$(BuildOutputRoot)\\bin\\$(Configuration)-x64\\profiler\\src\\ProfilerEngine\\Datadog.Profiler.Native.Windows\\Datadog.Profiler.Native.dll",
         "CORECLR_PROFILER_PATH_32": "$(BuildOutputRoot)\\bin\\$(Configuration)-x86\\profiler\\src\\ProfilerEngine\\Datadog.Profiler.Native.Windows\\Datadog.Profiler.Native.dll",
-
         "COMPlus_EnableDiagnostics": "1",
-
         "DD_PROFILING_ENABLED": "1",
         "DD_INTERNAL_PROFILING_ETW_ENABLED": "1",
         "DD_PROFILING_CPU_ENABLED": "1",
@@ -30,53 +27,49 @@
         "DD_PROFILING_ALLOCATION_ENABLED": "0",
         "DD_PROFILING_LOCK_ENABLED": "1",
         "DD_PROFILING_GC_ENABLED": "1",
-
         "DD_INTERNAL_PROFILING_DEBUG_INFO_ENABLED": "0",
         "DD_TRACE_DEBUG": "1",
         "DD_INTERNAL_PROFILING_OUTPUT_DIR": "$(PROGRAMDATA)\\Datadog-APM\\Pprof-files\\DotNet",
-
         "DD_ENV": "apm-profiling-local",
         "DD_SERVICE": "dd-dotnet-computer01-framework",
-
         "DD_INTERNAL_USE_DEVELOPMENT_CONFIGURATION": "true"
       },
       "nativeDebugging": true
     },
     "Tracer+Profiler": {
       "commandName": "Executable",
       "executablePath": "$(BaseOutputPath)\\$(ConfigBasedRelativeOutputPath)\\profiler\\src\\Demos\\Samples.Computer01\\$(TargetFramework)\\Samples.Computer01.exe",
-      "commandLineArgs": "--scenario 10 --threads 4 --param 250",
+      "commandLineArgs": "--scenario 13 --iterations 2 --param 1500",
       "environmentVariables": {
         "COR_ENABLE_PROFILING": "1",
         "COR_PROFILER": "{846F5F1C-F9AE-4B07-969E-05C26BC060D8}",
-
         "CORECLR_ENABLE_PROFILING": "1",
         "CORECLR_PROFILER": "{846F5F1C-F9AE-4B07-969E-05C26BC060D8}",
-
         "COMPlus_EnableDiagnostics": "1",
-
-        "DOTNET_gcServer": "0",
+        "DOTNET_gcServer": "1",
         "DOTNET_gcConcurrent": "1",
 
+        "DD_PROFILING_MANAGED_ACTIVATION_ENABLED": "0",
         "DD_PROFILING_ENABLED": "1",
         "DD_INTERNAL_PROFILING_ETW_ENABLED": "1",
         "DD_PROFILING_CPU_ENABLED": "1",
-        "DD_PROFILING_WALLTIME_ENABLED": "0",
-        "DD_PROFILING_EXCEPTION_ENABLED": "0",
-        "DD_PROFILING_ALLOCATION_ENABLED": "0",
+        "DD_PROFILING_WALLTIME_ENABLED": "1",
+        "DD_PROFILING_EXCEPTION_ENABLED": "1",
+        "DD_PROFILING_ALLOCATION_ENABLED": "1",
         "DD_PROFILING_LOCK_ENABLED": "1",
         "DD_PROFILING_GC_ENABLED": "1",
+        "DD_PROFILING_HEAPSNAPSHOT_ENABLED": "1",
+        "DD_INTERNAL_PROFILING_HEAPSNAPSHOT_MEMORY_PRESSURE_THRESHOLD": "0",
 
         "DD_INTERNAL_PROFILING_DEBUG_INFO_ENABLED": "0",
-        "DD_TRACE_DEBUG": "1",
         "DD_INTERNAL_PROFILING_OUTPUT_DIR": "$(PROGRAMDATA)\\Datadog-APM\\Pprof-files\\DotNet",
-
         "DD_ENV": "apm-profiling-local",
-        "DD_SERVICE": "dd-dotnet-computer01-gc",
+        "DD_SERVICE": "dd-dotnet-computer01-classhistogram",
 
+        "DD_TRACE_DEBUG": "1",
         "DD_INTERNAL_USE_DEVELOPMENT_CONFIGURATION": "true"
       },
-      "nativeDebugging": true
+      "nativeDebugging": false
     }
   }
-}
+}

profiler/src/ProfilerEngine/Datadog.Profiler.Native.Windows/EtwEventsManager.cpp

@@ -39,7 +39,9 @@ EtwEventsManager::EtwEventsManager(
     _parser = std::make_unique<ClrEventsParser>(
         nullptr,  // to avoid duplicates with what is done in EtwEventsHandler
         nullptr,  // to avoid duplicates with what is done in EtwEventsHandler
-        pGCSuspensionsListener);
+        pGCSuspensionsListener,
+        nullptr // no GC dump for .NET Framework (TODO: how to trigger it from ETW?)
+        );
     _logger = std::make_unique<ProfilerLogger>();
     _IpcClient = nullptr;
     _IpcServer = nullptr;

profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.cpp

@@ -41,11 +41,13 @@ void ClrEventsParser::LogGcEvent(
 ClrEventsParser::ClrEventsParser(
     IAllocationsListener* pAllocationListener,
     IContentionListener* pContentionListener,
-    IGCSuspensionsListener* pGCSuspensionsListener)
+    IGCSuspensionsListener* pGCSuspensionsListener,
+    IGCDumpListener* pGCDumpListener)
     :
     _pAllocationListener{pAllocationListener},
     _pContentionListener{pContentionListener},
-    _pGCSuspensionsListener{pGCSuspensionsListener}
+    _pGCSuspensionsListener{pGCSuspensionsListener},
+    _pGCDumpListener{pGCDumpListener}
 {
     ResetGC(_gcInProgress);
     ResetGC(_currentBGC);
@@ -69,7 +71,10 @@ void ClrEventsParser::ParseEvent(
     ULONG cbEventData,
     LPCBYTE eventData)
 {
-    if (KEYWORD_GC == (keywords & KEYWORD_GC))
+    if (
+        (KEYWORD_GC == (keywords & KEYWORD_GC)) ||
+        (KEYWORD_GCHEAPDUMP == (keywords & KEYWORD_GCHEAPDUMP))  // GCBulkXXX events are treated as GC events
+        )
     {
         ParseGcEvent(timestamp, id, version, cbEventData, eventData);
     }
@@ -242,6 +247,49 @@ ClrEventsParser::ParseGcEvent(std::chrono::nanoseconds timestamp, DWORD id, DWOR
         return;
     }
 
+    // GC dump related events
+    if (id == EVENT_GC_BULK_NODE)
+    {
+        // TODO: get the list of objects in the GC heap dump
+        LogGcEvent("OnGCBulkNode");
+
+        if (_pGCDumpListener != nullptr)
+        {
+            GCBulkNodePayload payload{0};
+            ULONG offset = 0;
+            if (!EventsParserHelper::Read<GCBulkNodePayload>(payload, pEventData, cbEventData, offset))
+            {
+                // TODO: log and stop the dump?
+                return;
+            }
+
+            // sanity check
+            _pGCDumpListener->OnBulkNodes(
+                payload.Index,
+                payload.Count,
+                (GCBulkNodeValue*)(pEventData + offset));
+        }
+    }
+    else if (id == EVENT_GC_BULK_EDGE)
+    {
+        // TODO: get the list of references between objects in the GC heap dump
+        LogGcEvent("OnGCBulkEdge");
+
+        if (_pGCDumpListener != nullptr)
+        {
+            // TODO: _pGCDumpListener->OnGCBulkEdge(...);
+            GCBulkEdgePayload payload{0};
+            ULONG offset = 0;
+            if (!EventsParserHelper::Read<GCBulkEdgePayload>(payload, pEventData, cbEventData, offset))
+            {
+                _pGCDumpListener->OnBulkEdges(
+                    payload.Index,
+                    payload.Count,
+                    (GCBulkEdgeValue*)(pEventData + offset));
+            }
+        }
+    }
+
     // the rest of events are related to garbage collections lifetime
     // read https://medium.com/criteo-engineering/spying-on-net-garbage-collector-with-net-core-eventpipes-9f2a986d5705?source=friends_link&sk=baf9a7766fb5c7899b781f016803597f
     // for more details about the state machine
@@ -480,11 +528,12 @@ void ClrEventsParser::NotifyGarbageCollectionEnd(
     std::chrono::nanoseconds endTimestamp,
     uint64_t gen2Size,
     uint64_t lohSize,
-    uint64_t pohSize)
+    uint64_t pohSize,
+    uint32_t memPressure)
 {
     for (auto& pGarbageCollectionsListener : _pGarbageCollectionsListeners)
     {
-        LogGcEvent("OnGarbageCollectionEnd: ", number, " ", generation, " ", reason, " ", type);
+        LogGcEvent("OnGarbageCollectionEnd: #", number, " gen", generation, " ", reason, " ", type, " ", memPressure, "%");
 
         pGarbageCollectionsListener->OnGarbageCollectionEnd(
             number,
@@ -497,7 +546,8 @@ void ClrEventsParser::NotifyGarbageCollectionEnd(
             endTimestamp,
             gen2Size,
             lohSize,
-            pohSize);
+            pohSize,
+            memPressure);
     }
 }
 
@@ -525,6 +575,7 @@ void ClrEventsParser::ResetGC(GCDetails& gc)
     gc.gen2Size = 0;
     gc.lohSize = 0;
     gc.pohSize = 0;
+    gc.memPressure = 0;
 }
 
 void ClrEventsParser::InitializeGC(std::chrono::nanoseconds timestamp, GCDetails& gc, GCStartPayload& payload)
@@ -541,6 +592,7 @@ void ClrEventsParser::InitializeGC(std::chrono::nanoseconds timestamp, GCDetails
     gc.gen2Size = 0;
     gc.lohSize = 0;
     gc.pohSize = 0;
+    gc.memPressure = 0;
 }
 
 void ClrEventsParser::OnGCTriggered()
@@ -623,7 +675,8 @@ void ClrEventsParser::OnGCRestartEEEnd(std::chrono::nanoseconds timestamp)
             timestamp,
             gc.gen2Size,
             gc.lohSize,
-            gc.pohSize);
+            gc.pohSize,
+            gc.memPressure);
         ResetGC(gc);
     }
 }
@@ -641,7 +694,6 @@ void ClrEventsParser::OnGCHeapStats(std::chrono::nanoseconds timestamp, uint64_t
     gc.gen2Size = gen2Size;
     gc.lohSize = lohSize;
     gc.pohSize = pohSize;
-
     if (gc.HasGlobalHeapHistoryBeenReceived && (gc.Generation == 2) && (gc.Type == GCType::BackgroundGC))
     {
         auto duration = std::chrono::duration_cast<std::chrono::milliseconds>(timestamp - gc.StartTimestamp).count();
@@ -658,7 +710,8 @@ void ClrEventsParser::OnGCHeapStats(std::chrono::nanoseconds timestamp, uint64_t
             timestamp,
             gc.gen2Size,
             gc.lohSize,
-            gc.pohSize);
+            gc.pohSize,
+            gc.memPressure);
         ResetGC(gc);
     }
 }
@@ -673,6 +726,7 @@ void ClrEventsParser::OnGCGlobalHeapHistory(std::chrono::nanoseconds timestamp,
         return;
     }
     gc.HasGlobalHeapHistoryBeenReceived = true;
+    gc.memPressure = payload.MemPressure;
 
     // check if the collection was compacting
     gc.IsCompacting =
@@ -694,7 +748,8 @@ void ClrEventsParser::OnGCGlobalHeapHistory(std::chrono::nanoseconds timestamp,
             timestamp,
             gc.gen2Size,
             gc.lohSize,
-            gc.pohSize);
+            gc.pohSize,
+            payload.MemPressure);
         ResetGC(gc);
     }
 }

profiler/src/ProfilerEngine/Datadog.Profiler.Native/ClrEventsParser.h

@@ -19,6 +19,7 @@
 #include "IAllocationsListener.h"
 #include "IGarbageCollectionsListener.h"
 #include "IGCSuspensionsListener.h"
+#include "IGCDumpListener.h"
 
 #include "../../../../shared/src/native-src/string.h"
 #include "assert.h"
@@ -50,6 +51,9 @@ const int EVENT_GC_PINOBJECTATGCTIME = 33;
 
 const int EVENT_SW_STACK = 82;
 
+// events sent during heap dumps
+const int EVENT_GC_BULK_NODE = 18;
+const int EVENT_GC_BULK_EDGE = 19;
 
 
 #define LONG_LENGTH 1024
@@ -233,6 +237,9 @@ struct GCGlobalHeapPayload
     uint32_t Gen0ReductionCount;
     uint32_t Reason;
     uint32_t GlobalMechanisms;
+    uint16_t ClrInstanceID;
+    uint32_t PauseMode;
+    uint32_t MemPressure;
 };
 
 struct WaitHandleWaitStartPayload // for .NET 9+
@@ -246,8 +253,40 @@ struct WaitHandleWaitStopPayload // for .NET 9+
 {
     uint16_t ClrInstanceId;    // Unique ID for the instance of CLR.
 };
+
+//struct GCBulkNodeValue
+//{
+//    uintptr_t Address;
+//    uint64_t Size;
+//    uint64_t TypeID;
+//    uint64_t EdgeCount;
+//};
+//struct GCBulkNodePayload
+//{
+//    uint32_t Index;
+//    uint32_t Count;
+//    uint16_t ClrInstanceID;
+//
+//    // this is followed by an array of Count GCBulkNodeValue structures
+//};
+//
+//struct GCBulkEdgeValue
+//{
+//    uintptr_t Value;
+//    uint32_t ReferencingFieldID;
+//};
+//struct GCBulkEdgePayload
+//{
+//    uint32_t Index;
+//    uint32_t Count;
+//    uint16_t ClrInstanceID;
+//
+//    // this is followed by an array of Count GCBulkEdgeValue structures
+//};
+
 #pragma pack()
 
+
 class IContentionListener;
 
 
@@ -264,6 +303,7 @@ struct GCDetails
     uint64_t gen2Size;
     uint64_t lohSize;
     uint64_t pohSize;
+    uint32_t memPressure;
 
     // GlobalHeapHistory and HeapStats events are not received in the same order
     // between Framework and CoreCLR. So we need to keep track of what has been received
@@ -276,17 +316,18 @@ class ClrEventsParser
 public:
     static const int64_t KEYWORD_GC =                             0x1;
     static const int64_t KEYWORD_CONTENTION =                  0x4000;
+    static const int64_t KEYWORD_GCHEAPDUMP =                0x100000; // for gcdump
     static const int64_t KEYWORD_WAITHANDLE =           0x40000000000; // .NET 9+ only
     static const int64_t KEYWORD_ALLOCATION_SAMPLING =  0x80000000000; // .NET 10+ only
 
 public:
     ClrEventsParser(
         IAllocationsListener* pAllocationListener,
         IContentionListener* pContentionListener,
-        IGCSuspensionsListener* pGCSuspensionsListener
+        IGCSuspensionsListener* pGCSuspensionsListener,
+        IGCDumpListener* pGCDumpListener
         );
 
-
     // the parser is used both for synchronous (ICorProfilerCallback) and
     // asynchronous (.NET Framework via the Agent) cases. The timestamp parameter
     // is only valid (different from 0) in the asynchronous scenario.
@@ -335,7 +376,8 @@ class ClrEventsParser
         std::chrono::nanoseconds endTimestamp,
         uint64_t gen2Size,
         uint64_t lohSize,
-        uint64_t pohSize
+        uint64_t pohSize,
+        uint32_t memPressure
         );
     GCDetails& GetCurrentGC();
     void InitializeGC(std::chrono::nanoseconds timestamp, GCDetails& gc, GCStartPayload& payload);
@@ -346,6 +388,7 @@ class ClrEventsParser
     IContentionListener* _pContentionListener = nullptr;
     IGCSuspensionsListener* _pGCSuspensionsListener = nullptr;
     std::vector<IGarbageCollectionsListener*> _pGarbageCollectionsListeners;
+    IGCDumpListener* _pGCDumpListener = nullptr;
 
     template <typename... Args>
     void LogGcEvent(Args const&... args);