From 588d67f9620997f0b4aaa2415b6d7b3f3bdd7a24 Mon Sep 17 00:00:00 2001 From: Dave Schuyler Date: Tue, 15 May 2001 00:53:22 +0000 Subject: [PATCH] profileTimer.h --- panda/src/express/profileTimer.I | 58 ++++++++++ panda/src/express/profileTimer.cxx | 169 +++++++++++++++++++++++++++++ 2 files changed, 227 insertions(+) create mode 100644 panda/src/express/profileTimer.I create mode 100644 panda/src/express/profileTimer.cxx diff --git a/panda/src/express/profileTimer.I b/panda/src/express/profileTimer.I new file mode 100644 index 0000000000..48aa0b760c --- /dev/null +++ b/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; +} diff --git a/panda/src/express/profileTimer.cxx b/panda/src/express/profileTimer.cxx new file mode 100644 index 0000000000..76fe9b432d --- /dev/null +++ b/panda/src/express/profileTimer.cxx @@ -0,0 +1,169 @@ +// ProfileTimer.cxx +#include "profileTimer.h" +#include +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 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::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); +} + + +