Make Profiler able to report number of calls per second

diff --git a/source/debug/profiler.cpp b/source/debug/profiler.cpp
index 6cce271983022302a6a3820acf20e049d02d7143..38681ed9fd2d5103c685d567a88690600cda36a8 100644 (file)
--- a/source/debug/profiler.cpp
+++ b/source/debug/profiler.cpp
@@ -25,8 +25,9 @@ void Profiler::set_period(unsigned p)
                if(p==0)
                        si.history.clear();
                else
                if(p==0)
                        si.history.clear();
                else

-                       si.history.assign(period, Time::zero);
+                       si.history.assign(period, CallInfo());

                si.hist_pos = 0;
                si.hist_pos = 0;

+               si.hist_full = false;

        }
 }
 
        }
 }
 


@@ -52,6 +53,7 @@ void Profiler::record(const ProfilingScope &scope)
        if(i==scopes.end())
        {
                i = scopes.insert(map<string, ScopeInfo>::value_type(scope.get_name(), ScopeInfo())).first;
        if(i==scopes.end())
        {
                i = scopes.insert(map<string, ScopeInfo>::value_type(scope.get_name(), ScopeInfo())).first;

+               i->second.first_call = scope.get_entry_time();

                i->second.history.resize(period);
        }
 
                i->second.history.resize(period);
        }
 


@@ -63,13 +65,31 @@ void Profiler::record(const ProfilingScope &scope)
        si.self_time += scope.get_time_spent()-scope.get_child_time();
        if(period)
        {
        si.self_time += scope.get_time_spent()-scope.get_child_time();
        if(period)
        {

-               si.avg_time += scope.get_time_spent()/period-si.history[si.hist_pos]/period;
-               si.history[si.hist_pos++] = scope.get_time_spent();
+               si.avg_time += scope.get_time_spent()/period-si.history[si.hist_pos].duration/period;
+
+               CallInfo &ci = si.history[si.hist_pos];
+               Time::TimeStamp old_entry = ci.entry_time;
+               ci.entry_time = scope.get_entry_time();
+               ci.duration = scope.get_time_spent();
+
+               ++si.hist_pos;

                if(si.hist_pos>=period)
                        si.hist_pos -= period;
                if(si.hist_pos>=period)
                        si.hist_pos -= period;

+
+               if(si.hist_full)
+                       si.calls_per_sec = period*Time::sec/(scope.get_entry_time()-old_entry);
+               else if(si.hist_pos>1)
+                       si.calls_per_sec = (si.hist_pos-1)*Time::sec/(scope.get_entry_time()-si.history.front().entry_time);
+
+               if(si.hist_pos==0)
+                       si.hist_full = true;

        }
        else
        }
        else

+       {

                si.avg_time = si.total_time/si.calls;
                si.avg_time = si.total_time/si.calls;

+               if(si.calls>1)
+                       si.calls_per_sec = (si.calls-1)*Time::sec/(scope.get_entry_time()-si.first_call);
+       }

 }
 
 const Profiler::ScopeInfo &Profiler::get_scope(const string &sn) const
 }
 
 const Profiler::ScopeInfo &Profiler::get_scope(const string &sn) const


@@ -80,7 +100,9 @@ const Profiler::ScopeInfo &Profiler::get_scope(const string &sn) const
 
 Profiler::ScopeInfo::ScopeInfo():
        calls(0),
 
 Profiler::ScopeInfo::ScopeInfo():
        calls(0),

-       hist_pos(0)
+       calls_per_sec(0),
+       hist_pos(0),
+       hist_full(false)

 { }
 
 } // namespace Debug
 { }
 
 } // namespace Debug

diff --git a/source/debug/profiler.h b/source/debug/profiler.h
index 5ec8f3f1fcafa5dae8ebe4508a5b02abaeb7e1f3..ad0653c0697f566b31f356974733293277d6e63b 100644 (file)
--- a/source/debug/profiler.h
+++ b/source/debug/profiler.h
@@ -5,6 +5,7 @@
 #include <string>
 #include <vector>
 #include <msp/time/timedelta.h>
 #include <string>
 #include <vector>
 #include <msp/time/timedelta.h>

+#include <msp/time/timestamp.h>

 
 namespace Msp {
 namespace Debug {
 
 namespace Msp {
 namespace Debug {


@@ -25,14 +26,23 @@ Profiler for each thread.
 class Profiler
 {
 public:
 class Profiler
 {
 public:

+       struct CallInfo
+       {
+               Msp::Time::TimeStamp entry_time;
+               Msp::Time::TimeDelta duration;
+       };
+

        struct ScopeInfo
        {
        struct ScopeInfo
        {

+               Time::TimeStamp first_call;

                unsigned calls;
                Time::TimeDelta total_time;
                Time::TimeDelta self_time;
                Time::TimeDelta avg_time;
                unsigned calls;
                Time::TimeDelta total_time;
                Time::TimeDelta self_time;
                Time::TimeDelta avg_time;

-               std::vector<Time::TimeDelta> history;
+               float calls_per_sec;
+               std::vector<CallInfo> history;

                unsigned hist_pos;
                unsigned hist_pos;

+               bool hist_full;

                std::map<std::string, unsigned> called_from;
 
                ScopeInfo();
                std::map<std::string, unsigned> called_from;
 
                ScopeInfo();