From: Alexey Vereschagin Date: Fri, 20 Jul 2018 11:29:09 +0000 (+0000) Subject: Add information about heap reserved memory and generations to tracelog X-Git-Tag: submit/tizen/20180820.164546~1 X-Git-Url: http://review.tizen.org/git/?a=commitdiff_plain;h=b96fa15396bdc8a2b733603818aed0a7a69aec4e;p=sdk%2Ftools%2Fcoreprofiler.git Add information about heap reserved memory and generations to tracelog --- diff --git a/README.md b/README.md index b767093..fdec13d 100644 --- 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 --- 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. --> | `` | `` | Profiling API ID | | `` | `∣?` | Internal CoreProfiler ID, `?` if undefined | | `` | `:` | Item of Code Info table | +| `` | `::` | Single generation description | | `` | `::` | Item of IL mapping table | | `` | `::` | Item of GC allocation table | | `` | `[:]` | 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` - 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 --- 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 --- 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 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 --- 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 --- a/src/trace/memorytrace.cpp +++ b/src/trace/memorytrace.cpp @@ -15,6 +15,7 @@ */ #include +#include #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 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 --- 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 --- 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 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 --- 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 &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 --- 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 &ranges) = 0; + virtual void DumpGcHeapAllocTable( DWORD timestamp, const AllocTable &allocInfoByTypes) = 0;