Tekkotsu Homepage
Demos
Overview
Downloads
Dev. Resources
Reference
Credits

Profiler.h

Go to the documentation of this file.
00001 //-*-c++-*-
00002 #ifndef INCLUDED_Profiler_h_
00003 #define INCLUDED_Profiler_h_
00004 
00005 #include "TimeET.h"
00006 #include <string>
00007 
00008 //! put this at the beginning of any function for which you wish to collect profiling information
00009 /*! Uses a variable named _PROFSECTION_id to store a static ID number - don't redefine or modify that...
00010  *  @param NAME the name of this section for reporting
00011  *  @param PROF the actual profiler to use
00012  */
00013 #ifndef PROFSECTION
00014 #define PROFSECTION(NAME,PROF) \
00015   static unsigned int _PROFSECTION_id=(PROF).getNewID(NAME);\
00016   Profiler::Timer _PROFSECTION_timer(_PROFSECTION_id,&(PROF).prof);
00017 #endif
00018 
00019 //! Manages a hierarchy of timers for profiling time spent in code, gives microsecond resolution
00020 /*! Doesn't use any pointers so it's safe to put this in shared memory regions.\n
00021  *  That's handy so one process can collate all the profiling information across processes
00022  *  to give a summary report to the user.\n
00023  *  
00024  *  Example usage:
00025  *  - Use a static variable to hold an id number for the code section (doesn't necessarily have to be static, but is faster that way)
00026  *  - Create a Profiler::Timer object - its construction marks the 'start' time, and its destructor marks the 'stop' time.
00027  *
00028  *  @code
00029  *  ProfilerOfSize<2> prof; //A global manager for all the sections
00030  *  
00031  *  void f() {
00032  *    static unsigned int id=prof.getNewID("f"); // <== Get the ID number 
00033  *    Profiler::Timer timer(id,&prof.prof);      // <== start the timer
00034  *    //...
00035  *    if(rand()>RAND_MAX/2)
00036  *      return; // destruction of timer occurs automatically!
00037  *    //...
00038  *  } // if we didn't hit the return, timer will otherwise destruct here!
00039  *  @endcode
00040  *
00041  *  However, there's a macro that makes this a one liner:
00042  *  
00043  *  @code
00044  *  void g() {
00045  *    PROFSECTION("g",prof);   // <== Most of the time, this is all you need
00046  *    //...                    // (unless you're doing something fancy like conditional timers)
00047  *    f(); // will note f's time as g's child time, as well as g's own time
00048  *    //...
00049  *  }
00050  *  @endcode
00051  *
00052  *  The idea is similar to that used by MMAccessor.  If you want to profile a section at smaller
00053  *  resolution than a function, you can use tricks shown in MMAccessor's documentation to limit
00054  *  the timer's scope.
00055  *
00056  *  For convenience, there are three global profilers predefined: #mainProfiler, #motionProfiler,
00057  *  and #soundProfiler.  These are what are polled by the ProfilerCheckControl -- if you instantiate
00058  *  a new profiler, you will have to call its report() function yourself to get the results.  (If it's simply
00059  *  a matter of running out of sections in mainProfiler, increase the template parameter at the end
00060  *  of Profiler.h)  Keep in mind however, that these global profilers are pointers, and need to be
00061  *  dereferenced to use with the macro, e.g. <code>PROFSECTION("g2",*mainProfiler)</code>
00062  *
00063  *  Here were the constraints I set for myself:
00064  *  - Processes can read each other's Profilers - so must be able to live in shared memory\n
00065  *    This is so one process can generate a report on performance of the entire system at once
00066  *  - Flexible memory footprint\n
00067  *    MainObject will probably have a lot of subsections.  MotionObject won't.  Since SectionInfo
00068  *    takes some significant memory space, we don't want to force MotionObject to needlessly make
00069  *    a lot of them.
00070  *  - Flexible usage - can have a single generic global, as well as creating multiple
00071  *  - Fast - don't want to kill performance of profiled sections, or throw off reported results
00072  *
00073  *  Consessions made:
00074  *  - Sections are not dynamically allocated
00075  *  - Sections within a Profiler are mutually exclusive (otherwise curSection won't be reliable)
00076  *  - Results don't try to take affects of pre-emptive multitasking into account.
00077  *
00078  *  Global readability is first priority since generating reports is the primary usage, thus
00079  *  we have to be able to handle being in shared memory space.  This means no virtual functions and
00080  *  no pointer storage.  Unfortunately, this makes the second constraint rather difficult.\n
00081  *  Run-time dynamic allocation is right out.  But the number of sections is set at compile time
00082  *  anyway, so it should be OK to set this at compile time, using a template parameter.\n
00083  *  That gets us 99% of the way there, but it can be burdensome to use this since the template
00084  *  means there's no consistant type for all profilers - you can't have a generic Profiler type
00085  *  if it's templated - you would have to know the size of the profiler you're referring to.\n
00086  *  That kind of brings in the third constraint... Instead of accepting a single global, I
00087  *  decided to make a general base (Profiler) and then a templated subclass to hold the bulk data
00088  *  section.  This has the nice side affect of not having to specify the bulk of the code in the
00089  *  header, but has the downside that accessing the info stored in the subclass from the super class
00090  *  is very much a hack.  If you think you can get around this, good luck!
00091  *
00092  *  @note This could be made much prettier if we didn't care about the virtual function-shared
00093  *  memory problems... sigh
00094  */
00095 class Profiler {
00096 public:
00097   //! constructor, but you don't want to construct one of these!  Use ProfilerOfSize<x> instead!
00098   Profiler(unsigned int mx);
00099   
00100   //! maximum length of names of timers
00101   static const unsigned int MaxSectionNameLen=75;
00102   //! number of slots in the histograms
00103   static const unsigned int HistSize=32;
00104   //! the upper bound (exclusive) of the histograms, in milliseconds.
00105   static const unsigned int HistTime=10*1000;
00106   //! affects how linearly the buckets are distributed - 1 means linear, >1 causes higher resolution for short times
00107   static const float HistCurve;
00108   
00109     
00110   //! holds all the information needed for book keeping for each timer
00111   struct SectionInfo {
00112     SectionInfo();                     //!< constructor
00113     void reset();                      //!< resets profiling information
00114     char name[MaxSectionNameLen];      //!< the name of this timer
00115     TimeET totalTime;                  //!< the total time spent in this section
00116     TimeET lastTime;                   //!< time of last call, used to calculate #totalInterval, which gives idea of rate of calls
00117     TimeET totalInterval;              //!< the total time spent between calls (not time between end of one and start of next, is time between start of one and start of next)
00118     TimeET childTime;                  //!< the total time spent in child sections
00119     float execExpAvg;                 //!< exponential average of execution time
00120     float interExpAvg;                //!< exponential average of inter-call time
00121     unsigned int execHist[HistSize];   //!< histogram of execution times, uses logarithmic size bins (so high res for quick functions, low res for longer functions)
00122     unsigned int interHist[HistSize];  //!< histogram of inter-call time, uses logarithmic size bins (so high res for quick functions, low res for longer functions)
00123     unsigned int calls;                //!< number of calls to this section
00124   };    
00125   
00126   //! Measures the time that this class exists, reports result to a profiler
00127   /*! Don't bother trying to use this as a quick timer - just use TimeET directly.
00128    *  But there are functions to get the elapsed time and such if you insist.  */
00129   class Timer {
00130     //! Profiler will need to read out some data that no one else should be depending on
00131     friend class Profiler;
00132   public:
00133     Timer() : _prof(NULL), _id(-1U), _parent(-1U), _t() {} //!< constructor - starts timer, but you can restart it...
00134     Timer(unsigned int id, Profiler* prof); //!< constructor - starts the timer, sets current timer in @a prof
00135     Timer(const Timer& t) : _prof(t._prof), _id(t._id), _parent(t._parent),_t(t._t) { } //!< copy constructor, not that you should need it, does same as default
00136     Timer& operator=(const Timer& t) { _prof=t._prof; _id=t._id; _parent=t._parent; _t=t._t; return *this; } //!< not that you should need it, does same as default
00137     ~Timer(); //!< destructor - stops the timer, reports results
00138     void setID(unsigned int id, Profiler* prof); //!< sets the ID and profiler, also starts timer
00139     void start() { _t.Set(); } //!< starts timer (or resets it)
00140     const TimeET& startTime() { return _t; } //!< returns time of start
00141     TimeET elapsed() { return _t.Age(); } //!< returns time since start
00142   protected:
00143     Profiler* _prof;      //!< the profiler this should report to
00144     unsigned int _id;     //!< the id number for this code section (See example in beginning of class documentation for how these are assigned)
00145     unsigned int _parent; //!< the id number of the timer this timer is under
00146     TimeET _t;            //!< the time this timer was created
00147   };
00148   
00149   //! call this to get a new ID number
00150   unsigned int getNewID(const char* name);
00151 
00152   //! called during process init (before any profiled sections)
00153   static void initBuckets();
00154 
00155   //! returns the bucket boundaries
00156   float* getBuckets() { return buckets; }
00157 
00158   //! outputs profiling information
00159   std::string report();
00160 
00161   //! resets profiling information
00162   void reset();
00163     
00164   unsigned int curSection;         //!< the current timer
00165   TimeET startTime;                //!< time of beginning profiling
00166   float gamma;                    //!< gamma to use with exponential averages (1 to freeze, 0 to set to last)
00167   const unsigned int maxSections;  //!< so we can read the size of the infos array back again at runtime
00168   unsigned int sectionsUsed;       //!< the number of timer IDs which have been assigned
00169 
00170   //! gets the actual storage area of the SectionInfo's
00171   inline SectionInfo* getInfos() { return (SectionInfo*)((char*)this+infosOffset); }
00172     
00173 protected:
00174   //! Only the Timer's should be calling setCurrent() and finished() upon the Timer's construction and destruction
00175   friend class Timer;
00176   //! called automatically by Timer() - sets the current timer
00177   void setCurrent(Timer& tr);
00178   //! called automatically by ~Timer() - notes the specified timer as finished (doesn't check if the timer is actually the current one - don't screw up!)
00179   void finished(Timer& tr);
00180   
00181   //! returns which bucket a time should go in, does a binary search over buckets (unless someone things a log() call would be faster...)
00182   unsigned int getBucket(float t) {
00183     unsigned int l=0;          //inclusive
00184     unsigned int h=HistSize-1; //inclusive
00185     unsigned int c=(h+l)/2;    //current bucket
00186     while(l!=h) {
00187       //      std::cout << this << ' ' << t << '\t' << l << ' ' << c << ' ' << h <<std::endl;
00188       if(t>buckets[c])
00189         l=c+1;
00190       else
00191         h=c;
00192       c=(h+l)/2;
00193     }
00194     return h;
00195   }
00196     
00197   static float buckets[HistSize];  //!< holds boundaries for each bucket
00198 
00199   static unsigned int infosOffset; //!< NASTY HACK - this is how we get around using virtual functions
00200   
00201   //! Automatically causes initialization of the histogram buckets when the first Profiler is instantiated
00202   class AutoInit {
00203   public:
00204     AutoInit(); //!< constructor, adds to #refcount and #totalcount, causes initalization if was 0
00205     ~AutoInit(); //!< destructor, decrements #refcount, does teardown if it hits 0
00206   protected:
00207     static unsigned int refcount; //!< the number of profilers in existance
00208     static unsigned int totalcount; //!< the number of profilers which have been created
00209   } autoInit;
00210 };
00211 
00212 //! templated subclass allows compile-time flexibility of how much memory to use.
00213 template<unsigned int MaxSections>
00214 class ProfilerOfSize {
00215 public:
00216   ProfilerOfSize() : prof(MaxSections) {} //!< constructor
00217   
00218   //! call this to get a new ID number
00219   unsigned int getNewID(const char* name) { return prof.getNewID(name); }
00220   
00221   //! outputs profiling information
00222   std::string report() { return prof.report(); }
00223   
00224   Profiler prof; //!< the profiler that does the work, must immediately preceed #infos!
00225   Profiler::SectionInfo infos[MaxSections]; //!< the actual profiling information storage
00226 };
00227 
00228 // feel free to ignore these or add your own as well -- these are the ones that framework-included code will use
00229 typedef ProfilerOfSize<20> mainProfiler_t; //!< defines type for code profiling information for MainObject; use this instead of the templated type so you don't rely on a particular size
00230 typedef ProfilerOfSize<6> motionProfiler_t; //!< defines type for code profiling information for MotionObject; use this instead of the templated type so you don't rely on a particular size
00231 typedef ProfilerOfSize<6> soundProfiler_t; //!< defines type for code profiling information for SoundPlay; use this instead of the templated type so you don't rely on a particular size
00232 extern mainProfiler_t * mainProfiler; //!< holds code profiling information for MainObject
00233 extern motionProfiler_t * motionProfiler; //!< holds code profiling information for MotoObject
00234 extern soundProfiler_t * soundProfiler; //!< holds code profiling information for SoundPlay
00235 
00236 /*! @file
00237  * @brief Describes Profiler, which managers a hierarchy of timers for profiling time spent in code
00238  * @author ejt (Creator)
00239  */
00240 
00241 #endif

Tekkotsu v5.1CVS
Generated Mon May 9 04:58:49 2016 by Doxygen 1.6.3