   Profiling: how?
  Hi all,Trying to find out what is the cause of a bottleneck in a C++/OpenGL application, I read on "Game Programming Gems Volume 1" the importance of profiling, but I can't actually understand how to practically do it.I don't need complex tools, I would just like to know basic information such as how many times each method is called, how many time it takes etc..I work with Visual Studio 2008 Professional, so it would be great to have something which integrates with the IDE. I read in this forum about Intel's vtune, but I need a free solution.Thanks.   
  AMD CodeAnalyst is freely available.   ;  I also recommend an in-game profiler for general use. External tools like code analyst and vtune are good but are complex and sometimes tricky to use. Generally you can get enough information out of a built in profiler that you need to figure out what subsystems of your project are responsible for taking the most time. I wouldn't add timer code to every single function though, so if you need that go with one of the bigger tools. IMO having that detail of profiling information is usually overkill, and it's simpler to profiler your code at logical boundaries that you can much more easily set up as part of an ingame timing system, such as http://silverspaceship.com/src/iprof/ . Of course, keep in mind there is a degree of overhead to an in-game timing system, though it is generally very small.   ;  It is fairly simple thing to do poorly.  just use a high performance timer such as query performance counter to take timings.  You probably want to keep min, max, and average.  Don't forget to set processor affinity or your timings may be off.  The tools are pretty cool,  you more or less point them at the exe and they do the rest.   ;  So you have a game engine that is bottlenecked (and railing the CPU).  Is it single threaded?  On a system where you can debug it?  Can you leave symbols?  Can you make the bottleneck condition last multiple seconds?  (even if in a loop)In the above case, a simple Monte Carlo profiling technique works wonders.  Bring your program into the bottlenecked portion.  Hit break.  Look at the call stack.Repeat 10 times.Pay attention to as much of the call stack as you can.Almost certainly, the call stack will contain very common elements over those 10 times.  These are the parts of your code that is taking the most time.This will not let you tune an engine to get that last handful of X% of performance out of it.  It will let you find the parts of the code that your engine is spending the most time in, so you can find the code you need to improve to make your engine performance increase by a factor of 3 to 100.That last handful of % of performance boost needs a less crude tool than the above.  However, if you aren't doing final-pass performance...  it kicks ass, and is simple to do.;Quote:Original post by Luca DI don't need complex tools, I would just like to know basic information such as how many times each method is called, how many time it takes etc..There are free tools such as CodeAnalyst expensive tools, static analysis tools, and your own in-game profilers.Quote:but I can't actually understand how to practically do it.There is both an art and a science to profiling and optimizing code.  Some of it can be taught with book knowledge, but it also requires your own skill and talents.It is amazing amount of noise in where people will immediately jump to parallelize the code either through threading (introducing race conditions and bugs) or through simd or other parallel instructions (making the code difficult to maintain).  Those are very useful tools, but they should not be the first ones you pull from the shelf. At work I recently wrote up my activities over a short profiling and optimizing session.  Here is a short summary.  I removed a lot of interesting details of the code and variables, but it will walk you through one of my typical profiling and optimization session.This game is running on an older console.  The CPU is measured in MHz rather than GHz, and the memory is measured in MB rather than GB.  We had a general performance issue of dropped frames.I ran the profiler over a specific subsystem for 20 frames.  I noted the main CPU usage within the subsystem: the particle manager was taking up 77% of the subsystem's time, collectible object updates taking up 7%, and actor update taking up 6%.  So the particle system is an obvious target for cleaning up.  Everyone already suspected this, but you must always measure to confirm.The first thing I did is a cursory review of the code, attempting to fully understand it and remove any completely unnecessary content.I notice two things:  First, the system is being called too often.  Second, the system is taking too long.  I decide to first improve the speed of the system, and after it is quicker, make it called less often.The code itself is around 500 lines total, which isn't too bad for what the particle system is doing.  I also have a constraint that I cannot change the results of the math behind the particles, since doing so would invalidate all the particle systems used in the game.I reduced my profiler coverage to just the particle system and child calls, and profiled again over 20 frames to get a good set of results.Glancing over the new profile results I observe one of the most commonly called function is the Vector3D constructor --- called 8200 times over 20 frames.  I made a few small changes to initialize with the final value wherever possible, removing many but not all of the default constructors.I note that one section of the calculation loop is executed roughly 1000 times because it is run for each particle.  So I know that even a small improvement there will be multiplied giving a big improvement.Within this loop, I notice we are using an iterator, of the form (*iter).  I happen to know our compiler's optimizer has a very hard time with aliasing and pointer invalidation.  That means that the compiler will frequently generate bad code for dereferencing an iterator.  So at the beginning of the loop I create a reference to the object:  Foo& foo = *iter;  I replace all the uses of the iterator with the reference.Also within the loop, I notice that there are certain conditions which are mutually exclusive, so I move those to an if/elseif tree.From experience I know that all of these are good changes that will improve the code, but it is now time to measure again.  If I were less experienced at profiling I would have wanted to measure again after every change, and decide to either keep or revert the change depending on the new actual profile results.The new measurements show it reduced to 89% of the original time.   That's an 11% improvement in just a matter of minutes.  Not too shabby.More review of the loop shows that it is making many calls to two functions.  The first gets the incremental velocity, the other gets the current size factor.  The functions themselves are fairly quick (0.5 avg time units), but they are called many thousands of times.  I note the obvious problem that they are passing a structure directly.  I change this to pass a const reference to eliminate the creation of the temporary.  I observe that these functions are creating a scaling vector locally, so I extract that to a static value that is reused.  So with those two small changes, I rebuild and reprofile.  As expected, this further reduced the average execution time.  Specifically, the per-particle update time was reduced from 14.9 time units on average to 12.0, or as a percentage, it was reduced by about 20%.With a few simple measurements (before and after) and some very small code changes, there was a huge measured performance difference with almost no real work.I spent a couple more hours reducing the math difficulty and improving the performance, but none were as dramatic or easy as those first few simple changes.  Ultimately I removed about 40% of the processing time, but I am not convinced that the last few percent were worth the time and effort.Next, I went after the other part of performance --- calling the functions less often, just calling it when necessary.  I introduced a fairly trivial visibility test, and removed everything that was outside the camera's view plus a buffer.  This dropped about 60% of updates.I performed some additional optimization work, but those were the biggest improvements.In just a few hours I reduced the processing requirements to just 12% of the time originally required.    I did not need to rewrite using SIMD parallel processing.  I did not need to rewrite code in assembly.  I did not use any fancy hacks that were difficult to maintain.  I only applied some simple high-level changes that any programmer could maintain.  I measured before the change, and after the change.  In a few cases the changes actually hurt performance, and I reverted them.  The rest of my optimization session was similar, with simple high-level changes that eliminated huge amounts of waste from the code.  I hope this is useful instructions on how to use your profiler to help guide performance optimization.   ;  The fun thing about profiling is it is often the little things which can cause issues.At work I'm currently doing things towards game X, and the tech we are using is from another company who have been working on game Y, which is the prequeal to our game, for a while now.It's a 360 game, so there is a lovely profiler in PIX, so all I did was kick the game off running and started a capture for a segment of a level.Right away I could see that, while the averge fps was indeed 60, it was swinging between 48fps and 84fps each frame. D3D was also showing a blocked percentage of 70%! As the GPU looked unloaded from the data and we seemed to be having problems CPU side I took a look at the various times for the already marked sections of data.Right away something jumpped out at me; a rendering routine was taking longer todo less work. I followed the profiling points down and discovered that we were losing 9ms (or just over half a frame work of time!) waiting for a vertex buffer to lock.So, off I went to the code, found the offending bit and swapped the vertex buffer from being a single one for the class to a double buffer setup. Recompiled things, booted the game, ran the capture again and bam! 60fps solid, frame times all the same and the D3D blocking percentage was yoyoing between 15 and 30%.Which shows that sometimes a little change (in this case about 7 lines of C++) can make a huge difference to things.Today was a good day [grin]   ;  Thanks guys for all your answers.I think I'll start creating an in-game very simple profiler.Thank you frob for your detailed description: I'm facing problems very similar to yours, regarding particles and vector constructors, but before changing something I'd like to profile those section to have a clearer idea of timings.Hence I'll try what you all suggested and then I'll return on this post.   