In this lesson, you will learn how to identify and correlate Garbage Collection (GC) pauses with throughput degradation by analyzing EventPipe logs and ETW events.
The GC Performance Trap
When your application experiences sudden, periodic dips in throughput, the culprit is often "GC pressure." This happens when your code allocates objects faster than the GC can reclaim them, triggering frequent Gen 0/1 collections or, worse, "Stop-the-World" Gen 2 collections. Because the runtime pauses managed threads during these collections, your request processing throughput drops to zero for the duration of the pause.
Analyzing GC Events
To diagnose this, you don't look at application logs; you look at the GC event stream. Tools like dotnet-trace or PerfView allow you to capture Microsoft-Windows-DotNETRuntime events. Specifically, you need to track GCStart_V2 and GCEnd_V1 events.
If you see a pattern where a GCStart event for a Gen 2 collection occurs exactly when your request latency spikes, you have found your bottleneck. Here is a conceptual view of how you might correlate this in a trace:
// Conceptual event correlation:
// 1. Log: Request_Received (CorrelationID: 101)
// 2. GC_Event: GCStart (Gen 2, Reason: AllocationSmall)
// 3. GC_Event: GCEnd (Duration: 150ms)
// 4. Log: Request_Completed (CorrelationID: 101)
// Result: 150ms of the 200ms request time was spent waiting for the GC.
Identifying the Cause
Once you confirm GC pauses are causing the drops, focus on the "GC Reason" field in the logs. If the reason is AllocationSmall, your application is simply creating too many short-lived objects. If it is Induced, some part of your code (or a third-party library) is explicitly calling GC.Collect().
By mapping these events against your correlation IDs, you can pinpoint which specific web request or background task is triggering the surge in allocations that forces the GC to intervene. If the pause duration is consistently high, it’s a sign that your heap is too fragmented or simply too large to scan efficiently.
Key Takeaway: Use EventPipe logs to correlate GC pause timestamps with request latency spikes to determine if throughput drops are caused by excessive allocation rates or forced collection cycles.