Last active
December 25, 2019 15:38
-
-
Save leppie/cd2796bb3bf750247e1091313cad8e13 to your computer and use it in GitHub Desktop.
GCVisualisation mods (https://github.com/mattwarren/GCVisualisation)
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
using Microsoft.Diagnostics.Tracing; | |
using Microsoft.Diagnostics.Tracing.Parsers; | |
using Microsoft.Diagnostics.Tracing.Parsers.Clr; | |
using Microsoft.Diagnostics.Tracing.Session; | |
using System; | |
using System.Collections.Concurrent; | |
using System.Diagnostics; | |
using System.Linq; | |
using System.Text; | |
using System.Threading.Tasks; | |
namespace GCVisualisation | |
{ | |
class Program | |
{ | |
private static TraceEventSession session; | |
private static ConcurrentBag<int> ProcessIdsUsedInRuns = new ConcurrentBag<int>(); | |
private static long totalBytesAllocated, gen0, gen1, gen2, gen2Background, gen3; | |
static double timeingc, start, stop; | |
static void Main(string[] args) | |
{ | |
// TODO | |
// - allow to specify PID of running process (DON'T kill it at the end!!) | |
// - put some stats in a "margin" and display the output on the RH 80% of the screen | |
// - GC pauses, for info see | |
// - https://blogs.msdn.microsoft.com/maoni/2014/12/22/gc-etw-events-1/ | |
// - https://blogs.msdn.microsoft.com/maoni/2014/12/25/gc-etw-events-3/ | |
// - https://blogs.msdn.microsoft.com/maoni/2015/11/20/are-you-glad/ | |
// - https://blogs.msdn.microsoft.com/maoni/2006/06/07/suspending-and-resuming-threads-for-gc/ | |
var sessionName = "GCVisualiser"; | |
session = new TraceEventSession(sessionName); | |
session.EnableProvider(ClrTraceEventParser.ProviderGuid, | |
TraceEventLevel.Verbose, | |
(ulong)(ClrTraceEventParser.Keywords.GC)); | |
// The ETW collection thread starts receiving events immediately, but we only care about one process | |
Task.Factory.StartNew(StartProcessingEvents, TaskCreationOptions.LongRunning); | |
//ProcessStartInfo startInfo = new ProcessStartInfo(); | |
//startInfo.FileName = args[0]; | |
//var process = Process.Start(startInfo); | |
var process = Process.GetProcessesByName(args[0])[0]; | |
ProcessIdsUsedInRuns.Add(process.Id); | |
process.Exited += (sender, e) => Console.WriteLine("\nProcess has exited\n"); | |
Console.CancelKeyPress += (sender, e) => | |
{ | |
Console.WriteLine("\nConsole being killed, tidying up\n"); | |
session.Dispose(); | |
}; | |
PrintSymbolInformation(); | |
Console.WriteLine("Visualising GC Events, press <ENTER>, <ESC> or 'q' to exit"); | |
ConsoleKeyInfo cki; | |
while (true) | |
{ | |
cki = Console.ReadKey(); | |
if (cki.Key == ConsoleKey.Enter || | |
cki.Key == ConsoleKey.Escape || | |
cki.Key == ConsoleKey.Q) | |
{ | |
break; | |
} | |
if (cki.Key == ConsoleKey.S) | |
{ | |
lock (ConsoleLock) | |
{ | |
PrintSummaryInfo(); | |
} | |
} | |
} | |
PrintSummaryInfo(); | |
Console.WriteLine(); | |
//if (process.HasExited == false) | |
// process.Kill(); | |
session.Dispose(); | |
} | |
private static void PrintSummaryInfo() | |
{ | |
session.Flush(); | |
Console.ForegroundColor = ConsoleColor.DarkYellow; | |
Console.Write(" "); | |
if (Console.CursorLeft > 0) | |
Console.WriteLine(); | |
Console.WriteLine("Memory Allocations:"); | |
// 100GB = 107,374,182,400 bytes, so min-width = 15 | |
Console.WriteLine(" {0,15:N0} bytes currently allocated", GC.GetTotalMemory(forceFullCollection: false)); | |
Console.WriteLine(" {0,15:N0} bytes allocated in total", totalBytesAllocated); | |
//Console.WriteLine("GC Collections - Gen0: {0:N0}, Gen1: {1:N0}, Gen2 {2:N0}, Gen2 B/G: {3:N0}, Gen3: {4:N0}", | |
// gen0, gen1, gen2, gen2Background, gen3); | |
var totalGC = gen0 + gen1 + gen2 + gen3; | |
var testTime = stop - start; | |
Console.WriteLine("GC Collections: {0:N0} in total (excl B/G)", totalGC); | |
Console.WriteLine(" {0,4:N0} - generation 0", gen0); | |
Console.WriteLine(" {0,4:N0} - generation 1", gen1); | |
Console.WriteLine(" {0,4:N0} - generation 2", gen2); | |
Console.WriteLine(" {0,4:N0} - generation 2 B/G", gen2Background); | |
if (gen3 > 0) | |
Console.WriteLine(" {0,4:N0} - generation 3 (LOH)", gen3); | |
Console.WriteLine("Time in GC: {0:F1} ms ({1:F2} ms avg) ", timeingc, timeingc / totalGC); | |
Console.WriteLine("Time under test: {0:F0} ms ({1:P2} spent in GC)", testTime, timeingc / testTime); | |
Console.ResetColor(); | |
} | |
private static void PrintSymbolInformation() | |
{ | |
Console.WriteLine("Key to symbols:"); | |
Console.WriteLine(" - '.' represents ~100K of memory ALLOCATIONS"); | |
Console.Write(" - "); | |
Console.ForegroundColor = GetColourForGC(0); Console.Write("0"); | |
Console.ResetColor(); Console.Write("/"); | |
Console.ForegroundColor = GetColourForGC(1); Console.Write("1"); | |
Console.ResetColor(); Console.Write("/"); | |
Console.ForegroundColor = GetColourForGC(2); Console.Write("2"); | |
Console.ResetColor(); | |
Console.WriteLine(" indicates a FOREGROUND GC Collection, for the given generation (0, 1 or 2)"); | |
Console.Write(" - "); | |
Console.BackgroundColor = GetColourForGC(2); Console.ForegroundColor = ConsoleColor.Black; Console.Write("2"); | |
Console.ResetColor(); | |
Console.WriteLine(" indicates a BACKGROUND GC Collection (Gen 2 only)"); | |
Console.WriteLine(" - ░/▒/▓/█ indicates a PAUSE due to a GC Collection"); | |
Console.WriteLine(" - ░ up to 25 msecs"); | |
Console.WriteLine(" - ▒ 25 to 50 msecs"); | |
Console.WriteLine(" - ▓ 50 to 75 msecs"); | |
Console.WriteLine(" - █ 75 msecs or longer"); | |
Console.WriteLine(new string('#', 25) + "\n"); | |
} | |
private static object ConsoleLock = new object(); | |
private static void StartProcessingEvents() | |
{ | |
// See https://github.com/dotnet/coreclr/blob/775003a4c72f0acc37eab84628fcef541533ba4e/src/pal/prebuilt/inc/mscoree.h#L294-L315 | |
session.Source.Clr.RuntimeStart += runtimeData => | |
{ | |
if (ProcessIdsUsedInRuns.Contains(runtimeData.ProcessID) == false) | |
return; | |
// probably not needed | |
lock (ConsoleLock) | |
{ | |
Console.WriteLine("\nCONCURRENT_GC = {0}, SERVER_GC = {1}", | |
(runtimeData.StartupFlags & StartupFlags.CONCURRENT_GC) == StartupFlags.CONCURRENT_GC, | |
(runtimeData.StartupFlags & StartupFlags.SERVER_GC) == StartupFlags.SERVER_GC); | |
} | |
}; | |
session.Source.Clr.GCAllocationTick += allocationData => | |
{ | |
if (ProcessIdsUsedInRuns.Contains(allocationData.ProcessID) == false) | |
return; | |
if (start == 0) | |
start = allocationData.TimeStampRelativeMSec; | |
stop = allocationData.TimeStampRelativeMSec; | |
totalBytesAllocated += allocationData.AllocationAmount; | |
// probably not needed | |
lock (ConsoleLock) | |
{ | |
Console.Write("."); | |
} | |
}; | |
GCType lastGCType = 0; | |
session.Source.Clr.GCStart += gcData => | |
{ | |
if (ProcessIdsUsedInRuns.Contains(gcData.ProcessID) == false) | |
return; | |
var colourToUse = GetColourForGC(gcData.Depth); | |
lastGCType = gcData.Type; | |
IncrementGCCollectionCounts(gcData); | |
lock (ConsoleLock) | |
{ | |
if (gcData.Type == GCType.ForegroundGC || gcData.Type == GCType.NonConcurrentGC) | |
{ | |
// Make the FG coloured/highlighted | |
Console.ForegroundColor = colourToUse; | |
Console.BackgroundColor = ConsoleColor.Black; | |
} | |
else // GCType.BackgroundGC | |
{ | |
// Make the BG coloured/highlighted | |
Console.ForegroundColor = ConsoleColor.Black; | |
Console.BackgroundColor = colourToUse; | |
} | |
Console.Write(gcData.Depth); | |
Console.ResetColor(); | |
} | |
}; | |
//In a typical blocking GC (this means all ephemeral GCs and full blocking GCs) the event sequence is very simple: | |
//GCSuspendEE_V1 Event | |
//GCSuspendEEEnd_V1 Event <– suspension is done | |
//GCStart_V1 Event | |
//GCEnd_V1 Event <– actual GC is done | |
//GCRestartEEBegin_V1 Event | |
//GCRestartEEEnd_V1 Event <– resumption is done. | |
// When NOT a B/G GC, Suspension MSec column is simply (timestamp of the GCSuspendEEEnd_V1 – timestamp of the GCSuspendEE_V1). | |
double pauseStart = 0; | |
session.Source.Clr.GCSuspendEEStop += suspendData => | |
{ | |
if (ProcessIdsUsedInRuns.Contains(suspendData.ProcessID) == false) | |
return; | |
pauseStart = suspendData.TimeStampRelativeMSec; | |
}; | |
session.Source.Clr.GCRestartEEStop += restartData => | |
{ | |
if (ProcessIdsUsedInRuns.Contains(restartData.ProcessID) == false) | |
return; | |
// Only display this if the GC Type is Foreground, (Background is different!!) | |
// 0x0 - NonConcurrentGC - Blocking garbage collection occurred outside background garbage collection. | |
// 0x1 - BackgroundGC - Background garbage collection. | |
// 0x2 - ForegroundGC - Blocking garbage collection occurred during background garbage collection. | |
if (lastGCType == GCType.BackgroundGC) | |
return; | |
stop = restartData.TimeStampRelativeMSec; | |
var pauseDurationMSec = restartData.TimeStampRelativeMSec - pauseStart; | |
var pauseText = new StringBuilder(); | |
while (pauseDurationMSec > 100) | |
{ | |
pauseText.Append('█'); | |
pauseDurationMSec -= 100; | |
} | |
if (pauseDurationMSec > 75) | |
pauseText.Append('█'); | |
else if (pauseDurationMSec > 50) | |
pauseText.Append('▓'); | |
else if (pauseDurationMSec > 25) | |
pauseText.Append('▒'); | |
else | |
pauseText.Append("░"); | |
timeingc += pauseDurationMSec; | |
//pauseText.AppendFormat("({0:N2} ms)", restartData.TimeStampRelativeMSec - pauseStart); | |
lock (ConsoleLock) | |
{ | |
Console.ResetColor(); | |
Console.Write(pauseText); | |
} | |
}; | |
session.Source.Process(); | |
} | |
private static void IncrementGCCollectionCounts(GCStartTraceData gcData) | |
{ | |
if (gcData.Type == GCType.BackgroundGC && gcData.Depth == 2) | |
gen2Background++; | |
else if (gcData.Depth == 0) | |
gen0++; | |
else if (gcData.Depth == 1) | |
gen1++; | |
else if (gcData.Depth == 2) | |
gen2++; | |
else if (gcData.Depth == 3) | |
gen3++; // L.O.H | |
} | |
private static ConsoleColor GetColourForGC(int depth) | |
{ | |
var colourToUse = ConsoleColor.White; | |
if (depth == 0) | |
colourToUse = ConsoleColor.Yellow; | |
else if (depth == 1) | |
colourToUse = ConsoleColor.Blue; | |
else if (depth == 2) | |
colourToUse = ConsoleColor.Red; | |
else | |
colourToUse = ConsoleColor.Green; | |
return colourToUse; | |
} | |
} | |
} |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment