Fast Timers

The Second Life client has an embedded profiling system built on top of a timer class called LLFastTimer. To profile a piece of code, simply create an instance of a fast timer in the stack frame you wish to profile. The fast timer constructor takes a category as a parameter. Categories are defined in llfasttimer.h.

For example, in LLSpatialPartition::cull():

   {
       LLFastTimer ftm(LLFastTimer::FTM_FRUSTUM_CULL);		
       LLOctreeCull culler(&camera);
       culler.traverse(mOctree);
   }

A fast timer is created under the category FTM_FRUSTUM_CULL and is destroyed after LLOctreeCull::traverse returns. In llfasttimerview.cpp, you will find a table of categories used for displaying the results of the profile. The entry for frustum cull is seen in context below:

   { LLFastTimer::FTM_WORLD_UPDATE,		"  World Update",		&LLColor4::blue1, 1 },
   { LLFastTimer::FTM_UPDATE_MOVE,		"   Move Objects",		&LLColor4::pink2, 0 },
   { LLFastTimer::FTM_OCTREE_BALANCE,		"    Octree Balance", &LLColor4::red3, 0 },
   { LLFastTimer::FTM_CULL,			"   Object Cull",	&LLColor4::blue2, 1 },
   { LLFastTimer::FTM_CULL_REBOUND,		"    Rebound",		&LLColor4::blue3, 0 },
   { LLFastTimer::FTM_FRUSTUM_CULL,		"    Frustum Cull",	&LLColor4::blue4, 0 },
   { LLFastTimer::FTM_OCCLUSION,		"    Object Occlude", &LLColor4::pink1, 0 },
   { LLFastTimer::FTM_OCCLUSION_READBACK,	"    Occlusion Read", &LLColor4::red2, 0 },

The leading white space on the label represents the stack depth of each timer. Here, you can see that the frustum cull timer is instantiated in a stack frame lower than Object Cull, which is under World Update. To view the results of the profile, run the viewer and open the fast timer console (Client->Consoles->Fast Timers). What you see is a live profile of how much time was spent in each stack frame corresponding to a fast timer instance.

On the left hand side, you will see a legend of currently visible categories. Click on a category to expand or collapse it. It is possible to overextend the legend tree, so try to limit the number of visible categories (apologies for the lack of scroll bar). On the top, you will see an aggregate profile result as a timer bar, in the middle you'll see a live log of timer bars with some history, and at the bottom you'll see a normalized line graph of currently viewed data. If you mouse over a category in the legend, it will highlight in the timer bars and the line graph will renormalize to the highlighted value. If you alt-click on the console, it will toggle between showing timed data and call count (the number of fast timer instances created last frame for that category). Left clicking will pause/restart the timers, and using the mouse wheel while the cursor is over the line graph will scroll through the history.

In general, to test whether or not an optimization worked well, take the amount of time spent in a given category, divide it by the number of calls into that category for a given scene, and compare the result before and after the optimization (three trials on each side of the fence). It's helpful to find scenes that stress the area you're trying to measure to minimize error between runs. In optimizing render calls, be sure to measure the entire render frame instead of just the category in question, as what makes one section of the render frame faster may cause a pipeline stall somewhere else.

Some useful scenes for testing:

• Welcome Area: http://slurl.com/secondlife/Ahern/5/24/41
  • High avatar count
  • Relatively safe for work
• First Look Isle: http://slurl.com/secondlife/First%20Look%20Isle/126/125/23
  • Several static test scenes:
  • Scene 1: Geometry stress test
  • Scene 2: Particle stress test
  • Scene 3: Texture/material stress test
  • Scene 4: Easy case
• Grignano: http://slurl.com/secondlife/Grignano/116/175/60
  • Old city with thousands of unique textures
  • Moderate avatar count
  • Dense, diverse geometry
  • Stresses network, LOD, and texture decodes