Recording the reason why we change the generation to condemn during j…

…oined_generation_to_condemn() to the event stream (#1042)
dotnet · Jan 17, 2020 · 631cb1b · 631cb1b
1 parent 8b94a3f
commit 631cb1b
Show file tree

Hide file tree

Showing 9 changed files with 125 additions and 28 deletions.
diff --git a/src/coreclr/src/gc/env/etmdummy.h b/src/coreclr/src/gc/env/etmdummy.h
@@ -163,7 +163,7 @@
 #define FireEtwGCMarkWithType(HeapNum, ClrInstanceID, Type, Bytes) 0
 #define FireEtwGCJoin_V2(Heap, JoinTime, JoinType, ClrInstanceID, JoinID) 0
 #define FireEtwGCPerHeapHistory_V3(ClrInstanceID, FreeListAllocated, FreeListRejected, EndOfSegAllocated, CondemnedAllocated, PinnedAllocated, PinnedAllocatedAdvance, RunningFreeListEfficiency, CondemnReasons0, CondemnReasons1, CompactMechanisms, ExpandMechanisms, HeapIndex, ExtraGen0Commit, Count, Values_Len_, Values) 0
-#define FireEtwGCGlobalHeapHistory_V2(FinalYoungestDesired, NumHeaps, CondemnedGeneration, Gen0ReductionCount, Reason, GlobalMechanisms, ClrInstanceID, PauseMode, MemoryPressure) 0
+#define FireEtwGCGlobalHeapHistory_V3(FinalYoungestDesired, NumHeaps, CondemnedGeneration, Gen0ReductionCount, Reason, GlobalMechanisms, ClrInstanceID, PauseMode, MemoryPressure, CondemnReasons0, CondemnReasons1) 0
 #define FireEtwDebugIPCEventStart() 0
 #define FireEtwDebugIPCEventEnd() 0
 #define FireEtwDebugExceptionProcessingStart() 0

diff --git a/src/coreclr/src/gc/gc.cpp b/src/coreclr/src/gc/gc.cpp
@@ -2608,6 +2608,8 @@ GCEvent     gc_heap::bgc_start_event;
 
 gc_mechanisms gc_heap::saved_bgc_settings;
 
+gc_history_global gc_heap::bgc_data_global;
+
 GCEvent     gc_heap::background_gc_done_event;
 
 GCEvent     gc_heap::ee_proceed_event;
@@ -3190,18 +3192,22 @@ void gc_heap::fire_per_heap_hist_event (gc_history_per_heap* current_gc_data_per
 
 void gc_heap::fire_pevents()
 {
-    settings.record (&gc_data_global);
-    gc_data_global.print();
+    gc_history_global* current_gc_data_global = get_gc_data_global();
+
+    settings.record (current_gc_data_global);
+    current_gc_data_global->print();
 
-    FIRE_EVENT(GCGlobalHeapHistory_V2,
-               gc_data_global.final_youngest_desired,
-               gc_data_global.num_heaps,
-               gc_data_global.condemned_generation,
-               gc_data_global.gen0_reduction_count,
-               gc_data_global.reason,
-               gc_data_global.global_mechanisms_p,
-               gc_data_global.pause_mode,
-               gc_data_global.mem_pressure);
+    FIRE_EVENT(GCGlobalHeapHistory_V3,
+               current_gc_data_global->final_youngest_desired,
+               current_gc_data_global->num_heaps,
+               current_gc_data_global->condemned_generation,
+               current_gc_data_global->gen0_reduction_count,
+               current_gc_data_global->reason,
+               current_gc_data_global->global_mechanisms_p,
+               current_gc_data_global->pause_mode,
+               current_gc_data_global->mem_pressure,
+               current_gc_data_global->gen_to_condemn_reasons.get_reasons0(),
+               current_gc_data_global->gen_to_condemn_reasons.get_reasons1());
 
 #ifdef MULTIPLE_HEAPS
     for (int i = 0; i < gc_heap::n_heaps; i++)
@@ -15513,6 +15519,7 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
                                            BOOL* blocking_collection_p
                                            STRESS_HEAP_ARG(int n_original))
 {
+    gc_data_global.gen_to_condemn_reasons.init();
 #ifdef BGC_SERVO_TUNING
     if (settings.entry_memory_load == 0)
     {
@@ -15562,6 +15569,7 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
             else
             {
                 n = max_generation - 1;
+                gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_avoid_unproductive);
                 settings.elevation_reduced = TRUE;
             }
         }
@@ -15586,6 +15594,14 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
             // where foreground GCs are asking for a compacting full GC right away
             // and not getting it.
             dprintf (GTC_LOG, ("full GC induced, not reducing gen"));
+            if (initial_gen == max_generation)
+            {
+                gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_pm_induced_fullgc_p);
+            }
+            else
+            {
+                gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_pm_alloc_loh);
+            }
             *blocking_collection_p = TRUE;
         }
         else if (should_expand_in_full_gc || joined_last_gc_before_oom)
@@ -15596,6 +15612,7 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
         else
         {
             dprintf (GTC_LOG, ("reducing gen in PM: %d->%d->%d", initial_gen, n, (max_generation - 1)));
+            gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_last_gen2_fragmented);
             n = max_generation - 1;
         }
     }
@@ -15617,6 +15634,7 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
 
         if (joined_last_gc_before_oom)
         {
+            gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_limit_before_oom);
             full_compact_gc_p = true;
         }
         else if ((current_total_committed * 10) >= (heap_hard_limit * 9))
@@ -15627,13 +15645,15 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
             if ((loh_frag * 8) >= heap_hard_limit)
             {
                 dprintf (GTC_LOG, ("loh frag: %Id > 1/8 of limit %Id", loh_frag, (heap_hard_limit / 8)));
+                gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_limit_loh_frag);
                 full_compact_gc_p = true;
             }
             else
             {
                 // If there's not much fragmentation but it looks like it'll be productive to
                 // collect LOH, do that.
                 size_t est_loh_reclaim = get_total_gen_estimated_reclaim (max_generation + 1);
+                gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_limit_loh_reclaim);
                 full_compact_gc_p = ((est_loh_reclaim * 8) >= heap_hard_limit);
                 dprintf (GTC_LOG, ("loh est reclaim: %Id, 1/8 of limit %Id", est_loh_reclaim, (heap_hard_limit / 8)));
             }
@@ -15651,26 +15671,30 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
 #ifdef BGC_SERVO_TUNING
     if (bgc_tuning::should_trigger_ngc2())
     {
+        gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_servo_ngc);
         n = max_generation;
         *blocking_collection_p = TRUE;
     }
 
     if ((n < max_generation) && !recursive_gc_sync::background_running_p() &&
         bgc_tuning::stepping_trigger (settings.entry_memory_load, get_current_gc_index (max_generation)))
     {
+        gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_servo_initial);
         n = max_generation;
         saved_bgc_tuning_reason = reason_bgc_stepping;
     }
 
     if ((n < max_generation) && bgc_tuning::should_trigger_bgc())
     {
+        gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_servo_bgc);
         n = max_generation;
     }
 
     if (n == (max_generation - 1))
     {
         if (bgc_tuning::should_delay_alloc (max_generation))
         {
+            gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_servo_postpone);
             n -= 1;
         }
     }
@@ -15710,6 +15734,7 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
             // in gc stress, only escalate every 10th non-gen2 collection to a gen2...
             if ((current_gc_count % 10) == 0)
             {
+                gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_stress_mix);
                 n = max_generation;
             }
         }
@@ -15724,6 +15749,7 @@ int gc_heap::joined_generation_to_condemn (BOOL should_evaluate_elevation,
         else
 #endif // !FEATURE_REDHAWK
         {
+            gc_data_global.gen_to_condemn_reasons.set_condition(gen_joined_stress);
             n = max_generation;
         }
     }
@@ -18150,8 +18176,11 @@ void gc_heap::garbage_collect (int n)
             ((settings.pause_mode == pause_interactive) || (settings.pause_mode == pause_sustained_low_latency)))
         {
             keep_bgc_threads_p = TRUE;
-            c_write (settings.concurrent,  TRUE);
+            c_write (settings.concurrent, TRUE);
+            memset (&bgc_data_global, 0, sizeof(bgc_data_global));
+            memcpy (&bgc_data_global, &gc_data_global, sizeof(gc_data_global));
         }
+
 #endif //BACKGROUND_GC
 
         settings.gc_index = (uint32_t)dd_collection_count (dynamic_data_of (0)) + 1;
@@ -32839,6 +32868,16 @@ size_t gc_heap::joined_youngest_desired (size_t new_allocation)
 }
 #endif // BIT64
 
+inline
+gc_history_global* gc_heap::get_gc_data_global()
+{
+#ifdef BACKGROUND_GC
+    return (settings.concurrent ? &bgc_data_global : &gc_data_global);
+#else
+    return &gc_data_global;
+#endif //BACKGROUND_GC
+}
+
 inline
 gc_history_per_heap* gc_heap::get_gc_data_per_heap()
 {

diff --git a/src/coreclr/src/gc/gcevents.h b/src/coreclr/src/gc/gcevents.h
@@ -20,7 +20,7 @@ KNOWN_EVENT(GCTerminateConcurrentThread_V1, GCEventProvider_Default, GCEventLeve
 KNOWN_EVENT(GCTriggered, GCEventProvider_Default, GCEventLevel_Information, GCEventKeyword_GC)
 KNOWN_EVENT(GCMarkWithType, GCEventProvider_Default, GCEventLevel_Information, GCEventKeyword_GC)
 KNOWN_EVENT(GCJoin_V2, GCEventProvider_Default, GCEventLevel_Verbose, GCEventKeyword_GC)
-KNOWN_EVENT(GCGlobalHeapHistory_V2, GCEventProvider_Default, GCEventLevel_Information, GCEventKeyword_GC)
+KNOWN_EVENT(GCGlobalHeapHistory_V3, GCEventProvider_Default, GCEventLevel_Information, GCEventKeyword_GC)
 KNOWN_EVENT(GCAllocationTick_V1, GCEventProvider_Default, GCEventLevel_Verbose, GCEventKeyword_GC)
 KNOWN_EVENT(GCAllocationTick_V3, GCEventProvider_Default, GCEventLevel_Verbose, GCEventKeyword_GC)
 KNOWN_EVENT(PinObjectAtGCTime, GCEventProvider_Default, GCEventLevel_Verbose, GCEventKeyword_GC)

diff --git a/src/coreclr/src/gc/gcinterface.ee.h b/src/coreclr/src/gc/gcinterface.ee.h
@@ -87,14 +87,16 @@ class IGCToCLREventSink
     void FireGCJoin_V2(uint32_t heap, uint32_t joinTime, uint32_t joinType, uint32_t joinId) = 0;
 
     virtual
-    void FireGCGlobalHeapHistory_V2(uint64_t finalYoungestDesired,
+    void FireGCGlobalHeapHistory_V3(uint64_t finalYoungestDesired,
         int32_t numHeaps,
         uint32_t condemnedGeneration,
         uint32_t gen0reductionCount,
         uint32_t reason,
         uint32_t globalMechanisms,
         uint32_t pauseMode,
-        uint32_t memoryPressure) = 0;
+        uint32_t memoryPressure,
+        uint32_t condemnReasons0,
+        uint32_t condemnReasons1) = 0;
 
     virtual
     void FireGCAllocationTick_V1(uint32_t allocationAmount, uint32_t allocationKind) = 0;

diff --git a/src/coreclr/src/gc/gcpriv.h b/src/coreclr/src/gc/gcpriv.h
@@ -2910,6 +2910,8 @@ class gc_heap
     size_t  compute_in (int gen_number);
     PER_HEAP
     void compute_new_dynamic_data (int gen_number);
+    PER_HEAP_ISOLATED
+    gc_history_global* get_gc_data_global();
     PER_HEAP
     gc_history_per_heap* get_gc_data_per_heap();
     PER_HEAP
@@ -3027,9 +3029,6 @@ class gc_heap
     PER_HEAP_ISOLATED
     void recover_bgc_settings();
 
-    PER_HEAP
-    void save_bgc_data_per_heap();
-
     PER_HEAP
     BOOL should_commit_mark_array();
 
@@ -3640,6 +3639,9 @@ class gc_heap
     PER_HEAP_ISOLATED
     gc_mechanisms saved_bgc_settings;
 
+    PER_HEAP_ISOLATED
+    gc_history_global bgc_data_global;
+
     PER_HEAP
     gc_history_per_heap bgc_data_per_heap;
 

diff --git a/src/coreclr/src/gc/gcrecord.h b/src/coreclr/src/gc/gcrecord.h
@@ -61,12 +61,25 @@ enum gc_condemn_reason_condition
     gen_induced_noforce_p = 14,
     gen_before_bgc = 15,
     gen_almost_max_alloc = 16,
-    gcrc_max = 17
+    gen_joined_avoid_unproductive = 17,    /* This happens when the GC detects previous attempts to do a full compacting GC is not making progress and therefore reduce its generation */
+    gen_joined_pm_induced_fullgc_p = 18,   /* This happens when a full gc is induced under provisional mode */
+    gen_joined_pm_alloc_loh = 19,          /* This happens when a large object heap allocation is requested under provisional mode */
+    gen_joined_last_gen2_fragmented = 20,  /* This happens when we had a high memory and high fragmentation detected after the last full blocking GC, indicating we have lot of pinned objects in gen 2, so reducing its generation */
+    gen_joined_limit_before_oom = 21,      /* This happens when the last gc was oom */
+    gen_joined_limit_loh_frag = 22,        /* This happens when we had a heap limit and the fragmentation is reaching 1/8 of it */
+    gen_joined_limit_loh_reclaim = 23,     /* This happens when we had a heap limit and we could reclaim 1/8 of it */
+    gen_joined_servo_initial = 24,         /* This happen when the servo tuning is trying to get some initial data */
+    gen_joined_servo_ngc = 25,             /* This happen when the servo tuning decides a background gc is appropriate */
+    gen_joined_servo_bgc = 26,             /* This happen when the servo tuning decides a background gc is appropriate */
+    gen_joined_servo_postpone = 27,        /* This happen when the servo tuning decides a gen2 gc should be postponed */
+    gen_joined_stress_mix = 28,            /* This happen in GCStress mix mode, every 10th GC is gen2  */
+    gen_joined_stress = 29,                /* This happen in GCStress, every GC is gen2  */
+    gcrc_max = 30
 };
 
 #ifdef DT_LOG
 static char* record_condemn_reasons_gen_header = "[cg]i|f|a|t|";
-static char* record_condemn_reasons_condition_header = "[cc]i|e|h|v|l|l|e|m|m|m|m|g|o|s|n|b|a|";
+static char* record_condemn_reasons_condition_header = "[cc]i|e|h|v|l|l|e|m|m|m|m|g|o|s|n|b|a|1|2|3|4|5|6|7|8|9|0|a|b";
 static char char_gen_number[4] = {'0', '1', '2', '3'};
 #endif //DT_LOG
 
@@ -410,6 +423,7 @@ struct gc_history_global
     int pause_mode;
     uint32_t mem_pressure;
     uint32_t global_mechanisms_p;
+    gen_to_condemn_tuning gen_to_condemn_reasons;
 
     void set_mechanism_p (gc_global_mechanism_p mechanism)
     {

diff --git a/src/coreclr/src/vm/ClrEtwAll.man b/src/coreclr/src/vm/ClrEtwAll.man
@@ -1198,6 +1198,36 @@
                         </UserData>
                     </template>
 
+                    <template tid="GCGlobalHeap_V3">
+                        <data name="FinalYoungestDesired" inType="win:UInt64" outType="win:HexInt64" />
+                        <data name="NumHeaps" inType="win:Int32" />
+                        <data name="CondemnedGeneration" inType="win:UInt32" />
+                        <data name="Gen0ReductionCount" inType="win:UInt32" />
+                        <data name="Reason" inType="win:UInt32" />
+                        <data name="GlobalMechanisms" inType="win:UInt32" />
+                        <data name="ClrInstanceID" inType="win:UInt16" />
+                        <data name="PauseMode" inType="win:UInt32" />
+                        <data name="MemoryPressure" inType="win:UInt32" />
+                        <data name="CondemnReasons0" inType="win:UInt32" />
+                        <data name="CondemnReasons1" inType="win:UInt32" />
+
+                        <UserData>
+                            <GCGlobalHeap_V3 xmlns="myNs">
+                                <FinalYoungestDesired> %1 </FinalYoungestDesired>
+                                <NumHeaps> %2 </NumHeaps>
+                                <CondemnedGeneration> %3 </CondemnedGeneration>
+                                <Gen0ReductionCount> %4 </Gen0ReductionCount>
+                                <Reason> %5 </Reason>
+                                <GlobalMechanisms> %6 </GlobalMechanisms>
+                                <ClrInstanceID> %7 </ClrInstanceID>
+                                <PauseMode> %8 </PauseMode>
+                                <MemoryPressure> %9 </MemoryPressure>
+                                <CondemnReasons0> %10 </CondemnReasons0>
+                                <CondemnReasons1> %11 </CondemnReasons1>
+                            </GCGlobalHeap_V3>
+                        </UserData>
+                    </template>
+
                     <template tid="FinalizeObject">
                       <data name="TypeID" inType="win:Pointer" />
                       <data name="ObjectID" inType="win:Pointer" />
@@ -3566,6 +3596,11 @@
                            task="GarbageCollection"
                            symbol="GCGlobalHeapHistory_V2" message="$(string.RuntimePublisher.GCGlobalHeap_V2EventMessage)"/>
 
+                    <event value="205" version="3" level="win:Informational"  template="GCGlobalHeap_V3"
+                           keywords ="GCKeyword"  opcode="GCGlobalHeapHistory"
+                           task="GarbageCollection"
+                           symbol="GCGlobalHeapHistory_V3" message="$(string.RuntimePublisher.GCGlobalHeap_V3EventMessage)"/>
+
                     <!-- CLR Debugger events 240-249 -->
                     <event value="240" version="0" level="win:Informational"
                            keywords="DebuggerKeyword" opcode="win:Start"
@@ -4528,12 +4563,12 @@
                 </events>
             </provider>
 
+            <!-- CLR Stress Publisher-->
             <provider name="Microsoft-Windows-DotNETRuntimeStress"
                       guid="{CC2BCBBA-16B6-4cf3-8990-D74C2E8AF500}"
                       symbol="MICROSOFT_WINDOWS_DOTNETRUNTIME_STRESS_PROVIDER"
                       resourceFileName="%INSTALL_PATH%\clretwrc.dll"
                       messageFileName="%INSTALL_PATH%\clretwrc.dll">
-                <!-- CLR Stress Publisher-->
 
                 <!--Keywords-->
                 <keywords>
@@ -6759,6 +6794,7 @@
                 <string id="RuntimePublisher.GCJoin_V2EventMessage" value="Heap=%1;%nJoinTime=%2;%nJoinType=%3;%nClrInstanceID=%4;%nJoinID=%5"/>
                 <string id="RuntimePublisher.GCPerHeapHistory_V3EventMessage" value="ClrInstanceID=%1;%nFreeListAllocated=%2;%nFreeListRejected=%3;%nEndOfSegAllocated=%4;%nCondemnedAllocated=%5;%nPinnedAllocated=%6;%nPinnedAllocatedAdvance=%7;%RunningFreeListEfficiency=%8;%nCondemnReasons0=%9;%nCondemnReasons1=%10;%nCompactMechanisms=%11;%nExpandMechanisms=%12;%nHeapIndex=%13;%nExtraGen0Commit=%14;%nCount=%15"/>
                 <string id="RuntimePublisher.GCGlobalHeap_V2EventMessage" value="FinalYoungestDesired=%1;%nNumHeaps=%2;%nCondemnedGeneration=%3;%nGen0ReductionCountD=%4;%nReason=%5;%nGlobalMechanisms=%6;%nClrInstanceID=%7;%nPauseMode=%8;%nMemoryPressure=%9"/>
+                <string id="RuntimePublisher.GCGlobalHeap_V3EventMessage" value="FinalYoungestDesired=%1;%nNumHeaps=%2;%nCondemnedGeneration=%3;%nGen0ReductionCountD=%4;%nReason=%5;%nGlobalMechanisms=%6;%nClrInstanceID=%7;%nPauseMode=%8;%nMemoryPressure=%9;%CondemnReasons0=%10;%CondemnReasons1=%11"/>
                 <string id="RuntimePublisher.FinalizeObjectEventMessage" value="TypeID=%1;%nObjectID=%2;%nClrInstanceID=%3" />
                 <string id="RuntimePublisher.GCTriggeredEventMessage" value="Reason=%1" />
                 <string id="RuntimePublisher.PinObjectAtGCTimeEventMessage" value="HandleID=%1;%nObjectID=%2;%nObjectSize=%3;%nTypeName=%4;%n;%nClrInstanceID=%5" />

diff --git a/src/coreclr/src/vm/gctoclreventsink.cpp b/src/coreclr/src/vm/gctoclreventsink.cpp
@@ -121,19 +121,21 @@ void GCToCLREventSink::FireGCJoin_V2(uint32_t heap, uint32_t joinTime, uint32_t
     FireEtwGCJoin_V2(heap, joinTime, joinType, GetClrInstanceId(), joinId);
 }
 
-void GCToCLREventSink::FireGCGlobalHeapHistory_V2(uint64_t finalYoungestDesired,
+void GCToCLREventSink::FireGCGlobalHeapHistory_V3(uint64_t finalYoungestDesired,
         int32_t numHeaps,
         uint32_t condemnedGeneration,
         uint32_t gen0reductionCount,
         uint32_t reason,
         uint32_t globalMechanisms,
         uint32_t pauseMode,
-        uint32_t memoryPressure)
+        uint32_t memoryPressure,
+        uint32_t condemnReasons0,
+        uint32_t condemnReasons1)
 {
     LIMITED_METHOD_CONTRACT;
 
-    FireEtwGCGlobalHeapHistory_V2(finalYoungestDesired, numHeaps, condemnedGeneration, gen0reductionCount, reason,
-        globalMechanisms, GetClrInstanceId(), pauseMode, memoryPressure);
+    FireEtwGCGlobalHeapHistory_V3(finalYoungestDesired, numHeaps, condemnedGeneration, gen0reductionCount, reason,
+        globalMechanisms, GetClrInstanceId(), pauseMode, memoryPressure, condemnReasons0, condemnReasons1);
 }
 
 void GCToCLREventSink::FireGCAllocationTick_V1(uint32_t allocationAmount, uint32_t allocationKind)