Understanding Garbage Collection (GC) Performance Data

By default PerfView causes the Runtime to log an event at the beginning and end of each .NET Garbage Collection as well as every time 100K of objects are allocated.   As with all events the precise time is logged, so the amount of time spent in the GC can be known.    Most applications spend less than 10% of the total CPU time in the GC itself.   If your application is over this %, it usually means that your allocation pattern is such that you are causing many expensive Gen 2 GCs to occur.   

If the GC heap is a large percentage of the total memory used then GC heap optimization then use the Memory->Take Heap Snapshot feature to drill into GC heap usage. See Memory Usage Auditing For .NET Applications for  more on memory optimization.  .

During SOME GCs the application itself has to be suspended so the  GC can update object references.   Thus the application will pause when a GC happens.   If these pause times are larger than 100ms or so, it can impact the user experience.   The GC statistics will track the maximum and average pause time to allow you to confirm that this bad GC behavior is not happening.   

Understanding Finalization Performance Data

By enabling the Finalizers option, PerfView causes the Runtime to log an event every time a managed object is finalized, meaning that its finalizer (denoted in C# with the ~ syntax) is executed. For a detailed look at the costs involved in finalization, see this blog post.

PerfView is unable to determine the stack that allocated a finalizable object, but it is able to accurately report each type of object that had a finalizer executed along with the number of instances of that type that were finalized. This data is shown on the GC Stats report in the Finalized Object Counts table.

In an ideal application implementation, all finalizable objects would be cleaned up deterministically via an object's IDisposable.Dispose implementation, which should suppress the finalization of the object. Not deterministically disposing of finalizable objects can lead to degredation of both the reliability and performance of the app. You can examine the counts reported in the Finalized Object Counts table to determine whether any types have significant numbers of instances being left for finalization. Based on that, you can examine code that creates instances of these types and determine why those instances are being left for non-deterministic cleanup rather than being cleaned up deterministically with Dispose.

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. 

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. For very hot paths, the overhead of invoking methods has the potential to add measurable cost, and it's typical for developers to attempt to streamline their code as much as possible, with the intent that small methods and properties will be inlined in order to avoid these overheads. The information provided by PerfView and the JIT can be valuable in understanding when and where such attempts fail, with the JIT providing the reason it chose not to inline a particular call site, e.g. the callee had exception handling that prevented inlining, the callee was too big, the callee was explicitly annotated to prevent inlining, etc. Such information can then be used 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. 

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

1. SetProfileRoot(string directoryPath) - This method is called once per application (exe) and designates a directory that is writable by the application where the .NET Framework can store data about what JIT compilations happened during the execution of the program.    This directory should be devoted to this purpose (don't put other files in there).   Shared library code typically should NOT call this function because it does not have 'ownership' of such a location, and can't insure that it will only be called once per application. 
2. StartProfile(string scenario name) - This method indicates that you are about to start a operation that is likely to cause JIT compilations to happen.   Typically this is called at the VERY START of your program, or right after a user command (mouse click) that may cause a lot of new code to be executed for the first time.   You can make this call more than once in an application, once for each place where you expect a lot of JIT compilation to happen.

When your code encounters a 'StartProfile' operations the runtime will do the following:

1. It will look for a file in the 'Profile Root' directory (given in the SetProfileRoot call) that matches the name given in the 'StartProfile' call.    If such a file is found it reads the file in and determines if the data in the file is still applicable to this run.  If so it kicks off a background thread that aggressively JIT compiles all the methods on the list.  The StartProfile call returns and all the original threads continue to run as normal.   Hopefully as these threads continue their execution by the time they encounter methods that were not executed before they will find that the background thread has already JIT compiled the method.   The result is that the program runs faster.
2. In addition, the StartProfile call also causes the runtime to remember every method that was ACTUALLY used going forward (note this this may NOT be the same as the list of methods JIT compiled, since background JIT is FORCING methods be be jitted that MIGHT not be used).    It keeps monitoring in this way until a couple of seconds goes by without a method being JIT compiled.  At that point monitoring stops, and a file is written out (overwriting whatever was there before), of the methods that were used.    This file will be used the next time the program is launched.

Thus by placing two simple calls in your program (typically at the beginning of Main()), you can opt into background JIT. 

Background JIT has the following characteristics

1. It does not work on the VERY FIRST launch on a given machine.   There is no profile and thus nothing to act as the 'oracle' that indicates what to compile.
2. It does not work well if what happened on previous launches is a good indication of what will happen this time.  For example if a particular program is typically called with command line arguments that make it do very different things on each launch, then background JIT will not work well for the startup case.
3. It DOES self recover, however.   For example if the program often gets used with one set of command line argument but occasionally get used with another that will cause it to run very different code paths, then it will work well for most launches (but not the unusual command, and the one after it). 
4. You CAN fix the issue described above by introducing more profiles for the same application.   If you have a Profile not at START but at the start of each COMMAND then the runtime will keep a profile for each command and each of those will work well. 
5. Background JIT compilation tends to only be able push about 1/2 the JIT time of the scenario to the background where it does not impact end-to-end time.  This is because often the 'main thread' can 'catch up' to the background thread and need a method before the background thread could finish compiling it.  In a typical case where CPU cost associated with JIT compilation is much larger than execution of the JITTed code, this tends to result in half the methods being compiled by the main thread and half compiled by the background thread.   This is what NGENing is better than background JIT compilation. 

Expected Win from Background JIT Compilation

It is important to realize that background JIT compilation does NOT reduce JIT time.  If anything it INCREASES it, because it will JIT methods HOPING that they will be used shortly by the application.   If they are not used, then that time is 'wasted'.    However, the time background JIT uses is on a parallel thread (and only is attempted if there are 2 ore  more processors), and thus JIT time on the background thread is effectively 'free'.  Thus the important metric is how much JIT time was REMOVED from the foreground threads.   As mentioned, you typically get about half, but the exact number is applications specific, and depends on how well the previous trace predicts the methods that need to be JIT compiled on this run. 

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. 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. 
3. The 'BG' column of each JIT compiled method is set to indicate whether the JIT compilation happened in the background or not.

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

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.