From eba4f099e8889f828169b020400c5432e074bdb4 Mon Sep 17 00:00:00 2001 From: noahfalk Date: Tue, 15 May 2018 15:30:22 -0700 Subject: [PATCH 1/2] Support for tiered compilation Change the JitStats view to show data relevant to tiered compilation. Also cleaned up some of the output in general, moved some of the guidance into the user guide, and tried to make the text a little more applicable for customers that are using .Net Core. --- PerfView.sln | 160 ++++++++ src/PerfView/JitStats.cs | 347 +++++++++++------- .../SupportFiles/HtmlReportUsersGuide.htm | 128 +++++-- .../Computers/TraceManagedProcess.cs | 79 +++- 4 files changed, 551 insertions(+), 163 deletions(-) diff --git a/PerfView.sln b/PerfView.sln index 61a7a5ae0..3cf7599ca 100644 --- a/PerfView.sln +++ b/PerfView.sln @@ -76,89 +76,249 @@ EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution Debug|Any CPU = Debug|Any CPU + Debug|x64 = Debug|x64 + Debug|x86 = Debug|x86 Release|Any CPU = Release|Any CPU + Release|x64 = Release|x64 + Release|x86 = Release|x86 EndGlobalSection GlobalSection(ProjectConfigurationPlatforms) = postSolution {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Debug|Any CPU.ActiveCfg = Debug|Win32 {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Debug|Any CPU.Build.0 = Debug|Win32 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Debug|x64.ActiveCfg = Debug|Win32 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Debug|x86.ActiveCfg = Debug|Win32 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Debug|x86.Build.0 = Debug|Win32 {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Release|Any CPU.ActiveCfg = Release|Win32 {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Release|Any CPU.Build.0 = Release|Win32 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Release|x64.ActiveCfg = Release|Win32 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Release|x86.ActiveCfg = Release|Win32 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB8}.Release|x86.Build.0 = Release|Win32 {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Debug|Any CPU.ActiveCfg = Debug|x64 {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Debug|Any CPU.Build.0 = Debug|x64 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Debug|x64.ActiveCfg = Debug|x64 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Debug|x64.Build.0 = Debug|x64 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Debug|x86.ActiveCfg = Debug|x64 {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Release|Any CPU.ActiveCfg = Release|x64 {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Release|Any CPU.Build.0 = Release|x64 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Release|x64.ActiveCfg = Release|x64 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Release|x64.Build.0 = Release|x64 + {E9980619-4016-4A4A-B7CC-F8B0E483BDB9}.Release|x86.ActiveCfg = Release|x64 {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Debug|Any CPU.Build.0 = Debug|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Debug|x64.ActiveCfg = Debug|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Debug|x64.Build.0 = Debug|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Debug|x86.ActiveCfg = Debug|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Debug|x86.Build.0 = Debug|Any CPU {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Release|Any CPU.ActiveCfg = Release|Any CPU {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Release|Any CPU.Build.0 = Release|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Release|x64.ActiveCfg = Release|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Release|x64.Build.0 = Release|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Release|x86.ActiveCfg = Release|Any CPU + {B68F4968-A7CF-41CC-AD6E-373DB5E67944}.Release|x86.Build.0 = Release|Any CPU {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Debug|Any CPU.Build.0 = Debug|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Debug|x64.ActiveCfg = Debug|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Debug|x64.Build.0 = Debug|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Debug|x86.ActiveCfg = Debug|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Debug|x86.Build.0 = Debug|Any CPU {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Release|Any CPU.ActiveCfg = Release|Any CPU {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Release|Any CPU.Build.0 = Release|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Release|x64.ActiveCfg = Release|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Release|x64.Build.0 = Release|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Release|x86.ActiveCfg = Release|Any CPU + {F7D0F851-9B0D-4224-91AB-7FC12477F206}.Release|x86.Build.0 = Release|Any CPU {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Debug|Any CPU.Build.0 = Debug|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Debug|x64.ActiveCfg = Debug|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Debug|x64.Build.0 = Debug|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Debug|x86.ActiveCfg = Debug|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Debug|x86.Build.0 = Debug|Any CPU {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Release|Any CPU.ActiveCfg = Release|Any CPU {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Release|Any CPU.Build.0 = Release|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Release|x64.ActiveCfg = Release|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Release|x64.Build.0 = Release|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Release|x86.ActiveCfg = Release|Any CPU + {F3973FE4-DF1B-44C4-8D9C-2DE4B159CA69}.Release|x86.Build.0 = Release|Any CPU {6BAC7496-6953-41B8-9042-AAE45405A095}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {6BAC7496-6953-41B8-9042-AAE45405A095}.Debug|Any CPU.Build.0 = Debug|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Debug|x64.ActiveCfg = Debug|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Debug|x64.Build.0 = Debug|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Debug|x86.ActiveCfg = Debug|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Debug|x86.Build.0 = Debug|Any CPU {6BAC7496-6953-41B8-9042-AAE45405A095}.Release|Any CPU.ActiveCfg = Release|Any CPU {6BAC7496-6953-41B8-9042-AAE45405A095}.Release|Any CPU.Build.0 = Release|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Release|x64.ActiveCfg = Release|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Release|x64.Build.0 = Release|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Release|x86.ActiveCfg = Release|Any CPU + {6BAC7496-6953-41B8-9042-AAE45405A095}.Release|x86.Build.0 = Release|Any CPU {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Debug|Any CPU.Build.0 = Debug|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Debug|x64.ActiveCfg = Debug|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Debug|x64.Build.0 = Debug|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Debug|x86.ActiveCfg = Debug|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Debug|x86.Build.0 = Debug|Any CPU {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Release|Any CPU.ActiveCfg = Release|Any CPU {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Release|Any CPU.Build.0 = Release|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Release|x64.ActiveCfg = Release|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Release|x64.Build.0 = Release|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Release|x86.ActiveCfg = Release|Any CPU + {CE854091-F55D-4AD1-AA57-49CB9B60CAC0}.Release|x86.Build.0 = Release|Any CPU {80345889-A13D-4F2D-A096-98B95C55BF45}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {80345889-A13D-4F2D-A096-98B95C55BF45}.Debug|Any CPU.Build.0 = Debug|Any CPU + {80345889-A13D-4F2D-A096-98B95C55BF45}.Debug|x64.ActiveCfg = Debug|x64 + {80345889-A13D-4F2D-A096-98B95C55BF45}.Debug|x64.Build.0 = Debug|x64 + {80345889-A13D-4F2D-A096-98B95C55BF45}.Debug|x86.ActiveCfg = Debug|Any CPU + {80345889-A13D-4F2D-A096-98B95C55BF45}.Debug|x86.Build.0 = Debug|Any CPU {80345889-A13D-4F2D-A096-98B95C55BF45}.Release|Any CPU.ActiveCfg = Release|Any CPU {80345889-A13D-4F2D-A096-98B95C55BF45}.Release|Any CPU.Build.0 = Release|Any CPU + {80345889-A13D-4F2D-A096-98B95C55BF45}.Release|x64.ActiveCfg = Release|x64 + {80345889-A13D-4F2D-A096-98B95C55BF45}.Release|x64.Build.0 = Release|x64 + {80345889-A13D-4F2D-A096-98B95C55BF45}.Release|x86.ActiveCfg = Release|Any CPU + {80345889-A13D-4F2D-A096-98B95C55BF45}.Release|x86.Build.0 = Release|Any CPU {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Debug|Any CPU.Build.0 = Debug|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Debug|x64.ActiveCfg = Debug|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Debug|x64.Build.0 = Debug|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Debug|x86.ActiveCfg = Debug|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Debug|x86.Build.0 = Debug|Any CPU {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Release|Any CPU.ActiveCfg = Release|Any CPU {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Release|Any CPU.Build.0 = Release|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Release|x64.ActiveCfg = Release|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Release|x64.Build.0 = Release|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Release|x86.ActiveCfg = Release|Any CPU + {91DFAE19-098F-4E19-B81D-6CB36A9020D6}.Release|x86.Build.0 = Release|Any CPU {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Debug|Any CPU.Build.0 = Debug|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Debug|x64.ActiveCfg = Debug|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Debug|x64.Build.0 = Debug|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Debug|x86.ActiveCfg = Debug|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Debug|x86.Build.0 = Debug|Any CPU {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Release|Any CPU.ActiveCfg = Release|Any CPU {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Release|Any CPU.Build.0 = Release|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Release|x64.ActiveCfg = Release|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Release|x64.Build.0 = Release|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Release|x86.ActiveCfg = Release|Any CPU + {E6EACF92-F22D-47DC-8EEB-9BBC4DF1E4D5}.Release|x86.Build.0 = Release|Any CPU {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Debug|Any CPU.Build.0 = Debug|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Debug|x64.ActiveCfg = Debug|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Debug|x64.Build.0 = Debug|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Debug|x86.ActiveCfg = Debug|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Debug|x86.Build.0 = Debug|Any CPU {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Release|Any CPU.ActiveCfg = Release|Any CPU {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Release|Any CPU.Build.0 = Release|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Release|x64.ActiveCfg = Release|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Release|x64.Build.0 = Release|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Release|x86.ActiveCfg = Release|Any CPU + {C42873F2-D4A5-4AC7-9ADB-9CD8E1856A9B}.Release|x86.Build.0 = Release|Any CPU {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Debug|Any CPU.Build.0 = Debug|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Debug|x64.ActiveCfg = Debug|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Debug|x64.Build.0 = Debug|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Debug|x86.ActiveCfg = Debug|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Debug|x86.Build.0 = Debug|Any CPU {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Release|Any CPU.ActiveCfg = Release|Any CPU {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Release|Any CPU.Build.0 = Release|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Release|x64.ActiveCfg = Release|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Release|x64.Build.0 = Release|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Release|x86.ActiveCfg = Release|Any CPU + {B9384E1B-54B5-4A41-85BD-EBAD0577BDCD}.Release|x86.Build.0 = Release|Any CPU {19281902-FBC4-48C0-962B-9FDADAF5C783}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {19281902-FBC4-48C0-962B-9FDADAF5C783}.Debug|Any CPU.Build.0 = Debug|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Debug|x64.ActiveCfg = Debug|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Debug|x64.Build.0 = Debug|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Debug|x86.ActiveCfg = Debug|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Debug|x86.Build.0 = Debug|Any CPU {19281902-FBC4-48C0-962B-9FDADAF5C783}.Release|Any CPU.ActiveCfg = Release|Any CPU {19281902-FBC4-48C0-962B-9FDADAF5C783}.Release|Any CPU.Build.0 = Release|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Release|x64.ActiveCfg = Release|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Release|x64.Build.0 = Release|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Release|x86.ActiveCfg = Release|Any CPU + {19281902-FBC4-48C0-962B-9FDADAF5C783}.Release|x86.Build.0 = Release|Any CPU {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Debug|Any CPU.Build.0 = Debug|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Debug|x64.ActiveCfg = Debug|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Debug|x64.Build.0 = Debug|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Debug|x86.ActiveCfg = Debug|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Debug|x86.Build.0 = Debug|Any CPU {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Release|Any CPU.ActiveCfg = Release|Any CPU {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Release|Any CPU.Build.0 = Release|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Release|x64.ActiveCfg = Release|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Release|x64.Build.0 = Release|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Release|x86.ActiveCfg = Release|Any CPU + {F7419073-A62B-42E0-9B8C-4C2C4CE243A3}.Release|x86.Build.0 = Release|Any CPU {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Debug|Any CPU.Build.0 = Debug|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Debug|x64.ActiveCfg = Debug|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Debug|x64.Build.0 = Debug|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Debug|x86.ActiveCfg = Debug|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Debug|x86.Build.0 = Debug|Any CPU {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Release|Any CPU.ActiveCfg = Release|Any CPU {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Release|Any CPU.Build.0 = Release|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Release|x64.ActiveCfg = Release|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Release|x64.Build.0 = Release|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Release|x86.ActiveCfg = Release|Any CPU + {A0248EF2-8C39-478A-951E-324DDF4FF3EC}.Release|x86.Build.0 = Release|Any CPU {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Debug|Any CPU.Build.0 = Debug|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Debug|x64.ActiveCfg = Debug|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Debug|x64.Build.0 = Debug|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Debug|x86.ActiveCfg = Debug|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Debug|x86.Build.0 = Debug|Any CPU {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Release|Any CPU.ActiveCfg = Release|Any CPU {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Release|Any CPU.Build.0 = Release|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Release|x64.ActiveCfg = Release|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Release|x64.Build.0 = Release|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Release|x86.ActiveCfg = Release|Any CPU + {FE5CC86D-E87E-4560-8004-8852F3DE6794}.Release|x86.Build.0 = Release|Any CPU {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Debug|Any CPU.Build.0 = Debug|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Debug|x64.ActiveCfg = Debug|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Debug|x64.Build.0 = Debug|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Debug|x86.ActiveCfg = Debug|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Debug|x86.Build.0 = Debug|Any CPU {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Release|Any CPU.ActiveCfg = Release|Any CPU {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Release|Any CPU.Build.0 = Release|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Release|x64.ActiveCfg = Release|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Release|x64.Build.0 = Release|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Release|x86.ActiveCfg = Release|Any CPU + {034CB9AF-7E9E-4D96-8F71-526999D284BA}.Release|x86.Build.0 = Release|Any CPU {945509BC-A133-493B-9295-43EC708FD57F}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {945509BC-A133-493B-9295-43EC708FD57F}.Debug|Any CPU.Build.0 = Debug|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Debug|x64.ActiveCfg = Debug|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Debug|x64.Build.0 = Debug|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Debug|x86.ActiveCfg = Debug|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Debug|x86.Build.0 = Debug|Any CPU {945509BC-A133-493B-9295-43EC708FD57F}.Release|Any CPU.ActiveCfg = Release|Any CPU {945509BC-A133-493B-9295-43EC708FD57F}.Release|Any CPU.Build.0 = Release|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Release|x64.ActiveCfg = Release|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Release|x64.Build.0 = Release|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Release|x86.ActiveCfg = Release|Any CPU + {945509BC-A133-493B-9295-43EC708FD57F}.Release|x86.Build.0 = Release|Any CPU {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Debug|Any CPU.Build.0 = Debug|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Debug|x64.ActiveCfg = Debug|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Debug|x64.Build.0 = Debug|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Debug|x86.ActiveCfg = Debug|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Debug|x86.Build.0 = Debug|Any CPU {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Release|Any CPU.ActiveCfg = Release|Any CPU {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Release|Any CPU.Build.0 = Release|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Release|x64.ActiveCfg = Release|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Release|x64.Build.0 = Release|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Release|x86.ActiveCfg = Release|Any CPU + {2D5418E0-6513-4285-8B0D-53A30CBEF242}.Release|x86.Build.0 = Release|Any CPU {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Debug|Any CPU.ActiveCfg = Debug|Any CPU {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Debug|Any CPU.Build.0 = Debug|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Debug|x64.ActiveCfg = Debug|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Debug|x64.Build.0 = Debug|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Debug|x86.ActiveCfg = Debug|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Debug|x86.Build.0 = Debug|Any CPU {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Release|Any CPU.ActiveCfg = Release|Any CPU {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Release|Any CPU.Build.0 = Release|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Release|x64.ActiveCfg = Release|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Release|x64.Build.0 = Release|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Release|x86.ActiveCfg = Release|Any CPU + {121D62F5-0BB7-4DB5-8742-454127DF31F4}.Release|x86.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE diff --git a/src/PerfView/JitStats.cs b/src/PerfView/JitStats.cs index 315d1d11d..88840faa5 100644 --- a/src/PerfView/JitStats.cs +++ b/src/PerfView/JitStats.cs @@ -17,135 +17,185 @@ internal static class JitStats { public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotNetRuntime runtime, string fileName) { - JITStatsEx statsEx = JITStatsEx.Create(runtime); + 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("

JIT Stats for for Process {1,5}: {2}

",stats.ProcessID, stats.ProcessID, stats.Name); writer.WriteLine(""); - } - writer.WriteLine("
  • Total Number of JIT compiled methods : {0:n0}
    • ", runtime.JIT.Stats().Count); - writer.WriteLine("
  • Total MSec JIT compiling : {0:n0}
    • ", runtime.JIT.Stats().TotalCpuTimeMSec); + writer.WriteLine("
    "); + writer.WriteLine(""); + writer.WriteLine("" + + "" + + "" + + "" + + "" + + "" + + ""); + 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)); - if (runtime.JIT.Stats().TotalCpuTimeMSec != 0) - writer.WriteLine("
  • JIT compilation time as a percentage of total process CPU time : {0:f1}%
    • ", runtime.JIT.Stats().TotalCpuTimeMSec * 100.0 / stats.CPUMSec); - writer.WriteLine("
  • Individual JIT Events
    • ", stats.ProcessID); + writer.WriteLine("
    Jitting TriggerNum Compilations% of total jitted compilationsJit Time msecJit Time (% of total process CPU)
    "); + writer.WriteLine("
    "); + writer.WriteLine(""); - writer.WriteLine("", stats.ProcessID); - if (hasInliningEvents) - { - writer.WriteLine("
  • Inlining Decisions
    • ", stats.ProcessID); - writer.WriteLine("", stats.ProcessID); - } - else - { - writer.WriteLine("
  • No JIT Inlining data available. Consider enabling the JITInlining option.
    • "); - } - writer.WriteLine("
  • JIT Perf Users Guide
    • ", usersGuideFile); - writer.WriteLine(""); + // + // Module table + // - if (runtime.JIT.Stats().BackgroundJitThread == 0) - { - if (runtime.JIT.Stats().BackgroundJITEventsOn) + // Sort the module list by Jit Time; + List moduleNames = new List(statsEx.TotalModuleStats.Keys); + moduleNames.Sort(delegate (string x, string y) { - writer.WriteLine("

    " + - "This process does not use background JIT compilation. 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 Guide to Background JIT for more." + - "

    ", usersGuideFile); - } - else - { - writer.WriteLine("

    " + - "Background JIT compilation events are not being collected. 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 Guide to Background JIT for more." + - "

    ", usersGuideFile); - } - } - - writer.WriteLine("

    " + - "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 NGening your application. \r\n" + - "This will improve the startup time for your app. \r\n" + - "

    "); + 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("

    " + - "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" + - "

    "); - // Sort the module list by Jit Time; - List moduleNames = new List(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("
  • Summary of jitting time by module:

    "); + writer.WriteLine("
    "); + writer.WriteLine(""); + writer.WriteLine("" + + "" + + "" + + "" + + "" + + "" + + "" + + "" + + "" + + ""); + + string moduleTableRow = "" + + "" + + "" + + "" + + "" + + "" + + "" + + "" + + "" + + ""; + writer.WriteLine(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); + foreach (string moduleName in moduleNames) + { + JITStats info = statsEx.TotalModuleStats[moduleName]; + writer.WriteLine(moduleTableRow, + moduleName.Length == 0 ? "<UNKNOWN>" : moduleName, + info.TotalCpuTimeMSec, + info.Count, + info.TotalILSize, + info.TotalNativeSize, + info.TotalForegroundCpuTimeMSec, + info.TotalBackgroundMultiCoreJitCpuTimeMSec, + info.TotalBackgroundTieredCompilationCpuTimeMSec); + } + writer.WriteLine("
    NameJitTime
    msec    		Num CompilationsIL SizeNative Size" + GetLongNameForThreadClassification(CompilationThreadKind.Foreground) + "
    msec    		" + GetLongNameForThreadClassification(CompilationThreadKind.MulticoreJitBackground) + "
    msec    		" + GetLongNameForThreadClassification(CompilationThreadKind.TieredCompilationBackground) + "
    msec
    {0}{1:n1}{2:n0}{3:n0}{4:n0}{5:n1}{6:n1}{7:n1}
    "); + writer.WriteLine("
    "); + writer.WriteLine("
    • "); - writer.WriteLine("
    "); - writer.WriteLine(""); - writer.WriteLine(""); - writer.WriteLine("", - "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("", - moduleName.Length == 0 ? "<UNKNOWN>" : moduleName, info.TotalCpuTimeMSec, info.Count, info.TotalILSize, info.TotalNativeSize); } - writer.WriteLine("
    NameJitTime
    msec    		Num MethodsIL SizeNative Size
    {0}{1:n1}{2:n0}{3:n0}{4:n0}
    {0}{1:n1}{2:n0}{3:n0}{4:n0}
    "); - writer.WriteLine("
    "); + writer.WriteLine(""); bool backgroundJitEnabled = runtime.JIT.Stats().BackgroundJitThread != 0; @@ -155,12 +205,12 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN // 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("

    Warning: Truncating JIT events to " + maxEvents + ". Use 'View in Excel' link above to look all of them

    "); + writer.WriteLine("

    Warning: Truncating JIT events to " + maxEvents + ". View in excel to look all of them.

    ", stats.ProcessID); writer.WriteLine("
    "); writer.WriteLine(""); writer.Write("" + - ""); + ""); if (backgroundJitEnabled) { writer.Write(""); @@ -170,12 +220,12 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN foreach (TraceJittedMethod _event in runtime.JIT.Methods) { writer.Write("", - _event.StartTimeMSec, _event.CompileCpuTimeMSec, _event.ILSize, _event.NativeSize, _event.MethodName ?? " ", (_event.IsBackGround ? "BG" : "JIT"), + _event.StartTimeMSec, _event.CompileCpuTimeMSec, _event.ILSize, _event.NativeSize, _event.MethodName ?? " ", GetShortNameForThreadClassification(_event.CompilationThreadKind), _event.ModuleILPath.Length != 0 ? Path.GetFileName(_event.ModuleILPath) : "<UNKNOWN>"); if (backgroundJitEnabled) { writer.Write("", - _event.DistanceAhead, _event.IsBackGround ? "Not blocked" : _event.BlockedReason); + _event.DistanceAhead, _event.CompilationThreadKind == CompilationThreadKind.MulticoreJitBackground ? "Not blocked" : _event.BlockedReason); } writer.WriteLine(""); eventCount++; @@ -214,19 +264,72 @@ public static void ToHtml(TextWriter writer, TraceProcess stats, TraceLoadedDotN writer.WriteLine("


    "); } + private static string FormatThreadingModelTableRow(CompilationThreadKind kind, long count, double jitTimeMsec, TraceProcess stats, TraceLoadedDotNetRuntime runtime) + { + return FormatThreadingModelTableRow(GetLongNameForThreadClassification(kind), count, jitTimeMsec, stats, runtime); + } + + private static string FormatThreadingModelTableRow(string name, long count, double jitTimeMsec, TraceProcess stats, TraceLoadedDotNetRuntime runtime) + { + var countPercent = runtime.JIT.Stats().Count == 0 ? "-" : (count * 100.0 / runtime.JIT.Stats().Count).ToString("N1"); + var cpuPercent = stats.CPUMSec == 0 ? "-" : (jitTimeMsec * 100.0 / stats.CPUMSec).ToString("N1"); + return string.Format("", + name, count, countPercent, jitTimeMsec, cpuPercent); + } + + static string GetShortNameForThreadClassification(CompilationThreadKind kind) + { + if(kind == CompilationThreadKind.Foreground) + { + return "FG"; + } + else if(kind == CompilationThreadKind.MulticoreJitBackground) + { + return "MC"; + } + else if(kind == CompilationThreadKind.TieredCompilationBackground) + { + return "TC"; + } + else + { + throw new ArgumentException("Unknown CompilationThreadKind: " + kind); + } + } + + static string GetLongNameForThreadClassification(CompilationThreadKind kind) + { + if (kind == CompilationThreadKind.Foreground) + { + return "Foreground"; + } + else if (kind == CompilationThreadKind.MulticoreJitBackground) + { + return "Multicore JIT Background"; + } + else if (kind == CompilationThreadKind.TieredCompilationBackground) + { + return "Tiered Compilation Background"; + } + else + { + throw new ArgumentException("Unknown CompilationThreadKind: " + kind); + } + } + public static void ToCsv(string filePath, TraceLoadedDotNetRuntime runtime) { var listSeparator = Thread.CurrentThread.CurrentCulture.TextInfo.ListSeparator; using (var writer = File.CreateText(filePath)) { - writer.WriteLine("Start MSec{0}JitTime MSec{0}ThreadID{0}IL Size{0}Native Size{0}MethodName{0}BG{0}Module{0}DistanceAhead{0}BlockedReason", listSeparator); + writer.WriteLine("Start MSec{0}JitTime MSec{0}ThreadID{0}IL Size{0}Native Size{0}MethodName{0}Trigger{0}Module{0}DistanceAhead{0}BlockedReason", listSeparator); for (int i = 0; i < runtime.JIT.Methods.Count; i++) { var _event = runtime.JIT.Methods[i]; var csvMethodName = _event.MethodName.Replace(",", " "); // Insure there are no , in the name writer.WriteLine("{1:f3}{0}{2:f3}{0}{3}{0}{4}{0}{5}{0}{6}{0}{7}{0}{8}{0}{9}{0}{10}", listSeparator, _event.StartTimeMSec, _event.CompileCpuTimeMSec, _event.ThreadID, _event.ILSize, - _event.NativeSize, csvMethodName, (_event.IsBackGround ? "BG" : "JIT"), _event.ModuleILPath, _event.DistanceAhead, _event.BlockedReason); + _event.NativeSize, csvMethodName, GetShortNameForThreadClassification(_event.CompilationThreadKind), _event.ModuleILPath, _event.DistanceAhead, _event.BlockedReason); } } } @@ -369,15 +472,7 @@ public static JITStatsEx Create(TraceLoadedDotNetRuntime mang) stats.TotalBGJITStats = new JITStats(); foreach (TraceJittedMethod _method in mang.JIT.Methods) { - if (_method.ThreadID == mang.JIT.Stats().BackgroundJitThread) - { - _method.IsBackGround = true; - // update stats - stats.TotalBGJITStats.Count++; - stats.TotalBGJITStats.TotalCpuTimeMSec += _method.CompileCpuTimeMSec; - stats.TotalBGJITStats.TotalILSize += _method.ILSize; - stats.TotalBGJITStats.TotalNativeSize += _method.NativeSize; - } + stats.TotalBGJITStats.Update(_method); } } @@ -387,12 +482,12 @@ public static JITStatsEx Create(TraceLoadedDotNetRuntime mang) { if (_method.ModuleILPath != null) { - if (!stats.TotalModuleStats.ContainsKey(_method.ModuleILPath)) stats.TotalModuleStats.Add(_method.ModuleILPath, new JITStats()); - // update stats - stats.TotalModuleStats[_method.ModuleILPath].Count++; - stats.TotalModuleStats[_method.ModuleILPath].TotalCpuTimeMSec += _method.CompileCpuTimeMSec; - stats.TotalModuleStats[_method.ModuleILPath].TotalILSize += _method.ILSize; - stats.TotalModuleStats[_method.ModuleILPath].TotalNativeSize += _method.NativeSize; + if (!stats.TotalModuleStats.ContainsKey(_method.ModuleILPath)) + { + stats.TotalModuleStats.Add(_method.ModuleILPath, new JITStats()); + } + JITStats moduleStats = stats.TotalModuleStats[_method.ModuleILPath]; + moduleStats.Update(_method); } } diff --git a/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm b/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm index f14fc18dd..6afc8abbe 100644 --- a/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm +++ b/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm @@ -62,16 +62,51 @@

    Understanding Just In Time Compiler Performance Data

    - PerfView tracks detailed information of what methods - were Just In Time compiled.   This data is mostly useful for - optimizing startup (because that is when most methods get JIT compiled).  - If large numbers of methods are being compiled it can noticeably affect startup - time.  This report tells you exactly how much time is being spent (in fact - exactly which methods and exactly when they were compiled).   If JIT - time is high, the - NGen - Tool can be used to precompile the code, and thus eliminate most of this - overhead at startup. 

    + PerfView tracks detailed information of what methods were Just In Time compiled. + This data is mostly useful for optimizing startup (because that is when most + methods get JIT compiled). If large numbers of methods are being compiled it + can noticeably affect startup time. This report tells you why the JIT was + invoked and exactly how much time is being spent on each compilation. +

    + The summary statistics show JIT time broken down by the three different ways the + JIT can be triggered. First, foreground jitting occurs when a thread running managed + code wants to invoke a particular method that has not yet been compiled, in which + case the JIT is invoked synchronously to produce the code. Second, background + jitting occurs when the runtime predicts a method will be invoked in the future + and then pre-emptively invokes the JIT to compile it on a background thread. These + compilations occur in parallel with compilations on the foreground thread and + thus reduce total startup time. Third, tiered compilation is a feature that compiles + code a second time to generate higher quality code for frequently used methods. + Most tiered compilation JIT activity should not occur right at startup, but + rather very shortly afterwards. The JIT time used for tiered compilation determines + how quickly after startup the application transitions from running at a modest + speed to running at an optimal steady-state speed. +

    + If there is a large amount of time spent in the sum of Foreground and Multicore JIT + Background compilations then this can cause the application to start slowly. There + are several techniques to improve the startup performance. +

      +
    • + Precompile the code - On Desktop .NET the + + NGen Tool + can be used. On .Net Core + + Crossgen + can be used instead. Note that the ReadyToRun format produced by the crossgen tool + does not handle compiling generic code over value types so the number of compilations + at runtime will decrease substantially but it will often not go to zero. +
      • +
    • + Use Background jitting +
      • +
    • + On .Net Core 2.1 and above use Tiered compilation +
      • +
    • + Attempt to restructure your code so that less of it is invoked in the startup path. +
      • +

    As an additional option enabled with the JITInlining feature, PerfView can track all of the decisions made by the JIT about whether to inline or not at every call site. @@ -85,11 +120,16 @@

    by the developer to tweak their code in pursuit of a faster outcome.

    -

    - Understanding Background JIT compilation

    -

    Background JIT compilation is a feature that was introduced in Version 4.5 of the .NET runtime.   The basic idea is to take advantage of multiple processors available on most machines to speed up startup time by doing Just in Time (JIT) compilation on a background thread.     Note that the .NET runtime's preferred solution to the cost o JIT compilation is to precompile the code with NGEN.   This reduces the cost of JIT compilation to 0, where background JIT compilation cannot do nearly as well (it tends to reduce it by half), so using NGEN as part of application deployment should be considered first.  However if  using the - NGen - Tool is impossible (XCOPY deployment, non-admin deployment, silverlight, IL code generated at runtime), background JIT is the next best option. 

    +

    + Understanding Background JIT compilation +

    +

    + Background JIT compilation is a feature that was introduced in Version 4.5 of the .NET runtime.   The basic idea is to take advantage of multiple processors available on most machines to speed up startup time by doing Just in Time (JIT) compilation on a background thread.     Note that the .NET runtime's preferred solution to the cost o JIT compilation is to precompile the code with NGEN.   This reduces the cost of JIT compilation to 0, where background JIT compilation cannot do nearly as well (it tends to reduce it by half), so using NGEN as part of application deployment should be considered first.  However if  using the + + NGen + Tool + is impossible (XCOPY deployment, non-admin deployment, silverlight, IL code generated at runtime), background JIT is the next best option.  +

    There is a fundamental problem trying to push JIT compilation onto background threads, namely that the set of methods you will want to JIT compile depends on program execution and is not known until just before the method is used.  Thus to take advantage of multiple processors you need 'oracle' that will tell you the methods you need to compile well before you will actually need to execute them. 

    The solution that the runtime uses is to rely on PREVIOUS runs of the same program to act as this oracle that will predict the methods that need to be compiled.  For this to work the runtime will need to store on disk information about what methods were JIT compiled on the last run.   Moreover, you really don't want the COMPLETE list of methods compiled because that list will include methods use well after startup and cause you to JIT compile things that are not that important.   Thus to make background JIT compilation work well, we need help from the application.   This is exposed in two new methods of the System.Runtime.ProfilerOptimization class introduced in .NET Version 4.5

      @@ -120,30 +160,56 @@

      Expected Win from Background JIT Compilation

      Viewing Background JIT Compilation events. 

      If you have activated background JIT by placing the SetProfileRoot and StartProfile calls into your program you can view its effectiveness by turning on special background JIT compilation events.  You do this by checking the 'Background JIT' checkbox on the advanced options of the 'Collection' dialog box.  When you do this, the JITStats report is enhanced in several ways for processes that have called SetProfileRoot and StartProfile.

        -
      1. For that process, a set of top level statistics are displayed indicating how many JIT compilations happened in the background.  The most important of these metrics is the 'JIT time NOT moved to background thread'.  This is the JIT time that matters because it is left on the foreground thread where it slows down the application.  The difference between this number and the JIT time on a run without background JIT is the 'win' of performing this optimization. 
        2. +
      2. Each process has a set of top level statistics indicating how many JIT compilations happened in the foreground and background.  Any JIT time that remains on the foreground thread slows down the application startup.  The difference between the foreground times on runs with and without background JIT is the 'win' of performing this optimization. 
      3. There is a hyperlink to the a CSV spreadsheet displaying detailed diagnostics of the what was JIT compiled in the background as well as what was recorded for the next launch of the program. 
        4. -
      4. The 'BG' column of each JIT compiled method is set to indicate whether the JIT compilation happened in the background or not.
        5. +
      5. The 'Trigger' column of each method indicates whether the compilation happened in the foreground.

      What can go wrong with background JIT compilation.

      -

      It your program has used SetProfileRoot and StartProfile, but JIT compilation (as shown in the JITStats view) does not show any or very little background JIT compilation, there are several issues that may be responsible.   Fundamentally a important design goal was to insure that background JIT compilation did not change the behavior of the program under any circumstances.    Unfortunately, it means that the algorithm tends to bail out quickly.   In particular

      +

      It your program has used SetProfileRoot and StartProfile, but JIT compilation (as shown in the JITStats view) does not show any or very little background JIT compilation, there are several issues that may be responsible.   Fundamentally a important design goal was to insure that background JIT compilation did not change the behavior of the program under any circumstances.    Unfortunately, it means that the algorithm tends to bail out quickly.   In particular

      1. When modules are loaded, a module constructor could be called, which could have side effects (even this is very rare).   Thus if background JITTing would cause a module to be loaded earlier than it otherwise would be, it could expose (rare) bugs.  Because background JIT had a very high compatibility bar, it protects against this by taging each method with the EXACT modules that were loaded at the time of JIT compilation, and only allows them to be background JIT compiled after all those EXACT modules were also loaded in the current run.   Thus if you have a scenario (say a menu opening), where sometimes more or fewer modules are loaded (because previous user actions caused different modules to load), then background JIT may not work well. 
      2. If you have attached a callback to the System.Assembly.ModuleResolve event, it is possible (although extremely unlikely and very bad design) that background JITing could have side effects if the ModuleResolve callback returned different answers on the second run than it did on the first run.   Because of this background JIT compilation is suspended the first time an ModuleResolve callback in invoked.
      3. Because any module lookup that fails, WILL call the ModuleResolve event before it finally fails, this means that any probing for modules which fail will also inhibit background JIT compilation. 
      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      -

       

      +
      +

      + Understanding Tiered Compilation +

      +

      Tiered compilation is a feature that was introduced in .Net Core 2.1. It improves both startup performance and steady-state performance by hot-swapping between different compilations of the same method at runtime.

      +
        +
      1. Startup perf wins - The runtime requests that the JIT use minimal optimizations the first time a method is compiled. Later if the method is called frequently the method will be recompiled with more optimizations. This recompilation occurs on a background thread in parallel with other activity.
        2. +
      2. Steady-state perf wins - The runtime will identify frequently called methods whose code was originally loaded from ReadyToRun (aka crossgen) images and recompile it using the JIT. The jitted code is often more performant than the original because it can take advantage of additional information that is only known at runtime.
        3. +
      +

      Different compilations of the same method are refered to as tiers, and as of .Net Core 2.1 there are two of them, 'Tier0' and 'Tier1'. Tier0 is the initial code for each method, regardless whether it was obtained from the JIT or from a ReadyToRun image. Tier1 refers to the optimized jitted code that is compiled on a background thread

      +

      Enabling tiered compilation

      +

      In .Net Core 2.1 tiered compilation is an opt-in preview feature. It can be enabled either by any of these mechanisms:

      +
        +
      1. Set an app config switch in runtimeconfig.json "System.Runtime.TieredCompilation": "true"
        2. +
      2. Set the msbuild property <TieredCompilation>true</TieredCompilation> in the application's project file
        3. +
      3. Set the environment variable COMPlus_TieredCompilation=1
        4. +
      +

      Understanding Tiered Compilation events

      +

      Each process shows a high level summary table indicating JIT time broken down by trigger. One of these triggers is 'Tiered Compilation Background.' This category contains all the Tier1 methods. + The tier0 methods aren't identified explicitly as they can come from several sources:

      +
        +
      1. If the method is present in a precompiled ReadyToRun image then the JIT was not run. There is no accounting in the JITStats view for code loaded from images.
        2. +
      2. The method could be jitted by a foreground thread just prior to its first execution, in which case it is contained in the 'Foreground' group
        3. +
      3. If the Background JIT feature is enabled the method's usage may have been accurately predicted and jitted in advance on the Multicore JIT background thread, in which case it is accounted for in the 'Multicore JIT Background' group
        4. +
      +

      In the individual method listings the column 'Trigger' contains the value 'TC' for each Tier1 background recompilation due to Tiered compilation

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      +

       

      diff --git a/src/TraceEvent/Computers/TraceManagedProcess.cs b/src/TraceEvent/Computers/TraceManagedProcess.cs index 0444cc644..d31d5dc65 100644 --- a/src/TraceEvent/Computers/TraceManagedProcess.cs +++ b/src/TraceEvent/Computers/TraceManagedProcess.cs @@ -1131,7 +1131,7 @@ internal static void SetupCallbacks(TraceEventDispatcher source) var stats = currentManagedProcess(data); bool createdNewMethod; - var _method = JITStats.MethodComplete(stats, data, data.MethodSize, data.ModuleID, JITStats.GetMethodName(data), data.MethodID, out createdNewMethod); + var _method = JITStats.MethodComplete(stats, data, data.MethodSize, data.ModuleID, JITStats.GetMethodName(data), data.MethodID, (int)data.ReJITID, out createdNewMethod); // fire event - but only once if (createdNewMethod && stats.JITMethodStart != null) stats.JITMethodStart(process, _method); @@ -1147,7 +1147,7 @@ internal static void SetupCallbacks(TraceEventDispatcher source) var stats = currentManagedProcess(data); bool createdNewMethod; - var _method = JITStats.MethodComplete(stats, data, data.MethodSize, data.ModuleID, "", data.MethodID, out createdNewMethod); + var _method = JITStats.MethodComplete(stats, data, data.MethodSize, data.ModuleID, "", data.MethodID, 0, out createdNewMethod); // fire event - but only once if (createdNewMethod && stats.JITMethodStart != null) stats.JITMethodStart(process, _method); @@ -3322,6 +3322,30 @@ public class JITStats /// public double TotalCpuTimeMSec; /// + /// Number of methods JITT'd by foreground threads just prior to execution + /// + public long CountForeground; + /// + /// Total time spent compiling methods on foreground threads + /// + public double TotalForegroundCpuTimeMSec; + /// + /// Number of methods JITT'd by the multicore JIT background threads + /// + public long CountBackgroundMultiCoreJit; + /// + /// Total time spent compiling methods on background threads for multicore JIT + /// + public double TotalBackgroundMultiCoreJitCpuTimeMSec; + /// + /// Number of methods JITT'd by the tiered compilation background threads + /// + public long CountBackgroundTieredCompilation; + /// + /// Total time spent compiling methods on background threads for tiered compilation + /// + public double TotalBackgroundTieredCompilationCpuTimeMSec; + /// /// Total IL size for all JITT'd methods /// public long TotalILSize; @@ -3391,19 +3415,34 @@ public class JITStats /// Update method statistics /// /// - internal void Update(TraceJittedMethod _method) + public void Update(TraceJittedMethod _method) { Count++; TotalCpuTimeMSec += _method.CompileCpuTimeMSec; TotalILSize += _method.ILSize; TotalNativeSize += _method.NativeSize; + if (_method.CompilationThreadKind == CompilationThreadKind.MulticoreJitBackground) + { + CountBackgroundMultiCoreJit++; + TotalBackgroundMultiCoreJitCpuTimeMSec += _method.CompileCpuTimeMSec; + } + else if (_method.CompilationThreadKind == CompilationThreadKind.TieredCompilationBackground) + { + CountBackgroundTieredCompilation++; + TotalBackgroundTieredCompilationCpuTimeMSec += _method.CompileCpuTimeMSec; + } + else if(_method.CompilationThreadKind == CompilationThreadKind.Foreground) + { + CountForeground++; + TotalForegroundCpuTimeMSec += _method.CompileCpuTimeMSec; + } } #region private /// /// Legacgy /// - internal static TraceJittedMethod MethodComplete(TraceLoadedDotNetRuntime stats, TraceEvent data, int methodNativeSize, long moduleID, string methodName, long methodID, out bool createdNewMethod) + internal static TraceJittedMethod MethodComplete(TraceLoadedDotNetRuntime stats, TraceEvent data, int methodNativeSize, long moduleID, string methodName, long methodID, int rejitID, out bool createdNewMethod) { TraceJittedMethod _method = stats.JIT.m_stats.FindIncompleteJitEventOnThread(stats, data.ThreadID); createdNewMethod = false; @@ -3426,6 +3465,19 @@ internal static TraceJittedMethod MethodComplete(TraceLoadedDotNetRuntime stats, } _method.NativeSize = methodNativeSize; _method.CompileCpuTimeMSec = data.TimeStampRelativeMSec - _method.StartTimeMSec; + _method.VersionID = rejitID; + + if(stats.JIT.Stats().BackgroundJitThread != 0 && _method.ThreadID == stats.JIT.Stats().BackgroundJitThread) + { + _method.CompilationThreadKind = CompilationThreadKind.MulticoreJitBackground; + } + else + { + // This isn't always true, but we don't yet have enough data to distinguish tiered compilation from other causes of versioned compilation (ie profiler ReJIT) + _method.CompilationThreadKind = _method.IsDefaultVersion ? CompilationThreadKind.Foreground : CompilationThreadKind.TieredCompilationBackground; + + } + _method.Completed++; stats.JIT.m_stats.Update(_method); @@ -3586,6 +3638,13 @@ public struct InliningFailureResult public string Reason; } + public enum CompilationThreadKind + { + Foreground, + MulticoreJitBackground, + TieredCompilationBackground + } + /// /// Per method information /// @@ -3620,9 +3679,9 @@ public class TraceJittedMethod /// public int ThreadID; /// - /// Indication of if it was JIT'd in the background + /// Indication of if it was JIT'd in the background and why /// - public bool IsBackGround; + public CompilationThreadKind CompilationThreadKind; /// /// Amount of time the method was forcasted to JIT /// @@ -3665,6 +3724,14 @@ public string BlockedReason /// public double RunCpuTimeMSec; + /// + /// The version id that is created by the runtime code versioning feature. This is an incrementing counter that starts at 0 for each method. + /// The ETW events historically name this as the ReJITID event parameter in the payload, but we have now co-opted its usage. + /// + public int VersionID; + + public bool IsDefaultVersion { get { return VersionID == 0; } } + #region private /// /// Legacy From 4229ccb673fab1761e722bb3fc389129e605e972 Mon Sep 17 00:00:00 2001 From: noahfalk Date: Wed, 16 May 2018 17:25:35 -0700 Subject: [PATCH 2/2] Addressing code review feedback --- src/PerfView/JitStats.cs | 4 +- .../SupportFiles/HtmlReportUsersGuide.htm | 4 +- .../Computers/TraceManagedProcess.cs | 37 ++++++++++++------- 3 files changed, 28 insertions(+), 17 deletions(-) diff --git a/src/PerfView/JitStats.cs b/src/PerfView/JitStats.cs index 88840faa5..89f71cabe 100644 --- a/src/PerfView/JitStats.cs +++ b/src/PerfView/JitStats.cs @@ -472,7 +472,7 @@ public static JITStatsEx Create(TraceLoadedDotNetRuntime mang) stats.TotalBGJITStats = new JITStats(); foreach (TraceJittedMethod _method in mang.JIT.Methods) { - stats.TotalBGJITStats.Update(_method); + stats.TotalBGJITStats.AddMethodToStatistics(_method); } } @@ -487,7 +487,7 @@ public static JITStatsEx Create(TraceLoadedDotNetRuntime mang) stats.TotalModuleStats.Add(_method.ModuleILPath, new JITStats()); } JITStats moduleStats = stats.TotalModuleStats[_method.ModuleILPath]; - moduleStats.Update(_method); + moduleStats.AddMethodToStatistics(_method); } } diff --git a/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm b/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm index 6afc8abbe..1e60c8654 100644 --- a/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm +++ b/src/PerfView/SupportFiles/HtmlReportUsersGuide.htm @@ -165,7 +165,7 @@

      Viewing Background JIT Compilation events. 

    1. The 'Trigger' column of each method indicates whether the compilation happened in the foreground.

    What can go wrong with background JIT compilation.

    -

    It your program has used SetProfileRoot and StartProfile, but JIT compilation (as shown in the JITStats view) does not show any or very little background JIT compilation, there are several issues that may be responsible.   Fundamentally a important design goal was to insure that background JIT compilation did not change the behavior of the program under any circumstances.    Unfortunately, it means that the algorithm tends to bail out quickly.   In particular

    +

    If your program has used SetProfileRoot and StartProfile, but JIT compilation (as shown in the JITStats view) does not show any or very little background JIT compilation, there are several issues that may be responsible.   Fundamentally a important design goal was to insure that background JIT compilation did not change the behavior of the program under any circumstances.    Unfortunately, it means that the algorithm tends to bail out quickly.   In particular

    1. When modules are loaded, a module constructor could be called, which could have side effects (even this is very rare).   Thus if background JITTing would cause a module to be loaded earlier than it otherwise would be, it could expose (rare) bugs.  Because background JIT had a very high compatibility bar, it protects against this by taging each method with the EXACT modules that were loaded at the time of JIT compilation, and only allows them to be background JIT compiled after all those EXACT modules were also loaded in the current run.   Thus if you have a scenario (say a menu opening), where sometimes more or fewer modules are loaded (because previous user actions caused different modules to load), then background JIT may not work well. 
    2. If you have attached a callback to the System.Assembly.ModuleResolve event, it is possible (although extremely unlikely and very bad design) that background JITing could have side effects if the ModuleResolve callback returned different answers on the second run than it did on the first run.   Because of this background JIT compilation is suspended the first time an ModuleResolve callback in invoked.
      3. @@ -196,7 +196,7 @@

      Understanding Tiered Compilation events

    3. The method could be jitted by a foreground thread just prior to its first execution, in which case it is contained in the 'Foreground' group
    4. If the Background JIT feature is enabled the method's usage may have been accurately predicted and jitted in advance on the Multicore JIT background thread, in which case it is accounted for in the 'Multicore JIT Background' group
    -

    In the individual method listings the column 'Trigger' contains the value 'TC' for each Tier1 background recompilation due to Tiered compilation

    +

    In the individual method listings the column 'Trigger' contains the value 'TC' for each Tier1 background recompilation due to Tiered Compilation

     

     

     

    diff --git a/src/TraceEvent/Computers/TraceManagedProcess.cs b/src/TraceEvent/Computers/TraceManagedProcess.cs index d31d5dc65..116915f1a 100644 --- a/src/TraceEvent/Computers/TraceManagedProcess.cs +++ b/src/TraceEvent/Computers/TraceManagedProcess.cs @@ -3412,29 +3412,29 @@ public class JITStats public HashSet SymbolsMissing = new HashSet(); /// - /// Update method statistics + /// Aggregate a method to be included in the statistics /// - /// - public void Update(TraceJittedMethod _method) + /// + public void AddMethodToStatistics(TraceJittedMethod method) { Count++; - TotalCpuTimeMSec += _method.CompileCpuTimeMSec; - TotalILSize += _method.ILSize; - TotalNativeSize += _method.NativeSize; - if (_method.CompilationThreadKind == CompilationThreadKind.MulticoreJitBackground) + TotalCpuTimeMSec += method.CompileCpuTimeMSec; + TotalILSize += method.ILSize; + TotalNativeSize += method.NativeSize; + if (method.CompilationThreadKind == CompilationThreadKind.MulticoreJitBackground) { CountBackgroundMultiCoreJit++; - TotalBackgroundMultiCoreJitCpuTimeMSec += _method.CompileCpuTimeMSec; + TotalBackgroundMultiCoreJitCpuTimeMSec += method.CompileCpuTimeMSec; } - else if (_method.CompilationThreadKind == CompilationThreadKind.TieredCompilationBackground) + else if (method.CompilationThreadKind == CompilationThreadKind.TieredCompilationBackground) { CountBackgroundTieredCompilation++; - TotalBackgroundTieredCompilationCpuTimeMSec += _method.CompileCpuTimeMSec; + TotalBackgroundTieredCompilationCpuTimeMSec += method.CompileCpuTimeMSec; } - else if(_method.CompilationThreadKind == CompilationThreadKind.Foreground) + else if(method.CompilationThreadKind == CompilationThreadKind.Foreground) { CountForeground++; - TotalForegroundCpuTimeMSec += _method.CompileCpuTimeMSec; + TotalForegroundCpuTimeMSec += method.CompileCpuTimeMSec; } } @@ -3479,7 +3479,7 @@ internal static TraceJittedMethod MethodComplete(TraceLoadedDotNetRuntime stats, } _method.Completed++; - stats.JIT.m_stats.Update(_method); + stats.JIT.m_stats.AddMethodToStatistics(_method); return _method; } @@ -3679,6 +3679,17 @@ public class TraceJittedMethod /// public int ThreadID; /// + /// Indication of if it was JIT'd in the background + /// + [Obsolete("Use CompilationThreadKind")] + public bool IsBackground + { + get + { + return CompilationThreadKind != CompilationThreadKind.Foreground; + } + } + /// /// Indication of if it was JIT'd in the background and why /// public CompilationThreadKind CompilationThreadKind;
    Start (msec)JitTime
    msec    		IL SizeNative SizeMethod NameBGModuleTriggerModuleDistance AheadBackground JIT Blocking Reason
    {0:n3}{1:n1}{2:n0}{3:n0}{4}{5}{6}{0:n3}{1}
    {0}{1}{2}{3:F1}{4}