source/debug/profiler.cpp

   1 #include <msp/core/maputils.h>
   2 #include "profiler.h"
   3 #include "profilingscope.h"
   4
   5 using namespace std;
   6
   7 namespace Msp {
   8 namespace Debug {
   9
  10 Profiler::Profiler():
  11         period(0),
  12         inner(0)
  13 { }
  14
  15 void Profiler::set_period(unsigned p)
  16 {
  17         if(p==period)
  18                 return;
  19
  20         period = p;
  21         for(map<string, ScopeInfo>::iterator i=scopes.begin(); i!=scopes.end(); ++i)
  22         {
  23                 ScopeInfo &si = i->second;
  24                 if(p==0)
  25                         si.history.clear();
  26                 else
  27                         si.history.assign(period, CallInfo());
  28                 si.hist_pos = 0;
  29                 si.hist_full = false;
  30         }
  31 }
  32
  33 void Profiler::add_scope(const std::string &name)
  34 {
  35         if(!scopes.count(name))
  36         {
  37                 map<string, ScopeInfo>::iterator i = scopes.insert(map<string, ScopeInfo>::value_type(name, ScopeInfo())).first;
  38                 i->second.history.resize(period);
  39         }
  40 }
  41
  42 ProfilingScope *Profiler::enter(ProfilingScope *ps)
  43 {
  44         ProfilingScope *old = inner;
  45         inner = ps;
  46         return old;
  47 }
  48
  49 void Profiler::record(const ProfilingScope &scope)
  50 {
  51         map<string, ScopeInfo>::iterator i = scopes.find(scope.get_name());
  52         if(i==scopes.end())
  53         {
  54                 i = scopes.insert(map<string, ScopeInfo>::value_type(scope.get_name(), ScopeInfo())).first;
  55                 i->second.first_call = scope.get_entry_time();
  56                 i->second.history.resize(period);
  57         }
  58
  59         ScopeInfo &si = i->second;
  60         ++si.calls;
  61         if(scope.get_parent())
  62                 ++si.called_from[scope.get_parent()->get_name()];
  63         si.total_time += scope.get_time_spent();
  64         si.self_time += scope.get_time_spent()-scope.get_child_time();
  65         if(period)
  66         {
  67                 si.avg_time += scope.get_time_spent()/period-si.history[si.hist_pos].duration/period;
  68
  69                 CallInfo &ci = si.history[si.hist_pos];
  70                 Time::TimeStamp old_entry = ci.entry_time;
  71                 ci.entry_time = scope.get_entry_time();
  72                 ci.duration = scope.get_time_spent();
  73
  74                 ++si.hist_pos;
  75                 if(si.hist_pos>=period)
  76                         si.hist_pos -= period;
  77
  78                 if(si.hist_full)
  79                         si.calls_per_sec = period*Time::sec/(scope.get_entry_time()-old_entry);
  80                 else if(si.hist_pos>1)
  81                         si.calls_per_sec = (si.hist_pos-1)*Time::sec/(scope.get_entry_time()-si.history.front().entry_time);
  82
  83                 if(si.hist_pos==0)
  84                         si.hist_full = true;
  85         }
  86         else
  87         {
  88                 si.avg_time = si.total_time/si.calls;
  89                 if(si.calls>1)
  90                         si.calls_per_sec = (si.calls-1)*Time::sec/(scope.get_entry_time()-si.first_call);
  91         }
  92 }
  93
  94 const Profiler::ScopeInfo &Profiler::get_scope(const string &sn) const
  95 {
  96         return get_item(scopes, sn);
  97 }
  98
  99
 100 Profiler::ScopeInfo::ScopeInfo():
 101         calls(0),
 102         calls_per_sec(0),
 103         hist_pos(0),
 104         hist_full(false)
 105 { }
 106
 107 } // namespace Debug
 108 } // namespace Msp