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 2 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
32 changes: 21 additions & 11 deletions src/PerfView/JitStats.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -160,6 +160,7 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
"<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=\"The total amount of heap memory allocated for the code produced by the JIT for all methods in this module\">Allocated Heap Size</TH>" +
kunalspathak marked this conversation as resolved.
Show resolved Hide resolved
"<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>" +
Expand All @@ -171,16 +172,18 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
"<TD Align=\"Center\">{2:n0}</TD>" +
"<TD Align=\"Center\">{3:n0}</TD>" +
"<TD Align=\"Center\">{4:n0}</TD>" +
"<TD Align=\"Center\">{5:n1}</TD>" +
"<TD Align=\"Center\">{5:n0}</TD>" +
"<TD Align=\"Center\">{6:n1}</TD>" +
"<TD Align=\"Center\">{7:n1}</TD>" +
"<TD Align=\"Center\">{8:n1}</TD>" +
"</TR>";
writer.WriteLine(moduleTableRow,
"TOTAL",
runtime.JIT.Stats().TotalCpuTimeMSec,
runtime.JIT.Stats().Count,
runtime.JIT.Stats().TotalILSize,
runtime.JIT.Stats().TotalNativeSize,
runtime.JIT.Stats().TotalAllocatedHeapSize,
runtime.JIT.Stats().TotalForegroundCpuTimeMSec,
runtime.JIT.Stats().TotalBackgroundMultiCoreJitCpuTimeMSec,
runtime.JIT.Stats().TotalBackgroundTieredCompilationCpuTimeMSec);
Expand All @@ -193,6 +196,7 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
info.Count,
info.TotalILSize,
info.TotalNativeSize,
info.TotalAllocatedHeapSize,
info.TotalForegroundCpuTimeMSec,
info.TotalBackgroundMultiCoreJitCpuTimeMSec,
info.TotalBackgroundTieredCompilationCpuTimeMSec);
Expand Down Expand Up @@ -224,7 +228,8 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
"<TH>Start<BR/>(msec)</TH>" +
"<TH>Jit Time<BR/>(msec)</TH>" +
"<TH>IL<BR/>Size</TH>" +
"<TH>Native<BR/>Size</TH>");
"<TH>Native<BR/>Size</TH>" +
"<TH>Allocated<BR/>Heap Size</TH>");
if (showOptimizationTiers)
{
writer.Write("<TH Title=\"The optimization tier at which the method was jitted.\">Optimization<BR/>Tier</TH>");
Expand All @@ -248,11 +253,13 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN
"<TD Align=\"Center\">{0:n3}</TD>" +
"<TD Align=\"Center\">{1:n1}</TD>" +
"<TD Align=\"Center\">{2:n0}</TD>" +
"<TD Align=\"Center\">{3:n0}</TD>",
"<TD Align=\"Center\">{3:n0}</TD>" +
"<TD Align=\"Center\">{4:n0}</TD>",
_event.StartTimeMSec,
_event.CompileCpuTimeMSec,
_event.ILSize,
_event.NativeSize);
_event.NativeSize,
_event.AllocatedHeapSize);
if (showOptimizationTiers)
{
writer.Write(
Expand Down Expand Up @@ -377,7 +384,7 @@ public static void ToCsv(string filePath, TraceLoadedDotNetRuntime runtime)
bool showOptimizationTiers = ShouldShowOptimizationTiers(runtime);
using (var writer = File.CreateText(filePath))
{
writer.Write("Start MSec{0}JitTime MSec{0}ThreadID{0}IL Size{0}Native Size", listSeparator);
writer.Write("Start MSec{0}JitTime MSec{0}ThreadID{0}IL Size{0}Native Size{0}Allocated Heap Size", listSeparator);
if (showOptimizationTiers)
{
writer.Write("{0}OptimizationTier", listSeparator);
Expand All @@ -390,13 +397,14 @@ public static void ToCsv(string filePath, TraceLoadedDotNetRuntime runtime)
var csvMethodName = _event.MethodName.Replace(",", " "); // Insure there are no , in the name

writer.Write(
"{1:f3}{0}{2:f3}{0}{3}{0}{4}{0}{5}",
"{1:f3}{0}{2:f3}{0}{3}{0}{4}{0}{5}{0}{6}",
listSeparator,
_event.StartTimeMSec,
_event.CompileCpuTimeMSec,
_event.ThreadID,
_event.ILSize,
_event.NativeSize);
_event.NativeSize,
_event.AllocatedHeapSize);
if (showOptimizationTiers)
{
writer.Write(
Expand Down Expand Up @@ -478,8 +486,8 @@ 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}\" AllocatedHeapSize=\"{6}\"",
stats.Name, stats.ProcessID, runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize, runtime.JIT.Stats().TotalAllocatedHeapSize);
if (stats.CPUMSec != 0)
{
writer.Write(" ProcessCpuTimeMsec=\"{0}\"", stats.CPUMSec);
Expand All @@ -500,8 +508,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}\" TotalAllocatedHeapSize=\"{5}\">",
statsEx.TotalModuleStats.Count, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize, runtime.JIT.Stats().TotalAllocatedHeapSize);

// Sort the module list by Jit Time;
List<string> moduleNames = new List<string>(statsEx.TotalModuleStats.Keys);
Expand All @@ -528,6 +536,7 @@ 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));
writer.Write(" AllocatedHeapSize={0}", StringUtilities.QuotePadLeft(info.TotalAllocatedHeapSize.ToString(), 9));
writer.Write(" Name=\"{0}\"", moduleName);
writer.WriteLine("/>");
}
Expand All @@ -543,6 +552,7 @@ 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));
writer.Write(" AllocatedHeapSize={0}", StringUtilities.QuotePadLeft(info.AllocatedHeapSize.ToString(), 10));
if (showOptimizationTiers)
{
writer.Write(
Expand Down
35 changes: 34 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,15 @@ internal static void SetupCallbacks(TraceEventDispatcher source)
}
};

clrPrivate.LoaderHeapAllocRequest += delegate(LoaderHeapAllocRequestTraceData data)
{
var process = data.Process();
var stats = currentManagedProcess(data);
var _method = JITStats.JitAllocComplete(stats, data);
//TODO: What to do here of _method??
kunalspathak marked this conversation as resolved.
Show resolved Hide resolved

};

clrPrivate.ClrMulticoreJitCommon += delegate (MulticoreJitPrivateTraceData data)
{
var process = data.Process();
Expand Down Expand Up @@ -3776,6 +3785,10 @@ public class JITStats
/// </summary>
public long TotalNativeSize;
/// <summary>
/// Total allocated heap size for all JITT'd methods
/// </summary>
public long TotalAllocatedHeapSize;
/// <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 +3861,7 @@ public void AddMethodToStatistics(TraceJittedMethod method)
TotalCpuTimeMSec += method.CompileCpuTimeMSec;
TotalILSize += method.ILSize;
TotalNativeSize += method.NativeSize;
TotalAllocatedHeapSize += method.AllocatedHeapSize;
if (method.CompilationThreadKind == CompilationThreadKind.MulticoreJitBackground)
{
CountBackgroundMultiCoreJit++;
Expand All @@ -3867,7 +3881,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 +3926,21 @@ internal static TraceJittedMethod MethodComplete(TraceLoadedDotNetRuntime stats,
return _method;
}

/// <summary>
/// Handles AllocRequest event for JIT
/// </summary>
internal static TraceJittedMethod JitAllocComplete(TraceLoadedDotNetRuntime stats, LoaderHeapAllocRequestTraceData data)
kunalspathak marked this conversation as resolved.
Show resolved Hide resolved
kunalspathak marked this conversation as resolved.
Show resolved Hide resolved
{
TraceJittedMethod _method = stats.JIT.m_stats.FindIncompleteJitEventOnThread(stats, data.ThreadID);
if (_method != null)
{
_method.AllocatedHeapSize += data.RequestSize;
stats.JIT.m_stats.TotalAllocatedHeapSize += data.RequestSize;
}

return _method;
}

/// <summary>
/// Uniquely represents a method within a process.
/// Used as a lookup key for data structures.
Expand Down Expand Up @@ -4116,6 +4145,10 @@ public class TraceJittedMethod
/// </summary>
public int NativeSize;
/// <summary>
/// Heap size allocated for JIT code of method
/// </summary>
public int AllocatedHeapSize;
kunalspathak marked this conversation as resolved.
Show resolved Hide resolved
/// <summary>
/// Relative start time of JIT'd method
/// </summary>
public double StartTimeMSec;
Expand Down