nevrax.org : docs

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 
+