profileTimer.h

panda/src/express/profileTimer.I

@@ -0,0 +1,58 @@
+// ProfileTimer.I
+
+INLINE void ProfileTimer::
+on() {
+  _on = TrueClock::get_ptr()->get_real_time();
+}
+
+
+INLINE double ProfileTimer::
+getTime() {
+  double time = TrueClock::get_ptr()->get_real_time();
+  double et=_elapsedTime+=time-_on;
+  _on=time;
+  _elapsedTime=0.0;
+  return et;
+}
+
+
+INLINE void ProfileTimer::
+mark(const char* tag) {
+  if (!_entries) {
+    cerr << "ProfileTimer::mark !_entries" << endl;
+    exit(1);
+  }
+  if (_entryCount < _maxEntries-1) {
+    TimerEntry& p=_entries[_entryCount];
+    p._tag=tag;
+    p._time=getTime();
+    ++_entryCount;
+  } else {
+    _entries[_entryCount]._tag="*** Overflow ***";
+  }
+}
+
+
+INLINE void ProfileTimer::
+off() {
+  double time = TrueClock::get_ptr()->get_real_time();
+  _elapsedTime+=time-_on;
+}
+
+
+INLINE void ProfileTimer::
+off(const char* tag) {
+  double time = TrueClock::get_ptr()->get_real_time();
+  _elapsedTime+=time-_on;
+  mark(tag);
+}
+
+
+INLINE ProfileTimer::AutoTimer::
+~AutoTimer() {
+  // If the AutoTimer is the first auto ctor, then it will
+  // be the last auto dtor, for that block.  Therefore, now
+  // is the time to mark the time for the block/function:
+  _profile.mark(_tag);
+  --_profile._autoTimerCount;
+}

panda/src/express/profileTimer.cxx

@@ -0,0 +1,169 @@
+// ProfileTimer.cxx
+#include "profileTimer.h"
+#include <map>
+using namespace std;
+
+// See ProfileTimer.h for documentation.
+
+
+EXPCL_PANDAEXPRESS ProfileTimer Skyler_timer_global=ProfileTimer("startup");
+
+ProfileTimer* ProfileTimer::_head;
+
+ProfileTimer::
+ProfileTimer(const char* name, int maxEntries) :
+  _entries(0),
+  _autoTimerCount(0) {
+  // Keep a list of the ProfileTimers, so we can print them:
+  _next=_head;
+  _head=this;
+  if (name) {
+    init(name, maxEntries);
+  }
+}
+
+ProfileTimer::
+ProfileTimer(const ProfileTimer& other) {
+  // Add to list:
+  _next=_head;
+  _head=this;
+  // init it:
+  _name=other._name;
+  _maxEntries=other._maxEntries;
+  if (_name) {
+    init(_name, _maxEntries);
+  }
+  // Copy other entries:
+  _on=other._on;
+  _elapsedTime=other._elapsedTime;
+  _autoTimerCount=other._autoTimerCount;
+  _entryCount=other._entryCount;
+  if (other._entries) {
+    memcpy(_entries, other._entries, _entryCount * sizeof TimerEntry);
+  }
+}
+
+ProfileTimer::
+~ProfileTimer() {
+  delete [] _entries;
+  // Remove this from the list:
+  if (_head==this) {
+    _head=_next;
+  } else {
+    ProfileTimer* p=_head;
+    ProfileTimer* prior=p;
+    while (p) {
+      if (p==this) {
+        prior->_next=_next;
+        break;
+      }
+      prior=p;
+      p=p->_next;
+    }
+  }
+}
+
+void ProfileTimer::
+init(const char* name, int maxEntries) {
+  _name=name;
+  _maxEntries=maxEntries;
+  _entries=new TimerEntry[_maxEntries];
+  _entryCount=0;
+  _elapsedTime=0.0;
+  _on=0.0;
+}
+
+double ProfileTimer::
+getTotalTime() const {
+  double total=0;
+  int i;
+  for (i=0; i<_entryCount; ++i) {
+    TimerEntry& te=_entries[i];
+    total+=te._time;
+  }
+  return total;
+}
+
+void ProfileTimer::
+consolidateAllTo(ostream &out) {
+  ProfileTimer* p=_head;
+  while (p) {
+    p->consolidateTo(out);
+    p=p->_next;
+  }
+}
+
+void ProfileTimer::
+consolidateTo(ostream &out) const {
+  map<string, double> entries;
+  int i;
+  for (i=0; i<_entryCount; ++i) {
+    TimerEntry& te=_entries[i];
+    entries[te._tag]+=te._time;
+  }
+  out << "-------------------------------------------------------------------\n"
+    << "Profile Timing of " << _name 
+    << "\n\n"; // ...should print data and time too.
+  double total=0;
+  {
+  map<string, double>::const_iterator i=entries.begin();
+  for (;i!=entries.end(); ++i) {
+    out << "  " << setw(50) << i->first << ": " 
+    << setiosflags(ios::fixed) << setprecision(6) << setw(10) << i->second << "\n";
+    total+=i->second;
+  }
+  }
+  out << "\n                       [Total Time: " 
+    << setiosflags(ios::fixed) << setprecision(6) << total 
+    << " seconds]\n"
+    << "-------------------------------------------------------------------\n";
+  out << endl;
+}
+
+void ProfileTimer::
+printAllTo(ostream &out) {
+  ProfileTimer* p=_head;
+  while (p) {
+    p->printTo(out);
+    p=p->_next;
+  }
+}
+
+void ProfileTimer::
+printTo(ostream &out) const {
+  out << "-------------------------------------------------------------------\n"
+    << "Profile Timing of " << _name 
+    << "\n\n"; // ...should print data and time too.
+  double total=0;
+  int i;
+  for (i=0; i<_entryCount; ++i) {
+    TimerEntry& te=_entries[i];
+    out << "  " << setw(50) << te._tag << ": " 
+    << setiosflags(ios::fixed) << setprecision(6) << setw(10) << te._time << "\n";
+    total+=te._time;
+  }
+  out << "\n                       [Total Time: " 
+    << setiosflags(ios::fixed) << setprecision(6) << total 
+    << " seconds]\n"
+    << "-------------------------------------------------------------------\n";
+  out << endl;
+}
+
+ProfileTimer::AutoTimer::AutoTimer(ProfileTimer& profile, const char* tag) :
+    _profile(profile) {  
+  _tag=tag;
+  if (_profile._autoTimerCount) {
+    // ...this is a nested call to another AutoTimer.
+    // Assign the time to the prior AutoTimer:
+    _profile.mark(_profile._entries[_profile._entryCount-1]._tag);
+  } else {
+    // ...this is not a nested call.
+    _profile.mark("other");
+  }
+  // Tell the profile that it's in an AutoTimer:
+  ++_profile._autoTimerCount;
+  _profile.mark(_tag);
+}
+
+
+