Skip to content

Commit

Permalink
Merge pull request #1289 from kunalspathak/jit-alloc-size
Browse files Browse the repository at this point in the history 
Display JIT Allocated Heap Size
  • Loading branch information
@brianrob
brianrob authored Nov 10, 2020
2 parents 9502740 + a552161 commit 24ba662
Show file tree
Hide file tree
Showing 3 changed files with 277 additions and 15 deletions.
116 changes: 105 additions & 11 deletions src/PerfView/JitStats.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -154,16 +154,24 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
writer.WriteLine("<LI> Summary of jitting time by module:</P>");
writer.WriteLine("<Center>");
writer.WriteLine("<Table Border=\"1\">");
writer.WriteLine("<TR>" +
writer.Write("<TR>" +
"<TH Title=\"The name of the module\">Name</TH>" +
"<TH Title=\"The total CPU time spent jitting for all methods in this module\">JitTime<BR/>msec</TH>" +
"<TH Title=\"The number of times the JIT was invoked for methods in this module\">Num Compilations</TH>" +
"<TH Title=\"The total amount of IL processed by the JIT for all methods in this module\">IL Size</TH>" +
"<TH Title=\"The total amount of native code produced by the JIT for all methods in this module\">Native Size</TH>" +
"<TH Title=\"Time spent jitting synchronously to produce code for methods that were just invoked. These compilations often consume time at startup.\">" + GetLongNameForThreadClassification(CompilationThreadKind.Foreground) + "<BR/>msec</TH>" +
"<TH Title=\"Time spent jitting asynchronously to produce code for methods the runtime speculates will be invoked in the future.\">" + GetLongNameForThreadClassification(CompilationThreadKind.MulticoreJitBackground) + "<BR/>msec</TH>" +
"<TH Title=\"Time spent jitting asynchronously to produce code for methods that is more optimized than their initial code.\">" + GetLongNameForThreadClassification(CompilationThreadKind.TieredCompilationBackground) + "<BR/>msec</TH>" +
"</TR>");
"<TH Title=\"Time spent jitting asynchronously to produce code for methods that is more optimized than their initial code.\">" + GetLongNameForThreadClassification(CompilationThreadKind.TieredCompilationBackground) + "<BR/>msec</TH>");

if (runtime.JIT.Stats().IsJitAllocSizePresent)
{
writer.Write("<TH Title=\"The total amount of heap memory requested for the code produced by the JIT for all methods in this module. \">JIT Hotcode request size</TH>");
writer.Write("<TH Title=\"The total amount of heap memory requested for the read-only data of code produced by the JIT for all methods in this module. \">JIT RO-data request size</TH>");
writer.Write("<TH Title=\"The total amount of heap memory allocated for the code produced by the JIT for all methods in this module. \">Allocated size for JIT code</TH>");
}

writer.WriteLine("</TR>");

string moduleTableRow = "<TR>" +
"<TD Align=\"Left\">{0}</TD>" +
Expand All @@ -173,9 +181,9 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
"<TD Align=\"Center\">{4:n0}</TD>" +
"<TD Align=\"Center\">{5:n1}</TD>" +
"<TD Align=\"Center\">{6:n1}</TD>" +
"<TD Align=\"Center\">{7:n1}</TD>" +
"</TR>";
writer.WriteLine(moduleTableRow,
"<TD Align=\"Center\">{7:n1}</TD>";

writer.Write(moduleTableRow,
"TOTAL",
runtime.JIT.Stats().TotalCpuTimeMSec,
runtime.JIT.Stats().Count,
Expand All @@ -184,10 +192,26 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
runtime.JIT.Stats().TotalForegroundCpuTimeMSec,
runtime.JIT.Stats().TotalBackgroundMultiCoreJitCpuTimeMSec,
runtime.JIT.Stats().TotalBackgroundTieredCompilationCpuTimeMSec);

string allocSizeColumns = "";
if (runtime.JIT.Stats().IsJitAllocSizePresent)
{
allocSizeColumns +=
"<TD Align=\"Center\">{0:n0}</TD>" +
"<TD Align=\"Center\">{1:n0}</TD>" +
"<TD Align=\"Center\">{2:n0}</TD>";

writer.Write(allocSizeColumns,
runtime.JIT.Stats().TotalHotCodeAllocSize,
runtime.JIT.Stats().TotalRODataAllocSize,
runtime.JIT.Stats().TotalAllocSizeForJitCode);
}
writer.WriteLine();

foreach (string moduleName in moduleNames)
{
JITStats info = statsEx.TotalModuleStats[moduleName];
writer.WriteLine(moduleTableRow,
writer.Write(moduleTableRow,
moduleName.Length == 0 ? "&lt;UNKNOWN&gt;" : moduleName,
info.TotalCpuTimeMSec,
info.Count,
Expand All @@ -196,6 +220,17 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
info.TotalForegroundCpuTimeMSec,
info.TotalBackgroundMultiCoreJitCpuTimeMSec,
info.TotalBackgroundTieredCompilationCpuTimeMSec);

if (runtime.JIT.Stats().IsJitAllocSizePresent)
{
writer.Write(allocSizeColumns,
info.TotalHotCodeAllocSize,
info.TotalRODataAllocSize,
info.TotalAllocSizeForJitCode);
}

writer.WriteLine("</TR>");

}
writer.WriteLine("</Table>");
writer.WriteLine("</Center>");
Expand Down Expand Up @@ -225,6 +260,17 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
"<TH>Jit Time<BR/>(msec)</TH>" +
"<TH>IL<BR/>Size</TH>" +
"<TH>Native<BR/>Size</TH>");

if (runtime.JIT.Stats().IsJitAllocSizePresent)
{
writer.Write(
"<TH>JIT Hotcode<BR/>request size</TH>" +
"<TH>JIT RO-data<BR/>request size</TH>" +
"<TH>Allocated size<BR/>for JIT code</TH>" +
"<TH>JIT Allocation<BR/>Flags</TH>"
);
}

if (showOptimizationTiers)
{
writer.Write("<TH Title=\"The optimization tier at which the method was jitted.\">Optimization<BR/>Tier</TH>");
Expand Down Expand Up @@ -253,6 +299,21 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
_event.CompileCpuTimeMSec,
_event.ILSize,
_event.NativeSize);

if (_event.IsJitAllocSizePresent)
{
writer.Write(
"<TD Align=\"Center\">{0}</TD>" +
"<TD Align=\"Center\">{1}</TD>" +
"<TD Align=\"Center\">{2}</TD>" +
"<TD Align=\"Center\">{3}</TD>",
_event.JitHotCodeRequestSize,
_event.JitRODataRequestSize,
_event.AllocatedSizeForJitCode,
_event.JitAllocFlag
);
}

if (showOptimizationTiers)
{
writer.Write(
Expand Down Expand Up @@ -378,6 +439,10 @@ public static void ToCsv(string filePath, TraceLoadedDotNetRuntime runtime)
using (var writer = File.CreateText(filePath))
{
writer.Write("Start MSec{0}JitTime MSec{0}ThreadID{0}IL Size{0}Native Size", listSeparator);
if (runtime.JIT.Stats().IsJitAllocSizePresent)
{
writer.Write("{0}JIT HotCode request size{0}JIT RO-data request size{0}Allocated size for JIT code{0}JIT Allocation Flag", listSeparator);
}
if (showOptimizationTiers)
{
writer.Write("{0}OptimizationTier", listSeparator);
Expand All @@ -397,6 +462,17 @@ public static void ToCsv(string filePath, TraceLoadedDotNetRuntime runtime)
_event.ThreadID,
_event.ILSize,
_event.NativeSize);

if (_event.IsJitAllocSizePresent)
{
writer.Write("{0}{1}{0}{2}{0}{3}{0}{4}",
listSeparator,
_event.JitHotCodeRequestSize,
_event.JitRODataRequestSize,
_event.AllocatedSizeForJitCode,
_event.JitAllocFlag);
}

if (showOptimizationTiers)
{
writer.Write(
Expand Down Expand Up @@ -478,8 +554,11 @@ public static void ToXml(TextWriter writer, TraceProcess stats, TraceLoadedDotNe
JITStatsEx statsEx = JITStatsEx.Create(runtime);

// TODO pay attention to indent;
writer.Write(" <JitProcess Process=\"{0}\" ProcessID=\"{1}\" JitTimeMSec=\"{2:n3}\" Count=\"{3}\" ILSize=\"{4}\" NativeSize=\"{5}\"",
stats.Name, stats.ProcessID, runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize);
writer.Write(" <JitProcess Process=\"{0}\" ProcessID=\"{1}\" JitTimeMSec=\"{2:n3}\" Count=\"{3}\" ILSize=\"{4}\" NativeSize=\"{5}\"", stats.Name, stats.ProcessID, runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize);
if (runtime.JIT.Stats().IsJitAllocSizePresent)
{
writer.Write("HotCodeAllocSize=\"{0}\" RODataAllocSize=\"{1}\" AllocSizeForJitCode=\"{2}\"", runtime.JIT.Stats().TotalHotCodeAllocSize, runtime.JIT.Stats().TotalRODataAllocSize, runtime.JIT.Stats().TotalAllocSizeForJitCode);
}
if (stats.CPUMSec != 0)
{
writer.Write(" ProcessCpuTimeMsec=\"{0}\"", stats.CPUMSec);
Expand All @@ -500,8 +579,8 @@ public static void ToXml(TextWriter writer, TraceProcess stats, TraceLoadedDotNe

writer.WriteLine(" </JitEvents>");

writer.WriteLine(" <ModuleStats Count=\"{0}\" TotalCount=\"{1}\" TotalJitTimeMSec=\"{2:n3}\" TotalILSize=\"{3}\" TotalNativeSize=\"{4}\">",
statsEx.TotalModuleStats.Count, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize);
writer.WriteLine(" <ModuleStats Count=\"{0}\" TotalCount=\"{1}\" TotalJitTimeMSec=\"{2:n3}\" TotalILSize=\"{3}\" TotalNativeSize=\"{4}\" HotCodeAllocSize=\"{5}\" RODataAllocSize=\"{6}\" AllocSizeForJitCode=\"{7}\"",
statsEx.TotalModuleStats.Count, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize, runtime.JIT.Stats().TotalHotCodeAllocSize, runtime.JIT.Stats().TotalRODataAllocSize, runtime.JIT.Stats().TotalAllocSizeForJitCode);

// Sort the module list by Jit Time;
List<string> moduleNames = new List<string>(statsEx.TotalModuleStats.Keys);
Expand All @@ -528,6 +607,13 @@ public static void ToXml(TextWriter writer, TraceProcess stats, TraceLoadedDotNe
writer.Write(" Count={0}", StringUtilities.QuotePadLeft(info.Count.ToString(), 7));
writer.Write(" ILSize={0}", StringUtilities.QuotePadLeft(info.TotalILSize.ToString(), 9));
writer.Write(" NativeSize={0}", StringUtilities.QuotePadLeft(info.TotalNativeSize.ToString(), 9));

if (info.IsJitAllocSizePresent)
{
writer.Write(" HotCodeAllocSize={0}", StringUtilities.QuotePadLeft(info.TotalHotCodeAllocSize.ToString(), 9));
writer.Write(" RODataAllocSize={0}", StringUtilities.QuotePadLeft(info.TotalRODataAllocSize.ToString(), 9));
writer.Write(" RequestedAllocSizeForJitCode={0}", StringUtilities.QuotePadLeft(info.TotalAllocSizeForJitCode.ToString(), 9));
}
writer.Write(" Name=\"{0}\"", moduleName);
writer.WriteLine("/>");
}
Expand All @@ -543,6 +629,14 @@ private static void ToXml(TextWriter writer, TraceJittedMethod info, bool showOp
writer.Write(" JitTimeMSec={0}", StringUtilities.QuotePadLeft(info.CompileCpuTimeMSec.ToString("n3"), 8));
writer.Write(" ILSize={0}", StringUtilities.QuotePadLeft(info.ILSize.ToString(), 10));
writer.Write(" NativeSize={0}", StringUtilities.QuotePadLeft(info.NativeSize.ToString(), 10));

if (info.IsJitAllocSizePresent)
{
writer.Write(" JITHotCodeRequestSize={0}", StringUtilities.QuotePadLeft(info.JitHotCodeRequestSize.ToString(), 10));
writer.Write(" JITRODataRequestSize={0}", StringUtilities.QuotePadLeft(info.JitRODataRequestSize.ToString(), 10));
writer.Write(" AllocSizeForJitCode={0}", StringUtilities.QuotePadLeft(info.AllocatedSizeForJitCode.ToString(), 10));
writer.Write(" JitAllocFlag={0}", StringUtilities.QuotePadLeft(info.JitAllocFlag.ToString(), 10));
}
if (showOptimizationTiers)
{
writer.Write(
Expand Down
71 changes: 70 additions & 1 deletion src/TraceEvent/Computers/TraceManagedProcess.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1305,6 +1305,13 @@ internal static void SetupCallbacks(TraceEventDispatcher source)
}
};

source.Clr.MethodMemoryAllocatedForJitCode += delegate(MethodJitMemoryAllocatedForCodeTraceData data)
{
var process = data.Process();
var stats = currentManagedProcess(data);
JITStats.LogJitMethodAllocation(stats, data);
};

clrPrivate.ClrMulticoreJitCommon += delegate (MulticoreJitPrivateTraceData data)
{
var process = data.Process();
Expand Down Expand Up @@ -3805,6 +3812,22 @@ public class JITStats
/// </summary>
public long TotalNativeSize;
/// <summary>
/// Total hot code size allocated for all JITT'd methods
/// </summary>
public long TotalHotCodeAllocSize;
/// <summary>
/// Total read-only data size allocated for all JITT'd methods
/// </summary>
public long TotalRODataAllocSize;
/// <summary>
/// Total size allocated for all JITT'd methods
/// </summary>
public long TotalAllocSizeForJitCode;
/// <summary>
/// If data from alloc size for JIT event present
/// </summary>
public bool IsJitAllocSizePresent = false;
/// <summary>
/// Indication if this is running on .NET 4.x+
/// </summary>
[Obsolete("This is experimental, you should not use it yet for non-experimental purposes.")]
Expand Down Expand Up @@ -3877,6 +3900,10 @@ public void AddMethodToStatistics(TraceJittedMethod method)
TotalCpuTimeMSec += method.CompileCpuTimeMSec;
TotalILSize += method.ILSize;
TotalNativeSize += method.NativeSize;
TotalHotCodeAllocSize += method.JitHotCodeRequestSize;
TotalRODataAllocSize += method.JitRODataRequestSize;
IsJitAllocSizePresent |= method.IsJitAllocSizePresent;
TotalAllocSizeForJitCode += method.AllocatedSizeForJitCode;
if (method.CompilationThreadKind == CompilationThreadKind.MulticoreJitBackground)
{
CountBackgroundMultiCoreJit++;
Expand All @@ -3896,7 +3923,7 @@ public void AddMethodToStatistics(TraceJittedMethod method)

#region private
/// <summary>
/// Legacgy
/// Legacy
/// </summary>
internal static TraceJittedMethod MethodComplete(TraceLoadedDotNetRuntime stats, MethodLoadUnloadTraceDataBase data, string methodName, int rejitID, out bool createdNewMethod)
{
Expand Down Expand Up @@ -3941,6 +3968,26 @@ internal static TraceJittedMethod MethodComplete(TraceLoadedDotNetRuntime stats,
return _method;
}

/// <summary>
/// Handles AllocRequest event for JIT
/// </summary>
internal static void LogJitMethodAllocation(TraceLoadedDotNetRuntime stats, MethodJitMemoryAllocatedForCodeTraceData data)
{
TraceJittedMethod _method = stats.JIT.m_stats.FindIncompleteJitEventOnThread(stats, data.ThreadID);
if (_method != null)
{
// If we already counted alloc size for a method, don't count it again.
if (_method.JitHotCodeRequestSize == 0)
{
_method.IsJitAllocSizePresent = true;
_method.JitHotCodeRequestSize = data.JitHotCodeRequestSize;
_method.JitRODataRequestSize = data.JitRODataRequestSize;
_method.AllocatedSizeForJitCode = data.AllocatedSizeForJitCode;
_method.JitAllocFlag = data.JitAllocFlag;
}
}
}

/// <summary>
/// Uniquely represents a method within a process.
/// Used as a lookup key for data structures.
Expand Down Expand Up @@ -4145,6 +4192,22 @@ public class TraceJittedMethod
/// </summary>
public int NativeSize;
/// <summary>
/// Hot code size allocated for JIT code of method
/// </summary>
public long JitHotCodeRequestSize;
/// <summary>
/// Read-only data size allocated for JIT code of method
/// </summary>
public long JitRODataRequestSize;
/// <summary>
/// Total size allocated for JIT code of method
/// </summary>
public long AllocatedSizeForJitCode;
/// <summary>
/// Jit allocation flag
/// </summary>
public int JitAllocFlag;
/// <summary>
/// Relative start time of JIT'd method
/// </summary>
public double StartTimeMSec;
Expand Down Expand Up @@ -4230,6 +4293,12 @@ public string BlockedReason

public bool IsDefaultVersion { get { return VersionID == 0; } }

public bool IsJitAllocSizePresent
{
get;
set;
}

#region private
internal void SetOptimizationTier(OptimizationTier optimizationTier, TraceLoadedDotNetRuntime stats)
{
Expand Down
Loading

0 comments on commit 24ba662

Please sign in to comment.