Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Display JIT Allocated Heap Size #1289

Merged
merged 9 commits into from
Nov 10, 2020
Merged

Display JIT Allocated Heap Size #1289

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
50f2342
Display Allocated Heap Size
kunalspathak Oct 12, 2020
6395923
Accumulate allocation size at method level
kunalspathak Oct 14, 2020
ef5860d
Rename some variables and methods
kunalspathak Oct 14, 2020
eabad25
Display N/A if LoaderHeap event is not enabled
kunalspathak Oct 14, 2020
9b7924f
Add parsing logic for new event
kunalspathak Oct 27, 2020
5072c71
Working version
kunalspathak Oct 29, 2020
b584f1f
some misc bug fixes
kunalspathak Oct 29, 2020
0de08b0
Rename some of the fields
kunalspathak Oct 29, 2020
a552161
Replace methodName with methodId
kunalspathak Nov 5, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
116 changes: 105 additions & 11 deletions src/PerfView/JitStats.cs
View file
Open in desktop
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
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -1301,6 +1301,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 @@ -3776,6 +3783,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 @@ -3848,6 +3871,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 @@ -3867,7 +3894,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 @@ -3912,6 +3939,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 @@ -4116,6 +4163,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 @@ -4201,6 +4264,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