Add information about heap reserved memory and generations to tracelog

diff --git a/README.md b/README.md
index b767093..fdec13d 100644 (file)
--- a/README.md
+++ b/README.md
@@ -143,6 +143,10 @@ dumped (only timestamp of execution and configuration parameters is stored).
     option can be turned on or off manually. `PROF_GC_TRACE` is defaulted to
     `false`.
 
+      - `PROF_GC_TRACE_GEN` - enables tracking of generation bounds for each
+        GC invocation. This option provides records containing information about
+        memory consuption of each generation including reserved memory.
+
       - `PROF_GC_TRACE_ALT` - enables tracking of 'Heap Allocation Tables'
         for each GC invocation. Heap Allocation Table is set of records
         containing information about objects count and summary memory usage for

diff --git a/doc/tracelog-format.md b/doc/tracelog-format.md
index f152542..c137738 100644 (file)
--- a/doc/tracelog-format.md
+++ b/doc/tracelog-format.md
@@ -37,6 +37,7 @@ This document describes format of the performance data dumped by CoreProfiler.
 - [GC records](#gc-records)
   - [Garbage Collection Started: `gch gcs`](#garbage-collection-started-gch-gcs)
   - [Garbage Collection Finished: `gch gcf`](#garbage-collection-finished-gch-gcf)
+  - [GC Generation Bounds: `gch gen`](#gc-generation-bounds-gch-gen)
   - [GC Heap Allocation Table: `gch alt`](#gc-heap-allocation-table-gch-alt)
 - [Sample records](#sample-records)
   - [Stack Trace Sample: `sam str`](#stack-trace-sample-sam-str)
@@ -76,6 +77,7 @@ click) used in tables to avoid parser problems. -->
 | `<id>`         | `<hex64>`                                              | Profiling API ID                                                                  |
 | `<iid>`        | `<hex32>∣?`                                            | Internal CoreProfiler ID, `?` if undefined                                        |
 | `<code_info>`  | `<start_addr:hex64>:<size:hex>`                        | Item of Code Info table                                                           |
+| `<gen_range>`  | `<gen:str>:<length:num>:<lengthReserved:num>`          | Single generation description                                                     |
 | `<il_map>`     | `<ilOffset:hex>:<nativeStart:hex>:<nativeEnd:hex>`     | Item of IL mapping table                                                          |
 | `<alt_item>`   | `<classIid:hex>:<allocCount:num>:<memSize:num>`        | Item of GC allocation table                                                       |
 | `<frame>`      | `<functionIid:iid>[:<ip>]`                             | Call stack frame                                                                  |
@@ -394,6 +396,18 @@ Notifies that garbage collection has completed.
 * `osThreadId` - the PID of the operating system thread running GC.
 * `timestamp` - the event timestamp in milliseconds from the start of profiling.
 
+### GC Generation Bounds: `gch gen`
+
+```
+gch gen <timestamp:ms> <gen_range>...
+```
+
+* `timestamp` - the event timestamp in milliseconds from the start of profiling.
+* `gen_range` - description of all heap generations.
+  * `gen` - name of the generation (`g0`, `g1`, `g2`, `loh` or `?`).
+  * `length` - the size of the used portion of the memory block.
+  * `lengthReserved` - the total size of the memory block.
+
 ### GC Heap Allocation Table: `gch alt`
 
 ```

diff --git a/src/config/configurationmanager.cpp b/src/config/configurationmanager.cpp
index 4af1559..ec22443 100644 (file)
--- a/src/config/configurationmanager.cpp
+++ b/src/config/configurationmanager.cpp
@@ -183,9 +183,11 @@ void ConfigurationManager::FetchConfig(ProfilerConfig &config) const
     bool GcTraceEnabled;
     if (FetchValue("PROF_GC_TRACE", GcTraceEnabled))
     {
+        new_config.GcGenerationBoundsTraceEnabled = GcTraceEnabled;
         new_config.GcAllocTableTraceEnabled = GcTraceEnabled;
     }
-    FetchValue("PROF_GC_TRACE_ALT",     new_config.GcAllocTableTraceEnabled);
+    FetchValue("PROF_GC_TRACE_GEN", new_config.GcGenerationBoundsTraceEnabled);
+    FetchValue("PROF_GC_TRACE_ALT", new_config.GcAllocTableTraceEnabled);
 
     // Apply changes to the current configuration.
     config = new_config;

diff --git a/src/config/profilerconfig.cpp b/src/config/profilerconfig.cpp
index 9dcdeb0..795e870 100644 (file)
--- a/src/config/profilerconfig.cpp
+++ b/src/config/profilerconfig.cpp
@@ -34,6 +34,7 @@ ProfilerConfig::ProfilerConfig()
     , ExecutionTraceEnabled(false)
     , MemoryTraceEnabled(false)
     , StackTrackingEnabled(false)
+    , GcGenerationBoundsTraceEnabled(false)
     , GcAllocTableTraceEnabled(false)
 {}
 
@@ -138,6 +139,12 @@ std::vector<std::string> ProfilerConfig::Verify()
             warnings.push_back("stack tracking is memory tracing option");
         }
 
+        if (GcGenerationBoundsTraceEnabled)
+        {
+            warnings.push_back(
+                "GC generation bounds tracing is memory tracing option");
+        }
+
         if (GcAllocTableTraceEnabled)
         {
             warnings.push_back(

diff --git a/src/config/profilerconfig.h b/src/config/profilerconfig.h
index 87d9241..e44c7aa 100644 (file)
--- a/src/config/profilerconfig.h
+++ b/src/config/profilerconfig.h
@@ -72,6 +72,7 @@ struct ProfilerConfig
 
     bool             MemoryTraceEnabled;
     bool             StackTrackingEnabled;
+    bool             GcGenerationBoundsTraceEnabled;
     bool             GcAllocTableTraceEnabled;
 
     //

diff --git a/src/trace/memorytrace.cpp b/src/trace/memorytrace.cpp
index 88bd978..46cd045 100644 (file)
--- a/src/trace/memorytrace.cpp
+++ b/src/trace/memorytrace.cpp
@@ -15,6 +15,7 @@
  */
 
 #include <algorithm>
+#include <vector>
 
 #include "memorytrace.h"
 
@@ -95,6 +96,42 @@ void MemoryTrace::Shutdown() noexcept
     m_disabled = true;
 }
 
+HRESULT MemoryTrace::DumpGenerationBounds() noexcept
+{
+    if (!m_profiler.GetConfig().GcGenerationBoundsTraceEnabled)
+        return S_OK;
+
+    HRESULT hr = S_OK;
+    try
+    {
+        std::vector<COR_PRF_GC_GENERATION_RANGE> ranges;
+        ULONG rangesSize;
+        hr = m_info.v2()->GetGenerationBounds(0, &rangesSize, nullptr);
+        if (SUCCEEDED(hr))
+        {
+            ranges.resize(rangesSize);
+            hr = m_info.v2()->GetGenerationBounds(
+                rangesSize, &rangesSize, ranges.data());
+        }
+        if (FAILED(hr))
+        {
+            throw HresultException(
+                "MemoryTrace::DumpGenerationBounds(): "
+                "GetGenerationBounds()", hr
+            );
+        }
+
+        DWORD ticks = m_profiler.GetTickCountFromInit();
+        TRACE().DumpGenerationBounds(ticks, ranges);
+    }
+    catch (const std::exception &e)
+    {
+        hr = m_profiler.HandleException(e);
+    }
+
+    return hr;
+}
+
 HRESULT MemoryTrace::InitAllocInfoByTypes(AllocTable &allocInfoByTypes) noexcept
 {
     HRESULT hr = S_OK;
@@ -214,6 +251,23 @@ HRESULT MemoryTrace::GarbageCollectionStarted(
     if (m_disabled)
         return S_OK;
 
+    HRESULT hrReturn = S_OK;
+    HRESULT hr = S_OK;
+
+    //
+    // GC Generation Bounds Tracing
+    //
+
+    hr = this->DumpGenerationBounds();
+    if (FAILED(hr) && SUCCEEDED(hrReturn))
+    {
+        hrReturn = hr;
+    }
+
+    //
+    // GC Allocations Table Tracing
+    //
+
     _ASSERTE(m_survivedObjects.empty());
 
     // Reset object tracking transaction members.
@@ -222,7 +276,7 @@ HRESULT MemoryTrace::GarbageCollectionStarted(
         m_profiler.GetCommonTrace().IsSamplingSuspended();
     m_objectTrackingFailure = false;
 
-    return S_OK;
+    return hrReturn;
 }
 
 HRESULT MemoryTrace::ObjectReferences(
@@ -236,18 +290,18 @@ HRESULT MemoryTrace::ObjectReferences(
     if (m_disabled)
         return E_FAIL;
 
-    if (m_objectTrackingSuspended)
-        return E_FAIL;
-
-    if (m_objectTrackingFailure)
-        return E_FAIL;
-
     HRESULT hr = E_FAIL;
 
     //
     // GC Allocations Table Tracing
     //
 
+    if (m_objectTrackingSuspended)
+        return E_FAIL;
+
+    if (m_objectTrackingFailure)
+        return E_FAIL;
+
     if (m_profiler.GetConfig().GcAllocTableTraceEnabled)
     {
         hr = S_OK;
@@ -287,6 +341,23 @@ HRESULT MemoryTrace::GarbageCollectionFinished() noexcept
     if (m_disabled)
         return S_OK;
 
+    HRESULT hrReturn = S_OK;
+    HRESULT hr = S_OK;
+
+    //
+    // GC Generation Bounds Tracing
+    //
+
+    hr = this->DumpGenerationBounds();
+    if (FAILED(hr) && SUCCEEDED(hrReturn))
+    {
+        hrReturn = hr;
+    }
+
+    //
+    // GC Allocations Table Tracing
+    //
+
     // Check transaction is not suspended.
     if (m_objectTrackingSuspended)
         return S_OK;
@@ -295,12 +366,6 @@ HRESULT MemoryTrace::GarbageCollectionFinished() noexcept
     if (m_objectTrackingFailure)
         return S_OK;
 
-    HRESULT hr = S_OK;
-
-    //
-    // GC Allocations Table Tracing
-    //
-
     if (m_profiler.GetConfig().GcAllocTableTraceEnabled)
     {
         try
@@ -319,9 +384,13 @@ HRESULT MemoryTrace::GarbageCollectionFinished() noexcept
         {
             hr = m_profiler.HandleException(e);
         }
+        if (FAILED(hr) && SUCCEEDED(hrReturn))
+        {
+            hrReturn = hr;
+        }
 
         m_survivedObjects.clear();
     }
 
-    return hr;
+    return hrReturn;
 }

diff --git a/src/trace/memorytrace.h b/src/trace/memorytrace.h
index e76587a..d9c9b0a 100644 (file)
--- a/src/trace/memorytrace.h
+++ b/src/trace/memorytrace.h
@@ -51,6 +51,8 @@ public:
     //     ThreadInfo &thrInfo, SamplingSharedState &state) noexcept;
 
 private:
+    HRESULT DumpGenerationBounds() noexcept;
+
     HRESULT InitAllocInfoByTypes(AllocTable &allocInfoByTypes) noexcept;
 
 public:

diff --git a/src/tracelog/tracefmt.h b/src/tracelog/tracefmt.h
index 8df70f5..ab9b4d0 100644 (file)
--- a/src/tracelog/tracefmt.h
+++ b/src/tracelog/tracefmt.h
@@ -153,6 +153,23 @@ private:
             }
         }
 
+        record& str(COR_PRF_GC_GENERATION generation)
+        {
+            switch (generation)
+            {
+            case COR_PRF_GC_GEN_0:
+                return str("g0");
+            case COR_PRF_GC_GEN_1:
+                return str("g1");
+            case COR_PRF_GC_GEN_2:
+                return str("g2");
+            case COR_PRF_GC_LARGE_OBJECT_HEAP:
+                return str("loh");
+            default:
+                return str('?');
+            }
+        }
+
         template<typename T>
         record& qtn(T&& value)
         {
@@ -314,6 +331,14 @@ private:
             return *this;
         }
 
+        record& gen_range(const COR_PRF_GC_GENERATION_RANGE& r)
+        {
+            grps(':');
+            str(r.generation).num(r.rangeLength).num(r.rangeLengthReserved);
+            grpe();
+            return *this;
+        }
+
         record& alt_item(InternalID classIid, AllocInfo allocInfo)
         {
             grps(':');

diff --git a/src/tracelog/tracelog.cpp b/src/tracelog/tracelog.cpp
index 6773461..2a6cd85 100644 (file)
--- a/src/tracelog/tracelog.cpp
+++ b/src/tracelog/tracelog.cpp
@@ -336,6 +336,18 @@ public:
         m_tracefmt.log("gch gcf").pid(osThreadId).ms(timestamp);
     }
 
+    virtual void DumpGenerationBounds(
+        DWORD               timestamp,
+        const std::vector<COR_PRF_GC_GENERATION_RANGE>  &ranges) override
+    {
+        auto log = m_tracefmt.log("gch gen");
+        log.ms(timestamp);
+        for (const auto &range : ranges)
+        {
+            log.gen_range(range);
+        }
+    }
+
     virtual void DumpGcHeapAllocTable(
         DWORD               timestamp,
         const AllocTable    &allocInfoByTypes) override

diff --git a/src/tracelog/tracelog.h b/src/tracelog/tracelog.h
index cc8ab26..a34d922 100644 (file)
--- a/src/tracelog/tracelog.h
+++ b/src/tracelog/tracelog.h
@@ -193,6 +193,10 @@ public:
         DWORD       osThreadId,
         DWORD       timestamp) = 0;
 
+    virtual void DumpGenerationBounds(
+        DWORD               timestamp,
+        const std::vector<COR_PRF_GC_GENERATION_RANGE>  &ranges) = 0;
+
     virtual void DumpGcHeapAllocTable(
         DWORD               timestamp,
         const AllocTable    &allocInfoByTypes) = 0;