00001
00007
00008
00009
00010
00011
00012
00013
00014
00015
00016
00017
00018
00019
00020
00021
00022
00023
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
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
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
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
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
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
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
00151 uint64 getNumTicks() const
00152 {
00153 #ifdef NL_DEBUG
00154 nlassert(!_Started);
00155 #endif
00156 nlassert(_NumTicks != 0);
00157 return _NumTicks;
00158 }
00159
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
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
00224 void after(bool displayAfter = false);
00225
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
00288 {
00289 typedef std::vector<double> TTimeVect;
00290
00291 CNode *Parent;
00292 TNodeVect Sons;
00293 CHTimer *Owner;
00294 uint64 TotalTime;
00295 uint64 LastSonsTotalTime;
00296 uint64 SonsTotalTime;
00297 TTimeVect Measures;
00298 uint64 MinTime;
00299 uint64 MaxTime;
00300 uint64 NumVisits;
00301
00302 uint64 SonsPreambule;
00303 CSimpleClock Clock;
00304
00305 CNode(CHTimer *owner = NULL, CNode *parent = NULL) : Parent(parent), Owner(owner)
00306 {
00307 reset();
00308 }
00309
00310 ~CNode();
00311
00312 uint getNumNodes() const;
00313
00314 void releaseSons();
00315
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
00328 void displayPath(CLog *log) const;
00329
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
00347 void buildFromNode(CNode *node, double msPerTick);
00348
00349
00350 void buildFromNodes(CNode **firstNode, uint numNodes, double msPerTick);
00351
00352
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
00361 struct CTimerStat : public CStats
00362 {
00363 CHTimer *Timer;
00364 };
00365
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
00381 bool operator()(const CStats *lhs, const CStats *rhs);
00382 };
00383
00384
00388 struct CExamStackEntry
00389 {
00390
00391 CNode *Node;
00392
00393 uint CurrentChild;
00394
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
00407 void walkTreeToCurrent();
00408 private:
00409
00410 const char *_Name;
00411
00412 CHTimer *_Parent;
00413
00414 TTimerVect _Sons;
00415
00416 bool _IsRoot;
00417 private:
00418
00419 static CNode _RootNode;
00420
00421 static CNode *_CurrNode;
00422
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
00473
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
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 )
00499 {
00500 if (!_Benching) return;
00501 _CurrNode->Clock.stop();
00502 _PreambuleClock.start();
00503
00504
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 }
00541
00542 #endif // NL_HIERARCHICAL_TIMER_H
00543
00544
00545