public static void ToXml(TextWriter writer, TraceProcess stats, TraceLoadedDotNetRuntime runtime, string indent) { 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); if (stats.CPUMSec != 0) { writer.Write(" ProcessCpuTimeMsec=\"{0}\"", stats.CPUMSec); } if (!string.IsNullOrEmpty(stats.CommandLine)) { writer.Write(" CommandLine=\"{0}\"", XmlUtilities.XmlEscape(stats.CommandLine, false)); } writer.WriteLine(">"); writer.WriteLine(" <JitEvents>"); foreach (TraceJittedMethod _event in runtime.JIT.Methods) { ToXml(writer, _event); } 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); // Sort the module list by Jit Time; List <string> moduleNames = new List <string>(statsEx.TotalModuleStats.Keys); moduleNames.Sort(delegate(string x, string y) { double diff = statsEx.TotalModuleStats[y].TotalCpuTimeMSec - statsEx.TotalModuleStats[x].TotalCpuTimeMSec; if (diff > 0) { return(1); } else if (diff < 0) { return(-1); } return(0); }); foreach (string moduleName in moduleNames) { JITStats info = statsEx.TotalModuleStats[moduleName]; writer.Write("<Module"); writer.Write(" JitTimeMSec={0}", StringUtilities.QuotePadLeft(info.TotalCpuTimeMSec.ToString("n3"), 11)); 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(" Name=\"{0}\"", moduleName); writer.WriteLine("/>"); } writer.WriteLine(" </ModuleStats>"); writer.WriteLine(" </JitProcess>"); }
public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotNetRuntime runtime, string fileName) { JITStatsEx statsEx = JITStatsEx.Create(runtime); var usersGuideFile = ClrStatsUsersGuide.WriteUsersGuide(fileName); bool hasInliningEvents = runtime.JIT.Stats().InliningSuccesses.Count > 0 || runtime.JIT.Stats().InliningFailures.Count > 0; writer.WriteLine("<H3><A Name=\"Stats_{0}\"><font color=\"blue\">JIT Stats for for Process {1,5}: {2}</font><A></H3>", stats.ProcessID, stats.ProcessID, stats.Name); writer.WriteLine("<UL>"); { if (!string.IsNullOrEmpty(stats.CommandLine)) { writer.WriteLine("<LI>CommandLine: {0}</LI>", stats.CommandLine); } writer.WriteLine("<LI>Process CPU Time: {0:n0} msec</LI>", stats.CPUMSec); writer.WriteLine("<LI>Guidance on JIT data:"); writer.WriteLine("<UL>"); { writer.WriteLine("<LI> <A HREF=\"{0}#UnderstandingJITPerf\">JIT Perf Users Guide</A></LI>", usersGuideFile); if (runtime.JIT.Stats().BackgroundJitThread != 0 || runtime.JIT.Stats().BackgroundJitAbortedAtMSec != 0) { writer.WriteLine("<LI>Background JIT compilation (System.Runtime.ProfileOptimize) in use - <A HREF=\"{0}#UnderstandingBackgroundJIT\">Guide</A></LI>", usersGuideFile); writer.WriteLine(" <UL>"); if (runtime.JIT.Stats().RecordedModules.Count == 0) { writer.WriteLine(" <LI><font color=\"red\">This trace is missing some background JIT events, which could result in incorrect information in the background JIT blocking reason column.</font></LI>"); writer.WriteLine(" <LI><font color=\"red\">Re-collect the trace enabling \"Background JIT\" events on the collection menu to fix this.</font></LI>"); } if (runtime.JIT.Stats().BackgroundJitAbortedAtMSec != 0) { writer.WriteLine(" <LI><font color=\"red\">WARNING: Background JIT aborted at {0:n3} Msec</font></LI>", runtime.JIT.Stats().BackgroundJitAbortedAtMSec); writer.WriteLine(" <LI>The last assembly before the abort was '{0}' loaded {1} at {2:n3}</LI>", runtime.JIT.Stats().LastAssemblyLoadNameBeforeAbort, runtime.JIT.Stats().LastAssemblyLoadBeforeAbortSuccessful ? "successfully" : "unsuccessfully", runtime.JIT.Stats().LastAssemblyLoadBeforeAbortMSec); } writer.WriteLine(" </UL>"); } else if (runtime.JIT.Stats().BackgroundJitThread == 0) { if (runtime.JIT.Stats().BackgroundJITEventsOn) { writer.WriteLine("<LI>Background JIT compilation (System.Runtime.ProfileOptimize) not in use - <A HREF=\"{0}#UnderstandingBackgroundJIT\">Guide</A></LI>", usersGuideFile); writer.WriteLine("<UL><LI>If there is a lot of JIT time enabling this may improve startup performance</LI></UL>"); } else { writer.WriteLine("<LI>Background JIT compilation (System.Runtime.ProfileOptimize) events are not being collected - <A HREF=\"{0}#UnderstandingBackgroundJIT\">Guide</A></LI>", usersGuideFile); writer.WriteLine("<UL><LI>If you are interested in seeing them enable the 'Background JIT' checkbox in the 'Advanced' section of the collection dialog when collecting the data.</LI></UL>"); } } if (!runtime.IsTieredCompilationEnabled) { writer.WriteLine("<LI>Tiered compilation not in use - <A HREF=\"{0}#UnderstandingTieredCompilation\">Guide</A></LI>", usersGuideFile); writer.WriteLine("<UL><LI>On .Net Core, enabling this may improve application performance</LI></UL>"); } else { writer.WriteLine("<LI>Tiered compilation in use - <A HREF=\"{0}#UnderstandingTieredCompilation\">Guide</A></LI>", usersGuideFile); } } writer.WriteLine("</UL>"); writer.WriteLine("</LI>"); writer.WriteLine("<LI>Raw data:"); writer.WriteLine("<UL>"); { writer.WriteLine("<LI>Individual JIT Events <A HREF=\"#Events_{0}\">Html</A> | <A HREF=\"command:excel/{0}\">Excel</A></LI>", stats.ProcessID); if (hasInliningEvents) { writer.WriteLine("<LI>Inlining Decisions <A HREF=\"#Inlining_{0}\">Html</A> | <A HREF=\"command:excelInlining/{0}\">Excel</A></LI>", stats.ProcessID); } else { writer.WriteLine("<LI><I>No JIT Inlining data available. Consider enabling the JITInlining option.</I></LI>"); } if (runtime.JIT.Stats().BackgroundJitThread != 0 || runtime.JIT.Stats().BackgroundJitAbortedAtMSec != 0) { writer.WriteLine("<LI>Background Jit Diagnostics <A HREF=\"command:excelBackgroundDiag/{0}\">Excel</A></LI>", stats.ProcessID); } } writer.WriteLine("</UL>"); writer.WriteLine("</LI>"); // // Summary table by trigger // writer.WriteLine("<LI> Summary of jitting time by trigger:"); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.WriteLine("<TR>" + "<TH Title=\"The reason why the JIT was invoked.\">Jitting Trigger</TH>" + "<TH Title=\"The number of times the JIT was invoked\">Num Compilations</TH>" + "<TH Title=\"The % of all compilations that triggered by this trigger\">% of total jitted compilations</TH>" + "<TH Title=\"The total time used by all compilations with the given trigger\">Jit Time msec</TH>" + "<TH Title=\"The total time used by all compilations with the given trigger as a % of total CPU time used for the process\">Jit Time (% of total process CPU)</TH>" + "</TR>"); writer.WriteLine(FormatThreadingModelTableRow("TOTAL", runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalCpuTimeMSec, stats, runtime)); writer.WriteLine(FormatThreadingModelTableRow(CompilationThreadKind.Foreground, runtime.JIT.Stats().CountForeground, runtime.JIT.Stats().TotalForegroundCpuTimeMSec, stats, runtime)); writer.WriteLine(FormatThreadingModelTableRow(CompilationThreadKind.MulticoreJitBackground, runtime.JIT.Stats().CountBackgroundMultiCoreJit, runtime.JIT.Stats().TotalBackgroundMultiCoreJitCpuTimeMSec, stats, runtime)); writer.WriteLine(FormatThreadingModelTableRow(CompilationThreadKind.TieredCompilationBackground, runtime.JIT.Stats().CountBackgroundTieredCompilation, runtime.JIT.Stats().TotalBackgroundTieredCompilationCpuTimeMSec, stats, runtime)); writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); writer.WriteLine("</LI>"); // // Module table // // Sort the module list by Jit Time; List <string> moduleNames = new List <string>(statsEx.TotalModuleStats.Keys); moduleNames.Sort(delegate(string x, string y) { double diff = statsEx.TotalModuleStats[y].TotalCpuTimeMSec - statsEx.TotalModuleStats[x].TotalCpuTimeMSec; if (diff > 0) { return(1); } else if (diff < 0) { return(-1); } return(0); }); writer.WriteLine("<LI> Summary of jitting time by module:</P>"); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); 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>"); 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>" + "<TD Align=\"Center\">{1:n1}</TD>" + "<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\">{6:n1}</TD>" + "<TD Align=\"Center\">{7:n1}</TD>"; writer.Write(moduleTableRow, "TOTAL", runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize, 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.Write(moduleTableRow, moduleName.Length == 0 ? "<UNKNOWN>" : moduleName, info.TotalCpuTimeMSec, info.Count, info.TotalILSize, info.TotalNativeSize, 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>"); writer.WriteLine("</LI>"); } writer.WriteLine("</UL>"); bool backgroundJitEnabled = runtime.JIT.Stats().BackgroundJitThread != 0; writer.WriteLine("<HR/>"); writer.WriteLine("<H4><A Name=\"Events_{0}\">Individual JIT Events for Process {1,5}: {2}<A></H4>", stats.ProcessID, stats.ProcessID, stats.Name); // We limit the number of JIT events we ut on the page because it makes the user exerience really bad (browsers crash) const int maxEvents = 1000; if (runtime.JIT.Methods.Count >= maxEvents) { writer.WriteLine("<p><Font color=\"red\">Warning: Truncating JIT events to " + maxEvents + ". <A HREF=\"command:excel/{0}\">View in excel</A> to look all of them.</font></p>", stats.ProcessID); } bool showOptimizationTiers = ShouldShowOptimizationTiers(runtime); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.Write( "<TR>" + "<TH>Start<BR/>(msec)</TH>" + "<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>"); } writer.Write( "<TH>Method Name</TH>" + "<TH Title=\"Is Jit compilation occurring in the background for Multicore JIT (MC), in the background for tiered compilation (TC), or in the foreground on first execution of a method (FG).\">Trigger</TH>" + "<TH>Module</TH>"); if (backgroundJitEnabled) { writer.Write( "<TH Title=\"How far ahead of the method usage was relative to the background JIT operation.\">Distance Ahead</TH>" + "<TH Title=\"Why the method was not JITTed in the background.\">Background JIT Blocking Reason</TH>"); } writer.WriteLine("</TR>"); int eventCount = 0; foreach (TraceJittedMethod _event in runtime.JIT.Methods) { writer.Write( "<TR>" + "<TD Align=\"Center\">{0:n3}</TD>" + "<TD Align=\"Center\">{1:n1}</TD>" + "<TD Align=\"Center\">{2:n0}</TD>" + "<TD Align=\"Center\">{3:n0}</TD>", _event.StartTimeMSec, _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( "<TD Align=\"Center\">{0}</TD>", _event.OptimizationTier == OptimizationTier.Unknown ? string.Empty : _event.OptimizationTier.ToString()); } writer.Write( "<TD Align=Left>{0}</TD>" + "<TD Align=\"Center\">{1}</TD>" + "<TD Align=\"Center\">{2}</TD>", _event.MethodName ?? " ", GetShortNameForThreadClassification(_event.CompilationThreadKind), _event.ModuleILPath.Length != 0 ? Path.GetFileName(_event.ModuleILPath) : "<UNKNOWN>"); if (backgroundJitEnabled) { writer.Write( "<TD Align=\"Center\">{0:n3}</TD>" + "<TD Align=\"Left\">{1}</TD>", _event.DistanceAhead, _event.CompilationThreadKind == CompilationThreadKind.MulticoreJitBackground ? "Not blocked" : _event.BlockedReason); } writer.WriteLine("</TR>"); eventCount++; if (eventCount >= maxEvents) { break; } } writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); if (hasInliningEvents) { writer.WriteLine("<HR/>"); writer.WriteLine("<A Name=\"Inlining_{0}\">", stats.ProcessID); writer.WriteLine("<H4>Successful Inlinings for Process {0,5}: {1}<A></H4>", stats.ProcessID, stats.Name); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.Write("<TR><TH>Method Begin Compiled</TH><TH>Inliner</TH><TH>Inlinee</TH></TR>"); foreach (InliningSuccessResult success in runtime.JIT.Stats().InliningSuccesses) { writer.Write("<TR><TD>{0}</TD><TD>{1}</TD><TD>{2}</TD></TR>", success.MethodBeingCompiled, success.Inliner, success.Inlinee); } writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); writer.WriteLine("<H4>Failed Inlinings for Process {0,5}: {1}<A></H4>", stats.ProcessID, stats.Name); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.Write("<TR><TH>Method Begin Compiled</TH><TH>Inliner</TH><TH>Inlinee</TH><TH>Failure Reason</TH></TR>"); foreach (InliningFailureResult failure in runtime.JIT.Stats().InliningFailures) { writer.Write("<TR><TD>{0}</TD><TD>{1}</TD><TD>{2}</TD><TD>{3}</TD></TR>", failure.MethodBeingCompiled, failure.Inliner, failure.Inlinee, failure.Reason); } writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); } writer.WriteLine("<HR/><HR/><BR/><BR/>"); }
public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotNetRuntime runtime, string fileName) { JITStatsEx statsEx = JITStatsEx.Create(runtime); var usersGuideFile = ClrStatsUsersGuide.WriteUsersGuide(fileName); bool hasInliningEvents = runtime.JIT.Stats().InliningSuccesses.Count > 0 || runtime.JIT.Stats().InliningFailures.Count > 0; writer.WriteLine("<H3><A Name=\"Stats_{0}\"><font color=\"blue\">JIT Stats for for Process {1,5}: {2}</font><A></H3>",stats.ProcessID, stats.ProcessID, stats.Name); writer.WriteLine("<UL>"); if (!runtime.JIT.Stats().IsClr4) writer.WriteLine("<LI><Font color=\"red\">Warning: Could not confirm that a V4.0 CLR was loaded. JitTime or ILSize can only be computed for V4.0 runtimes. Otherwise their value will appear as 0.</font></LI>"); if (!string.IsNullOrEmpty(stats.CommandLine)) writer.WriteLine("<LI>CommandLine: {0}</LI>", stats.CommandLine); writer.WriteLine("<LI>Process CPU Time: {0:n0} msec</LI>", stats.CPUMSec); if (runtime.JIT.Stats().BackgroundJitThread != 0 || runtime.JIT.Stats().BackgroundJitAbortedAtMSec != 0) { writer.WriteLine("<LI>This process uses Background JIT compilation (System.Runtime.ProfileOptimize)</LI>"); writer.WriteLine(" <UL>"); if (runtime.JIT.Stats().RecordedModules.Count == 0) { writer.WriteLine(" <LI><font color=\"red\">This trace is missing some background JIT events, which could result in incorrect information in the background JIT blocking reason column.</font></LI>"); writer.WriteLine(" <LI><font color=\"red\">Re-collect the trace enabling \"Background JIT\" events on the collection menu to fix this.</font></LI>"); } if (runtime.JIT.Stats().BackgroundJitAbortedAtMSec != 0) { writer.WriteLine(" <LI><font color=\"red\">WARNING: Background JIT aborted at {0:n3} Msec</font></LI>", runtime.JIT.Stats().BackgroundJitAbortedAtMSec); writer.WriteLine(" <LI>The last assembly before the abort was '{0}' loaded {1} at {2:n3}</LI>", runtime.JIT.Stats().LastAssemblyLoadNameBeforeAbort, runtime.JIT.Stats().LastAssemblyLoadBeforeAbortSuccessful ? "successfully" : "unsuccessfully", runtime.JIT.Stats().LastAssemblyLoadBeforeAbortMSec); } if (runtime.JIT.Stats().BackgroundJitThread != 0) { var foregroundJitTimeMSec = runtime.JIT.Stats().TotalCpuTimeMSec - statsEx.TotalBGJITStats.TotalCpuTimeMSec; writer.WriteLine(" <LI><strong>JIT time NOT moved to background thread</strong> : {0:n0}</LI> ({1:n1}%)", foregroundJitTimeMSec, foregroundJitTimeMSec * 100.0 / runtime.JIT.Stats().TotalCpuTimeMSec); var foregroundCount = runtime.JIT.Stats().Count - statsEx.TotalBGJITStats.Count; writer.WriteLine(" <LI>Methods Not moved to background thread: {0:n0} ({1:n1}%)</LI>", foregroundCount, foregroundCount * 100.0 / runtime.JIT.Stats().Count); writer.WriteLine(" <LI>Methods Background JITTed : {0:n0} ({1:n1}%)</LI>", statsEx.TotalBGJITStats.Count, statsEx.TotalBGJITStats.Count * 100.0 / runtime.JIT.Stats().Count); writer.WriteLine(" <LI>MSec Background JITTing : {0:n0}</LI>", statsEx.TotalBGJITStats.TotalCpuTimeMSec); writer.WriteLine(" <LI>Background JIT Thread : {0}</LI>", runtime.JIT.Stats().BackgroundJitThread); } writer.WriteLine(" <LI> <A HREF=\"command:excelBackgroundDiag/{0}\">View Raw Background Jit Diagnostics</A></LI></UL>", stats.ProcessID); writer.WriteLine(" <LI> See <A HREF=\"{0}#UnderstandingBackgroundJIT\">Guide to Background JIT</A></LI> for more on background JIT", usersGuideFile); writer.WriteLine(" </UL>"); } writer.WriteLine("<LI>Total Number of JIT compiled methods : {0:n0}</LI>", runtime.JIT.Stats().Count); writer.WriteLine("<LI>Total MSec JIT compiling : {0:n0}</LI>", runtime.JIT.Stats().TotalCpuTimeMSec); if (runtime.JIT.Stats().TotalCpuTimeMSec != 0) writer.WriteLine("<LI>JIT compilation time as a percentage of total process CPU time : {0:f1}%</LI>", runtime.JIT.Stats().TotalCpuTimeMSec * 100.0 / stats.CPUMSec); writer.WriteLine("<LI><A HREF=\"#Events_{0}\">Individual JIT Events</A></LI>", stats.ProcessID); writer.WriteLine("<UL><LI> <A HREF=\"command:excel/{0}\">View in Excel</A></LI></UL>", stats.ProcessID); if (hasInliningEvents) { writer.WriteLine("<LI><A HREF=\"#Inlining_{0}\">Inlining Decisions</A></LI>", stats.ProcessID); writer.WriteLine("<UL><LI> <A HREF=\"command:excelInlining/{0}\">View in Excel</A></LI></UL>", stats.ProcessID); } else { writer.WriteLine("<LI><I>No JIT Inlining data available. Consider enabling the JITInlining option.</I></LI>", stats.ProcessID); } writer.WriteLine("<LI> <A HREF=\"{0}#UnderstandingJITPerf\">JIT Perf Users Guide</A></LI>", usersGuideFile); writer.WriteLine("</UL>"); if (runtime.JIT.Stats().BackgroundJitThread == 0) { if (runtime.JIT.Stats().BackgroundJITEventsOn) { writer.WriteLine("<P>" + "<b>This process does not use background JIT compilation.</b> If there is a lot of JIT time and NGEN is not an possible\r\n" + "you should consider using Background JIT compilation.\r\n" + "See <A HREF=\"{0}#UnderstandingBackgroundJIT\">Guide to Background JIT</A> for more." + "</P>", usersGuideFile); } else { writer.WriteLine("<P>" + "<b>Background JIT compilation events are not being collected.</b> If you are interested in seeing the operation of Background JIT\r\n" + "Enabled the 'Background JIT' checkbox in the 'Advanced' section of the collection dialog when collecting the data." + "See <A HREF=\"{0}#UnderstandingBackgroundJIT\">Guide to Background JIT</A> for more." + "</P>", usersGuideFile); } } writer.WriteLine("<P>" + "Below is a table of the time taken to JIT compile the methods used in the program, broken down by module. \r\n" + "If this time is significant you can eliminate it by <A href=\"http://msdn.microsoft.com/en-us/magazine/cc163808.aspx\">NGening</A> your application. \r\n" + "This will improve the startup time for your app. \r\n" + "</P>"); writer.WriteLine("<P>" + "The list below is also useful for tuning the startup performance of your application in general. \r\n" + "In general you want as little to be run during startup as possible. \r\n" + "If you have 1000s of methods being compiled on startup " + "you should try to defer some of that computation until absolutely necessary.\r\n" + "</P>"); // Sort the module list by Jit Time; List<string> moduleNames = new List<string>(statsEx.TotalModuleStats.Keys); moduleNames.Sort(delegate (string x, string y) { double diff = statsEx.TotalModuleStats[y].TotalCpuTimeMSec - statsEx.TotalModuleStats[x].TotalCpuTimeMSec; if (diff > 0) return 1; else if (diff < 0) return -1; return 0; }); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.WriteLine("<TR><TH>Name</TH><TH>JitTime<BR/>msec</TH><TH>Num Methods</TH><TH>IL Size</TH><TH>Native Size</TH></TR>"); writer.WriteLine("<TR><TD Align=\"Left\">{0}</TD><TD Align=\"Center\">{1:n1}</TD><TD Align=\"Center\">{2:n0}</TD><TD Align=\"Center\">{3:n0}</TD><TD Align=\"Center\">{4:n0}</TD></TR>", "TOTAL", runtime.JIT.Stats().TotalCpuTimeMSec, runtime.JIT.Stats().Count, runtime.JIT.Stats().TotalILSize, runtime.JIT.Stats().TotalNativeSize); foreach (string moduleName in moduleNames) { JITStats info = statsEx.TotalModuleStats[moduleName]; writer.WriteLine("<TR><TD Align=\"Center\">{0}</TD><TD Align=\"Center\">{1:n1}</TD><TD Align=\"Center\">{2:n0}</TD><TD Align=\"Center\">{3:n0}</TD><TD Align=\"Center\">{4:n0}</TD></TR>", moduleName.Length == 0 ? "<UNKNOWN>" : moduleName, info.TotalCpuTimeMSec, info.Count, info.TotalILSize, info.TotalNativeSize); } writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); bool backgroundJitEnabled = runtime.JIT.Stats().BackgroundJitThread != 0; writer.WriteLine("<HR/>"); writer.WriteLine("<H4><A Name=\"Events_{0}\">Individual JIT Events for Process {1,5}: {2}<A></H4>", stats.ProcessID, stats.ProcessID, stats.Name); // We limit the number of JIT events we ut on the page because it makes the user exerience really bad (browsers crash) const int maxEvents = 1000; if (runtime.JIT.Methods.Count >= maxEvents) writer.WriteLine("<p><Font color=\"red\">Warning: Truncating JIT events to " + maxEvents + ". Use 'View in Excel' link above to look all of them</font></p>"); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.Write("<TR><TH>Start (msec)</TH><TH>JitTime</BR>msec</TH><TH>IL Size</TH><TH>Native Size</TH><TH>Method Name</TH>" + "<TH Title=\"Is Jit compilation occuring in the background (BG) or not (JIT).\">BG</TH><TH>Module</TH>"); if (backgroundJitEnabled) { writer.Write("<TH Title=\"How far ahead of the method usage was relative to the background JIT operation.\">Distance Ahead</TH><TH Title=\"Why the method was not JITTed in the background.\">Background JIT Blocking Reason</TH>"); } writer.WriteLine("</TR>"); int eventCount = 0; foreach (TraceJittedMethod _event in runtime.JIT.Methods) { writer.Write("<TR><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=Left>{4}</TD><TD Align=\"Center\">{5}</TD><TD Align=\"Center\">{6}</TD>", _event.StartTimeMSec, _event.CompileCpuTimeMSec, _event.ILSize, _event.NativeSize, _event.MethodName ?? " ", (_event.IsBackGround ? "BG" : "JIT"), _event.ModuleILPath.Length != 0 ? Path.GetFileName(_event.ModuleILPath) : "<UNKNOWN>"); if (backgroundJitEnabled) { writer.Write("<TD Align=\"Center\">{0:n3}</TD><TD Align=\"Left\">{1}</TD>", _event.DistanceAhead, _event.IsBackGround ? "Not blocked" : _event.BlockedReason); } writer.WriteLine("</TR>"); eventCount++; if (eventCount >= maxEvents) break; } writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); if (hasInliningEvents) { writer.WriteLine("<HR/>"); writer.WriteLine("<A Name=\"Inlining_{0}\">", stats.ProcessID); writer.WriteLine("<H4>Successful Inlinings for Process {0,5}: {1}<A></H4>", stats.ProcessID, stats.Name); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.Write("<TR><TH>Method Begin Compiled</TH><TH>Inliner</TH><TH>Inlinee</TH></TR>"); foreach (InliningSuccessResult success in runtime.JIT.Stats().InliningSuccesses) { writer.Write("<TR><TD>{0}</TD><TD>{1}</TD><TD>{2}</TD></TR>", success.MethodBeingCompiled, success.Inliner, success.Inlinee); } writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); writer.WriteLine("<H4>Failed Inlinings for Process {0,5}: {1}<A></H4>", stats.ProcessID, stats.Name); writer.WriteLine("<Center>"); writer.WriteLine("<Table Border=\"1\">"); writer.Write("<TR><TH>Method Begin Compiled</TH><TH>Inliner</TH><TH>Inlinee</TH><TH>Failure Reason</TH></TR>"); foreach (InliningFailureResult failure in runtime.JIT.Stats().InliningFailures) { writer.Write("<TR><TD>{0}</TD><TD>{1}</TD><TD>{2}</TD><TD>{3}</TD></TR>", failure.MethodBeingCompiled, failure.Inliner, failure.Inlinee, failure.Reason); } writer.WriteLine("</Table>"); writer.WriteLine("</Center>"); } writer.WriteLine("<HR/><HR/><BR/><BR/>"); }