# Home    # nevrax.com   
Nevrax
Nevrax.org
#News
#Mailing-list
#Documentation
#CVS
#Bugs
#License
Docs
 
Documentation  
Main Page   Namespace List   Class Hierarchy   Alphabetical List   Compound List   File List   Namespace Members   Compound Members   File Members   Related Pages   Search  

hierarchical_timer.h

Go to the documentation of this file.
00001 
00007 /* Copyright, 2000, 2001 Nevrax Ltd.
00008  *
00009  * This file is part of NEVRAX NeL Network Services.
00010  * NEVRAX NeL Network Services is free software; you can redistribute it and/or modify
00011  * it under the terms of the GNU General Public License as published by
00012  * the Free Software Foundation; either version 2, or (at your option)
00013  * any later version.
00014 
00015  * NEVRAX NeL Network Services is distributed in the hope that it will be useful, but
00016  * WITHOUT ANY WARRANTY; without even the implied warranty of
00017  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
00018  * General Public License for more details.
00019 
00020  * You should have received a copy of the GNU General Public License
00021  * along with NEVRAX NeL Network Services; see the file COPYING. If not, write to the
00022  * Free Software Foundation, Inc., 59 Temple Place - Suite 330, Boston,
00023  * MA 02111-1307, USA.
00024  */
00025 
00026 #ifndef NL_HIERARCHICAL_TIMER_H
00027 #define NL_HIERARCHICAL_TIMER_H
00028 
00029 #include <string>
00030 #include <vector>
00031 
00032 #include "nel/misc/types_nl.h"
00033 #include "nel/misc/time_nl.h"
00034 #include "nel/misc/debug.h"
00035 
00036 #include <algorithm>
00037 
00038 #define ALLOW_TIMING_MEASURES
00039 
00040 
00041 #ifdef ALLOW_TIMING_MEASURES
00042         // Several macros to use
00043 #       define H_TIME(name, inst) \
00044         { \
00045                 static NLMISC::CHTimer  nl_h_timer(name); \
00046                 nl_h_timer.before(); \
00047                 inst \
00048                 nl_h_timer.after(); \
00049         }
00050         //
00051 #       define H_BEFORE(__name) static NLMISC::CHTimer  __name##_timer(#__name); __name##_timer.before();
00052 #       define H_AFTER(__name)          __name##_timer.after();
00053         //
00054 #       define H_AUTO(__name)           static NLMISC::CHTimer  __name##_timer(#__name); NLMISC::CAutoTimer     __name##_auto(&__name##_timer);
00055         // display the timer info after each loop call
00056 #       define H_AUTO_INST(__name)      static NLMISC::CHTimer  __name##_timer(#__name); NLMISC::CAutoTimer     __name##_auto(&__name##_timer, true);
00057 
00061 #       define H_AUTO_DECL(__name)              static NLMISC::CHTimer  __name##_timer(#__name); 
00062 #       define H_AUTO_USE(__name)               NLMISC::CAutoTimer      __name##_auto(&__name##_timer);
00063 
00064 #else
00065         // void macros
00066 #       define H_TIME(name, inst)       
00067 #       define H_BEFORE(__name)
00068 #       define H_AFTER(__name)  
00069 #       define H_AUTO(__name)   
00070 #       define H_AUTO_INST(__name)
00071 #       define H_AUTO_DECL(__name)
00072 #       define H_AUTO_USE(__name)
00073 #endif
00074 
00075 
00076 namespace NLMISC
00077 {
00078 
00079 
00080 #ifdef NL_OS_WINDOWS
00081 // Vicual C++ warning : ebp maybe modified
00082 #       pragma warning(disable:4731)
00083 #endif
00084 
00085 
00088 #ifdef NL_CPU_INTEL
00089 
00090 inline uint64 rdtsc()
00091 {
00092         uint64 ticks;
00093 #       ifndef NL_OS_WINDOWS            
00094                 __asm__ volatile(".byte 0x0f, 0x31" : "=a" (ticks.low), "=d" (ticks.high));                             
00095 #       else            
00096                 __asm   rdtsc
00097                 __asm   mov             DWORD PTR [ticks], eax
00098                 __asm   mov             DWORD PTR [ticks + 4], edx              
00099 #       endif
00100         return ticks;   
00101 }
00102 
00103 #endif  
00104 
00105 
00114 class CSimpleClock
00115 {
00116 public: 
00117         CSimpleClock() : _NumTicks(0)
00118         {
00119 #               ifdef NL_DEBUG
00120                         _Started = false;
00121 #               endif
00122         }
00123         // start measure
00124         void start()
00125         {
00126 #               ifdef  NL_DEBUG
00127                         nlassert(!_Started);
00128                         _Started = true;
00129 #               endif
00130 #               ifdef NL_CPU_INTEL
00131                 _StartTick = rdtsc();
00132 #               else
00133                 _StartTick = CTime::getPerformanceTime();
00134 #               endif
00135         }
00136         // end measure
00137         void stop()
00138         {
00139 #               ifdef  NL_DEBUG
00140                         nlassert(_Started);
00141                         _Started = false;
00142 #               endif
00143 #               ifdef NL_CPU_INTEL
00144                 _NumTicks = rdtsc() - _StartTick;
00145 #               else
00146                 _NumTicks = CTime::getPerformanceTime() - _StartTick;
00147 #               endif
00148                 
00149         }       
00150         // get measure
00151         uint64  getNumTicks() const
00152         {
00153                 #ifdef NL_DEBUG
00154                         nlassert(!_Started);
00155                 #endif
00156                 nlassert(_NumTicks != 0);
00157                 return _NumTicks;
00158         }       
00159         // This compute the duration of start and stop (in cycles).
00160         static void init();
00164         static uint64 getStartStopNumTicks() 
00165         {               
00166                 return _StartStopNumTicks; 
00167         }       
00168 private:
00169         uint64  _StartTick;
00170         uint64  _NumTicks;
00171 #       ifdef  NL_DEBUG
00172                 bool    _Started;
00173 #       endif
00174         static bool             _InitDone;
00175         static uint64   _StartStopNumTicks;     
00176 };
00177 
00178 
00179 
00180 
00181 
00205 class CHTimer
00206 {
00207 public:
00208         // this enum is used to sort displayed results
00209         enum TSortCriterion { NoSort, 
00210                                                   TotalTime,
00211                                                   TotalTimeWithoutSons,
00212                                                   MeanTime,
00213                                                   NumVisits,
00214                                                   MaxTime,
00215                                                   MinTime,
00216                                                   SortCriterionsLast
00217                                                 };
00218 public:
00220         CHTimer(const char *name, bool isRoot = false) : _Name(name), _IsRoot(isRoot) {}
00222         void            before();
00223         // Ends a measuring session
00224         void            after(bool displayAfter = false);       
00225         // Get this node name
00226         const char         *getName() const { return _Name; }
00231         static void             startBench(bool wantStandardDeviation = false, bool quick = false);
00234         static void             bench() { startBench(); }
00237         static void             adjust() {}
00239         static void             endBench();
00243         static void             display(CLog *log= InfoLog, TSortCriterion criterion = TotalTime, bool displayInline = true, bool displayEx = true);
00249         static void             displayByExecutionPath(CLog *log= InfoLog, TSortCriterion criterion = TotalTime, bool displayInline = true, bool alignPaths = true, bool displayEx = true);
00250 
00255         static void             displayHierarchical(CLog *log= InfoLog, bool displayEx = true, uint labelNumChar = 32, uint indentationStep = 2);
00256 
00261         static void             displayHierarchicalByExecutionPath(CLog *log= InfoLog, bool displayEx = true, uint labelNumChar = 32, uint indentationStep = 2);
00262 
00267         static void             displayHierarchicalByExecutionPathSorted(CLog *log= InfoLog, TSortCriterion criterion = TotalTime, bool displayEx = true, uint labelNumChar = 32, uint indentationStep = 2);
00268 
00270         static void             clear();                
00271 
00276 #ifdef NL_CPU_INTEL
00277         static uint64   getProcessorFrequency(bool quick=false);
00278 #endif
00281 private:
00282         struct CNode;
00283         typedef std::vector<CNode *>   TNodeVect;
00284         typedef std::vector<CHTimer *> TTimerVect;
00285         //
00287         struct CNode
00288         {               
00289                 typedef std::vector<double> TTimeVect;
00290                 //
00291                 CNode                                   *Parent;
00292                 TNodeVect                               Sons;
00293                 CHTimer                                 *Owner;    // the hierarchical timer this node is associated with               
00294                 uint64                                  TotalTime; // the total time spent in that node, including sons         
00295                 uint64                                  LastSonsTotalTime; 
00296                 uint64                                  SonsTotalTime; // maybe different from LastSonsTotalTime while benching the sons and if the display is called in a benched node
00297                 TTimeVect                               Measures;  // All time measures. Used only when standard deviation is wanted
00298                 uint64                                  MinTime;   // the minimum time spent in that node
00299                 uint64                                  MaxTime;   // the maximum time spent in that node
00300                 uint64                                  NumVisits; // the number of time the execution has gone through this node               
00301                 //
00302                 uint64                                  SonsPreambule; // preambule time for the sons           
00303                 CSimpleClock                    Clock;         // a clock to do the measures at this node
00304                 // ctor 
00305           CNode(CHTimer *owner = NULL, CNode    *parent = NULL) : Parent(parent), Owner(owner)
00306                 {
00307                         reset();
00308                 }
00309                 // dtor
00310                 ~CNode();
00311                 // Get the number of nodes in the tree starting at this node
00312                 uint  getNumNodes() const;
00313                 // release the sons, should not be benching when calling this
00314                 void    releaseSons();
00315                 // reset this node measures
00316                 void    reset()
00317                 {
00318                         SonsTotalTime            = 0;
00319                         TotalTime                        = 0;
00320                         MaxTime                          = 0;
00321                         MinTime                          = (uint64) -1;
00322                         NumVisits                        = 0;
00323                         SonsPreambule        = 0;                       
00324                         LastSonsTotalTime    = 0;
00325                         NLMISC::contReset(Measures);
00326                 }
00327                 // Display this node path
00328                 void    displayPath(CLog *log) const;
00329                 // Get this node path
00330                 void    getPath(std::string &dest) const;               
00331         };
00332 
00336         struct CStats
00337         {       
00338                 double  TimeStandardDeviation;
00339                 double  TotalTime;              
00340                 double  TotalTimeWithoutSons;
00341                 double  MeanTime;
00342                 uint64  NumVisits;
00343                 double  MinTime;
00344                 double  MaxTime;                
00345 
00346                 // build stats from a single node
00347                 void buildFromNode(CNode *node, double msPerTick);
00348                 
00349                 // build stats from a vector of nodes
00350                 void buildFromNodes(CNode **firstNode, uint numNodes, double msPerTick);
00351 
00352                 // display stats
00353                 void display(CLog *log, bool displayEx = false, bool wantStandardDeviation = false);
00354 
00358                 void getStats(std::string &dest, bool statEx, double rootTotalTime, bool wantStandardDeviation = false);
00359         };
00360         // Stats and the associated timer
00361         struct CTimerStat : public CStats
00362         {
00363                 CHTimer *Timer;                 
00364         };
00365         // Stats and the associated node
00366         struct CNodeStat : public CStats
00367         {
00368                 CNode *Node;
00369         };      
00370 
00371 
00375         struct CStatSorter
00376         {
00377                 CStatSorter(TSortCriterion criterion = TotalTime) : Criterion(criterion)
00378                 {}
00379                 TSortCriterion Criterion;
00380                 // Less operator
00381                 bool operator()(const CStats *lhs, const CStats *rhs);
00382         };
00383 
00384 
00388         struct  CExamStackEntry
00389         {
00390                 // The node.
00391                 CNode                           *Node;
00392                 // The current child to process.
00393                 uint                            CurrentChild;
00394                 // The childs, sorted by specific criterion.
00395                 std::vector<CNode*>     Children;
00396 
00397                 explicit        CExamStackEntry(CNode *node)
00398                 {
00399                         Node= node;
00400                         CurrentChild= 0;
00401                 }
00402         };
00403 
00404 
00405 private:
00406         // walk the tree to current execution node, creating it if necessary
00407         void    walkTreeToCurrent();
00408 private:
00409         // node name
00410         const  char                                             *_Name;
00411         // the parent timer
00412         CHTimer                                                 *_Parent;
00413         // the sons timers
00414         TTimerVect                                              _Sons;
00415         // Tells if this is a root node
00416         bool                                                    _IsRoot;
00417 private:
00418         // root node of the hierarchy
00419         static CNode                                    _RootNode;
00420         // the current node of the execution
00421         static CNode                                    *_CurrNode;     
00422         // the root timer
00423         static CHTimer                                   _RootTimer;
00427         static CSimpleClock                             _PreambuleClock;
00428         //
00429         static double                                   _MsPerTick;
00430         //
00431         static bool                                             _Benching;
00432         //
00433         static bool                                             _BenchStartedOnce;
00434         //
00435         static bool                                             _WantStandardDeviation;
00436         //
00437         static CHTimer                             *_CurrTimer; 
00438 
00439 };
00440 
00441 
00442 
00459 class CAutoTimer
00460 {
00461 private:
00462         CHTimer         *_HTimer;
00463         bool            _DisplayAfter;
00464 public:
00465         CAutoTimer(CHTimer *timer, bool displayAfter=false) : _HTimer(timer), _DisplayAfter(displayAfter) { _HTimer->before(); }
00466         ~CAutoTimer() { _HTimer->after(_DisplayAfter); }
00467 };
00468 
00469 
00471 // inlines implementation //
00473 #if 0
00474 //===============================================
00475 inline void     CHTimer::before()
00476 {       
00477         if (!_Benching) return;
00478         _PreambuleClock.start();
00479         walkTreeToCurrent();                    
00480         ++ _CurrNode->NumVisits;
00481         _CurrNode->SonsPreambule = 0;
00482         if (!_Parent && _CurrTimer != this)
00483         {
00484                 _Parent = _CurrTimer;
00485                 // register as a son of the parent
00486                 _Parent->_Sons.push_back(this); 
00487         }
00488         _CurrTimer = this;
00489         _PreambuleClock.stop();
00490         if (_CurrNode->Parent)
00491         {       
00492                 _CurrNode->Parent->SonsPreambule += _PreambuleClock.getNumTicks();
00493         }
00494         _CurrNode->Clock.start();
00495 }
00496 
00497 //===============================================
00498 inline void     CHTimer::after(bool displayAfter /*= false*/)
00499 {
00500         if (!_Benching) return;
00501         _CurrNode->Clock.stop();                
00502         _PreambuleClock.start();
00503         //              
00504         //nlinfo((std::string("clock ") + _Name + std::string(" time = ") + NLMISC::toString(_CurrNode->Clock.getNumTicks())).c_str());
00505         uint64 numTicks = _CurrNode->Clock.getNumTicks()  - _CurrNode->SonsPreambule - (CSimpleClock::getStartStopNumTicks() << 1);
00506 
00507         _CurrNode->TotalTime += numTicks;               
00508         _CurrNode->MinTime = std::min(_CurrNode->MinTime, numTicks);
00509         _CurrNode->MaxTime = std::max(_CurrNode->MaxTime, numTicks);
00510         _CurrNode->LastSonsTotalTime = _CurrNode->SonsTotalTime;
00511         if (displayAfter)
00512         {               
00513                 nlinfo("FEHTIMER> %s %.3fms loop number %d", _Name, numTicks * _MsPerTick, _CurrNode->NumVisits);
00514         }
00515         //
00516         if (_WantStandardDeviation)
00517         {
00518                 _CurrNode->Measures.push_back(numTicks * _MsPerTick);
00519         }
00520         //
00521         if (_Parent)
00522         {
00523                 _CurrTimer = _Parent;
00524         }       
00525         //
00526         if (_CurrNode->Parent)
00527         {
00528                 _PreambuleClock.stop();
00529                 _CurrNode = _CurrNode->Parent;
00530                 _CurrNode->SonsTotalTime += numTicks;
00531                 _CurrNode->SonsPreambule += _PreambuleClock.getNumTicks();
00532         }
00533         else
00534         {
00535                 _PreambuleClock.stop();
00536         }
00537 }
00538 #endif
00539 
00540 } // NLMISC
00541 
00542 #endif // NL_HIERARCHICAL_TIMER_H
00543 
00544 /* End of hierarchical_timer.h */
00545