source/debug/profiler.cpp

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