Timer.cpp

00001 /*------------------------------------------------------------------------*/
00002 /*                 Copyright 2010 Sandia Corporation.                     */
00003 /*  Under terms of Contract DE-AC04-94AL85000, there is a non-exclusive   */
00004 /*  license for use of this work by or on behalf of the U.S. Government.  */
00005 /*  Export of this program may require a license from the                 */
00006 /*  United States Government.                                             */
00007 /*------------------------------------------------------------------------*/
00008 
00009 #include <math.h>
00010 #include <sstream>
00011 #include <iomanip>
00012 #include <algorithm>
00013 #include <functional>
00014 #include <stdexcept>
00015 #include <limits>
00016 
00017 #include <stk_util/util/string_case_compare.hpp>
00018 
00019 #include <stk_util/diag/Timer.hpp>
00020 #include <stk_util/diag/Writer.hpp>
00021 #include <stk_util/diag/WriterExt.hpp>
00022 
00023 namespace stk {
00024 namespace diag {
00025 
00026 namespace {
00027 
00028 MetricsMask s_enabledMetricsMask = METRICS_LAP_COUNT | METRICS_CPU_TIME | METRICS_WALL_TIME;        
00029 
00030 template <class T>
00031 typename MetricTraits<T>::Type
00032 value_now() {
00033   if (MetricTraits<T>::METRIC & getEnabledTimerMetricsMask())
00034     return MetricTraits<T>::value_now();
00035   else
00036     return 0;
00037 }
00038 
00039 std::vector<std::string> &
00040 split(
00041   const std::string &           path,
00042   char                          separator,
00043   std::vector<std::string> &    path_vector)
00044 {
00045   for (std::string::const_iterator it = path.begin(); ; ) {
00046     std::string::const_iterator it2 = std::find(it, path.end(), separator);
00047     path_vector.push_back(std::string(it, it2));
00048     if (it2 == path.end())
00049       break;
00050     it = it2 + 1;
00051   }
00052   
00053   return path_vector;
00054 }
00055 
00056 } // namespace <empty>
00057 
00058 
00059 MetricsMask getEnabledTimerMetricsMask()
00060 {
00061   return s_enabledMetricsMask;
00062 }
00063 
00064 void
00065 setEnabledTimerMetricsMask(
00066   MetricsMask   timer_mask)
00067 {
00068   s_enabledMetricsMask = timer_mask | METRICS_LAP_COUNT;
00069 }
00070 
00071 
00093 class TimerImpl
00094 {
00095   friend class Timer;
00096   
00097 public:
00098   static void updateRootTimer(TimerImpl *root_timer);
00099   
00100   static Timer createRootTimer(const std::string &name, const TimerSet &timer_set);
00101     
00102   static void deleteRootTimer(TimerImpl *root_timer);
00103 
00104   static std::vector<Timer> &findTimers(TimerImpl *root_timer, const std::string &path_tail, std::vector<Timer> &found_timers);
00105 
00106   static void findTimer(TimerImpl *timer, std::vector<std::string> &path_tail_vector, std::vector<Timer> &found_timers);
00107   
00108 private:
00118   static TimerImpl *reg(const std::string &name, TimerMask timer_mask, TimerImpl *parent_timer, const TimerSet &timer_set) {
00119     return parent_timer->addSubtimer(name, timer_mask, timer_set);
00120   }
00121 
00129   TimerImpl(const std::string &name, TimerMask timer_mask, TimerImpl *parent_timer, const TimerSet &timer_set);
00130 
00135   ~TimerImpl();
00136   
00137   TimerImpl(const TimerImpl &TimerImpl);
00138   TimerImpl &operator=(const TimerImpl &TimerImpl);
00139   
00146 #ifdef __INTEL_COMPILER
00147 #pragma warning(push)
00148 #pragma warning(disable: 444)
00149 #endif
00150   class finder : private std::unary_function<Timer, bool>
00151   {
00152   public:
00153     explicit finder(const std::string &name)
00154       : m_name(name)
00155     {}
00156     
00157     bool operator()(Timer timer) const {
00158       return equal_case(timer.getName(), m_name);
00159     }
00160 
00161   private:
00162     std::string   m_name;
00163   };
00164 #ifdef __INTEL_COMPILER
00165 #pragma warning(pop)
00166 #endif
00167 
00168 public:
00175   const std::string &getName() const {
00176     return m_name;
00177   }
00178 
00184   TimerMask getTimerMask() const {
00185     return m_timerMask;
00186   }
00187 
00193   const TimerSet &getTimerSet() const {
00194     return m_timerSet;
00195   }
00196 
00205   bool shouldRecord() const {
00206     return m_timerSet.shouldRecord(m_timerMask) && s_enabledMetricsMask;
00207   }
00208 
00215   double getSubtimerLapCount() const {
00216     return m_subtimerLapCount;
00217   }
00218 
00219   void setSubtimerLapCount(double value) {
00220     m_subtimerLapCount = value;
00221   }
00222 
00230   template <class T>
00231   const Timer::Metric<T> &getMetric() const;
00232 
00240   const TimerList &getTimerList() const {
00241     return m_subtimerList;
00242   }
00243  
00244   TimerList::iterator begin() {
00245     return m_subtimerList.begin();
00246   }
00247     
00248   TimerList::const_iterator begin() const {
00249     return m_subtimerList.begin();
00250   }
00251     
00252   TimerList::iterator end() {
00253     return m_subtimerList.end();
00254   }
00255     
00256   TimerList::const_iterator end() const {
00257     return m_subtimerList.end();
00258   }
00259     
00264   void reset();
00265 
00270   void checkpoint() const;
00271 
00277   TimerImpl &start();
00278 
00284   TimerImpl &lap();
00285 
00292   TimerImpl &stop();
00293 
00301   double accumulateSubtimerLapCounts() const;
00302 
00303   Timer getSubtimer(const std::string &name);
00304 
00305 public:
00314   Writer &dump(Writer &dout) const;
00315 
00316 private:
00328   TimerImpl *addSubtimer(const std::string &name, TimerMask timer_mask, const TimerSet &timer_set);
00329 
00330 private:
00331   std::string     m_name;     
00332   TimerMask     m_timerMask;    
00333   TimerImpl *     m_parentTimer;    
00334   mutable double    m_subtimerLapCount; 
00335   unsigned      m_lapStartCount;  
00336 
00337   TimerList     m_subtimerList;   
00338 
00339   const TimerSet &              m_timerSet;             
00340   Timer::Metric<LapCount>       m_lapCount;   
00341   Timer::Metric<CPUTime>        m_cpuTime;    
00342   Timer::Metric<WallTime>       m_wallTime;   
00343   Timer::Metric<MPICount>       m_MPICount;   
00344   Timer::Metric<MPIByteCount>   m_MPIByteCount;   
00345 };
00346 
00347 
00357 inline Writer &operator<<(Writer &dout, const TimerImpl &timer) {
00358   return timer.dump(dout);
00359 }
00360 
00361 
00362 void
00363 updateRootTimer(
00364   Timer                 root_timer)
00365 {
00366   TimerImpl::updateRootTimer(root_timer.m_timerImpl);
00367 }
00368 
00369 
00370 Timer
00371 createRootTimer(
00372   const std::string &   name,
00373   const TimerSet &      timer_set)
00374 {
00375   return TimerImpl::createRootTimer(name, timer_set);
00376 }
00377 
00378 
00379 void
00380 deleteRootTimer(
00381   Timer                 timer)
00382 {
00383   TimerImpl::deleteRootTimer(timer.m_timerImpl);
00384   timer.m_timerImpl = 0;
00385 }
00386 
00387 
00388 std::vector<Timer> &
00389 findTimers(Timer root_timer, const std::string &path_tail, std::vector<Timer> &found_timers) {
00390   TimerImpl::findTimers(root_timer.m_timerImpl, path_tail, found_timers);
00391   return found_timers;
00392 }
00393 
00394 
00395 TimerImpl::TimerImpl(
00396   const std::string & name,
00397   TimerMask   timer_mask,
00398   TimerImpl *   parent_timer,
00399   const TimerSet &      timer_set)
00400   : m_name(name),
00401     m_timerMask(timer_mask),
00402     m_parentTimer(parent_timer),
00403     m_subtimerLapCount(0.0),
00404     m_lapStartCount(0),
00405     m_subtimerList(),
00406     m_timerSet(timer_set)
00407 {}
00408 
00409 
00410 TimerImpl::~TimerImpl()
00411 {
00412   try {  
00413     for (TimerList::iterator it = m_subtimerList.begin(); it != m_subtimerList.end(); ++it)
00414       delete (*it).m_timerImpl;
00415   }
00416   catch (std::exception &) {
00417   }  
00418 }
00419 
00420 
00421 template<>
00422 const Timer::Metric<LapCount> &
00423 TimerImpl::getMetric<LapCount>() const {
00424   return m_lapCount;
00425 }
00426 
00427 
00428 template<>
00429 const Timer::Metric<CPUTime> &
00430 TimerImpl::getMetric<CPUTime>() const {
00431   return m_cpuTime;
00432 }
00433 
00434 
00435 template<>
00436 const Timer::Metric<WallTime> &
00437 TimerImpl::getMetric<WallTime>() const {
00438   return m_wallTime;
00439 }
00440 
00441 
00442 template<>
00443 const Timer::Metric<MPICount> &
00444 TimerImpl::getMetric<MPICount>() const {
00445   return m_MPICount;
00446 }
00447 
00448 
00449 template<>
00450 const Timer::Metric<MPIByteCount> &
00451 TimerImpl::getMetric<MPIByteCount>() const {
00452   return m_MPIByteCount;
00453 }
00454 
00455 
00456 void
00457 TimerImpl::reset()
00458 {
00459   m_lapStartCount = 0;
00460 
00461   m_lapCount.reset();
00462   m_cpuTime.reset();
00463   m_wallTime.reset();
00464   m_MPICount.reset();
00465   m_MPIByteCount.reset();
00466 }
00467 
00468 
00469 Timer
00470 TimerImpl::getSubtimer(
00471   const std::string & name)
00472 {
00473   TimerList::iterator it = std::find_if(m_subtimerList.begin(), m_subtimerList.end(), finder(name));
00474 
00475   if (it == m_subtimerList.end())
00476     throw std::runtime_error("Timer not found");
00477   else
00478     return *it;
00479 }
00480 
00481 
00482 TimerImpl *
00483 TimerImpl::addSubtimer(
00484   const std::string & name,
00485   TimerMask         timer_mask,
00486   const TimerSet &      timer_set)
00487 {
00488   TimerList::iterator it = std::find_if(m_subtimerList.begin(), m_subtimerList.end(), finder(name));
00489 
00490   if (it == m_subtimerList.end()) {
00491     TimerImpl *timer_impl = new TimerImpl(name, timer_mask, this, timer_set);
00492     m_subtimerList.push_back(Timer(timer_impl));
00493     return timer_impl;
00494   }
00495   else
00496     return (*it).m_timerImpl;
00497 }
00498 
00499 
00500 TimerImpl &
00501 TimerImpl::start()
00502 {
00503   if (shouldRecord()) {
00504     if (m_lapStartCount++ == 0) {
00505       m_lapCount.m_lapStart = m_lapCount.m_lapStop;
00506 
00507       m_cpuTime.m_lapStop = m_cpuTime.m_lapStart = value_now<CPUTime>();
00508       m_wallTime.m_lapStop = m_wallTime.m_lapStart = value_now<WallTime>();
00509       m_MPICount.m_lapStop = m_MPICount.m_lapStart = value_now<MPICount>();
00510       m_MPIByteCount.m_lapStop = m_MPIByteCount.m_lapStart = value_now<MPIByteCount>();
00511     }
00512   }
00513 
00514   return *this;
00515 }
00516 
00517 
00518 TimerImpl &
00519 TimerImpl::lap()
00520 {
00521   if (shouldRecord()) {
00522     if (m_lapStartCount > 0) {
00523       m_cpuTime.m_lapStop = value_now<CPUTime>();
00524       m_wallTime.m_lapStop = value_now<WallTime>();
00525       m_MPICount.m_lapStop = value_now<MPICount>();
00526       m_MPIByteCount.m_lapStop = value_now<MPIByteCount>();
00527     }
00528   }
00529 
00530   return *this;
00531 }
00532 
00533 
00534 TimerImpl &
00535 TimerImpl::stop()
00536 {
00537   if (shouldRecord()) {
00538     if (--m_lapStartCount <= 0) {
00539       m_lapStartCount = 0;
00540       m_lapCount.m_lapStop++;
00541 
00542       m_cpuTime.m_lapStop = value_now<CPUTime>();
00543       m_wallTime.m_lapStop = value_now<WallTime>();
00544       m_MPICount.m_lapStop = value_now<MPICount>();
00545       m_MPIByteCount.m_lapStop = value_now<MPIByteCount>();
00546 
00547       m_lapCount.addLap();
00548       m_cpuTime.addLap();
00549       m_wallTime.addLap();
00550       m_MPICount.addLap();
00551       m_MPIByteCount.addLap();
00552     }
00553   }
00554 
00555   return *this;
00556 }
00557 
00558 
00559 double
00560 TimerImpl::accumulateSubtimerLapCounts() const
00561 {
00562   m_subtimerLapCount = m_lapCount.getAccumulatedLap(false);
00563 
00564   for (TimerList::const_iterator it = m_subtimerList.begin(); it != m_subtimerList.end(); ++it)
00565     (*it).m_timerImpl->accumulateSubtimerLapCounts();
00566 
00567   for (TimerList::const_iterator it = m_subtimerList.begin(); it != m_subtimerList.end(); ++it)
00568     m_subtimerLapCount += (*it).m_timerImpl->m_subtimerLapCount;
00569 
00570   return m_subtimerLapCount;
00571 }
00572 
00573 
00574 void
00575 TimerImpl::checkpoint() const
00576 {
00577   m_lapCount.checkpoint();
00578   m_cpuTime.checkpoint();
00579   m_wallTime.checkpoint();
00580   m_MPICount.checkpoint();
00581   m_MPIByteCount.checkpoint();
00582 
00583   for (TimerList::const_iterator it = m_subtimerList.begin(); it != m_subtimerList.end(); ++it)
00584     (*it).m_timerImpl->checkpoint();
00585 }
00586 
00587 
00588 void
00589 TimerImpl::updateRootTimer(TimerImpl *root_timer)
00590 {
00591   root_timer->m_lapCount.m_lapStop = value_now<LapCount>();
00592   root_timer->m_cpuTime.m_lapStop = value_now<CPUTime>();
00593   root_timer->m_wallTime.m_lapStop = value_now<WallTime>();
00594   root_timer->m_MPICount.m_lapStop = value_now<MPICount>();
00595   root_timer->m_MPIByteCount.m_lapStop = value_now<MPIByteCount>();
00596 
00597   root_timer->m_lapCount.m_accumulatedLap = root_timer->m_lapCount.m_lapStop - root_timer->m_lapCount.m_lapStart;
00598   root_timer->m_cpuTime.m_accumulatedLap = root_timer->m_cpuTime.m_lapStop - root_timer->m_cpuTime.m_lapStart;
00599   root_timer->m_wallTime.m_accumulatedLap = root_timer->m_wallTime.m_lapStop - root_timer->m_wallTime.m_lapStart;
00600   root_timer->m_MPICount.m_accumulatedLap = root_timer->m_MPICount.m_lapStop - root_timer->m_MPICount.m_lapStart;
00601   root_timer->m_MPIByteCount.m_accumulatedLap = root_timer->m_MPIByteCount.m_lapStop - root_timer->m_MPIByteCount.m_lapStart;
00602 }
00603 
00604 
00605 
00606 Timer
00607 TimerImpl::createRootTimer(
00608   const std::string &   name,
00609   const TimerSet &      timer_set)
00610 {
00611   TimerImpl *timer_impl = new TimerImpl(name, 0, 0, timer_set);
00612   return Timer(timer_impl);
00613 }
00614 
00615 
00616 void
00617 TimerImpl::deleteRootTimer(
00618   TimerImpl *           root_timer)
00619 {
00620   delete root_timer;
00621 }
00622 
00623 
00624 void
00625 TimerImpl::findTimer(
00626   TimerImpl *                   timer,
00627   std::vector<std::string> &    path_tail_vector,
00628   std::vector<Timer> &          found_timers)
00629 {
00630   if (timer->begin() == timer->end()) { // at leaf
00631     
00632   }
00633   else
00634     for (TimerList::const_iterator it = timer->begin(); it != timer->end(); ++it)
00635       findTimer((*it).m_timerImpl, path_tail_vector, found_timers);
00636 }
00637 
00638 
00639 std::vector<Timer> &
00640 TimerImpl::findTimers(
00641   TimerImpl *                   root_timer,
00642   const std::string &           path_tail,
00643   std::vector<Timer> &          found_timers)
00644 {
00645   std::vector<std::string> path_tail_vector;
00646   
00647   findTimer(root_timer, split(path_tail, '.', path_tail_vector), found_timers);
00648 
00649   return found_timers;
00650 }
00651 
00652 
00653 
00654 Writer &
00655 TimerImpl::dump(
00656   Writer &    dout) const
00657 {
00658   if (dout.shouldPrint()) {
00659     dout << "TimerImpl" << push << dendl;
00660     dout << "m_name, " << m_name << dendl;
00661     dout << "m_timerMask, " << m_timerMask << dendl;
00662 //    dout << "m_parentTimer, " << c_ptr_name(m_parentTimer) << dendl;
00663     dout << "m_subtimerLapCount, " << m_subtimerLapCount << dendl;
00664     dout << "m_lapStartCount, " << m_lapStartCount << dendl;
00665 
00666     dout << "m_lapCount, " << m_lapCount << dendl;
00667     dout << "m_cpuTime, " << m_cpuTime << dendl;
00668     dout << "m_wallTime, " << m_wallTime << dendl;
00669     dout << "m_MPICount, " << m_MPICount << dendl;
00670     dout << "m_MPIByteCount, " << m_MPIByteCount << dendl;
00671 
00672     dout << "m_subtimerList, " << m_subtimerList << dendl;
00673     dout << pop;
00674   }
00675 
00676   return dout;
00677 }
00678 
00679 
00680 Timer::Timer(const std::string &name, const Timer parent)
00681   : m_timerImpl(TimerImpl::reg(name, parent.getTimerMask(), parent.m_timerImpl, parent.getTimerSet()))
00682 {}
00683 
00684 Timer::Timer(const std::string &name, TimerMask timer_mask, const Timer parent)
00685   : m_timerImpl(TimerImpl::reg(name, timer_mask, parent.m_timerImpl, parent.getTimerSet()))
00686 {}
00687 
00688 Timer::Timer(const std::string &name, const Timer parent, const TimerSet &timer_set)
00689   : m_timerImpl(TimerImpl::reg(name, parent.getTimerMask(), parent.m_timerImpl, timer_set))
00690 {}
00691 
00692 Timer::Timer(const std::string &name, TimerMask timer_mask, const Timer parent, const TimerSet &timer_set)
00693   : m_timerImpl(TimerImpl::reg(name, timer_mask, parent.m_timerImpl, timer_set))
00694 {}
00695 
00696 
00697 const std::string &
00698 Timer::getName() const {
00699   return m_timerImpl->m_name;
00700 }
00701 
00702 TimerMask
00703 Timer::getTimerMask() const {
00704   return m_timerImpl->getTimerMask();
00705 }
00706 
00707 const TimerSet &
00708 Timer::getTimerSet() const {
00709   return m_timerImpl->getTimerSet();
00710 }
00711 
00712 double
00713 Timer::getSubtimerLapCount() const {
00714   return m_timerImpl->getSubtimerLapCount();
00715 }
00716 
00717 const TimerList &
00718 Timer::getTimerList() const {
00719   return m_timerImpl->getTimerList();
00720 }
00721 
00722 template<class T>
00723 const Timer::Metric<T> &
00724 Timer::getMetric() const {
00725   return m_timerImpl->getMetric<T>();
00726 }
00727 
00728 template const Timer::Metric<LapCount> &Timer::getMetric<LapCount>() const;
00729 template const Timer::Metric<CPUTime> &Timer::getMetric<CPUTime>() const;
00730 template const Timer::Metric<WallTime> &Timer::getMetric<WallTime>() const;
00731 template const Timer::Metric<MPICount> &Timer::getMetric<MPICount>() const;
00732 template const Timer::Metric<MPIByteCount> &Timer::getMetric<MPIByteCount>() const;
00733 
00734 
00735 bool
00736 Timer::shouldRecord() const
00737 {
00738   return m_timerImpl->shouldRecord();
00739 }
00740 
00741 TimerList::iterator
00742 Timer::begin()
00743 {
00744   return m_timerImpl->begin();
00745 }
00746     
00747 TimerList::const_iterator
00748 Timer::begin() const
00749 {
00750   return m_timerImpl->begin();
00751 }
00752     
00753 TimerList::iterator
00754 Timer::end()
00755 {
00756   return m_timerImpl->end();
00757 }
00758     
00759 TimerList::const_iterator
00760 Timer::end() const
00761 {
00762   return m_timerImpl->end();
00763 }
00764     
00765 double
00766 Timer::accumulateSubtimerLapCounts() const {
00767   return m_timerImpl->accumulateSubtimerLapCounts();
00768 }
00769 
00770 Timer &
00771 Timer::start() {
00772   m_timerImpl->start();
00773   return *this;
00774 }
00775 
00776 Timer &
00777 Timer::lap() {
00778   m_timerImpl->lap();
00779   return *this;
00780 }
00781 
00782 Timer &
00783 Timer::stop() {
00784   m_timerImpl->stop();
00785   return *this;
00786 }
00787 
00788 void
00789 Timer::checkpoint() const {
00790   m_timerImpl->checkpoint();
00791 }
00792 
00793 Writer &
00794 Timer::dump(Writer& dout) const {
00795   return m_timerImpl->dump(dout);
00796 }
00797 
00798 template <class T>
00799 Writer &
00800 Timer::Metric<T>::dump(
00801   Writer &    dout) const
00802 {
00803   if (dout.shouldPrint()) {
00804     dout << "Timer::Metric<T>" << push << dendl;
00805     dout << "m_lapStart, " << m_lapStart << dendl;
00806     dout << "m_lapStop, " << m_lapStop << dendl;
00807     dout << "m_accumulatedLap, " << m_accumulatedLap << dendl;
00808     dout << "m_checkpoint, " << m_checkpoint << dendl;
00809     dout << pop;
00810   }
00811   return dout;
00812 }
00813 
00814 template Writer &Timer::Metric<LapCount>::dump(Writer &) const;
00815 template Writer &Timer::Metric<CPUTime>::dump(Writer &) const;
00816 template Writer &Timer::Metric<WallTime>::dump(Writer &) const;
00817 template Writer &Timer::Metric<MPICount>::dump(Writer &) const;
00818 template Writer &Timer::Metric<MPIByteCount>::dump(Writer &) const;
00819 
00820 
00821 TimeBlockSynchronized::TimeBlockSynchronized(
00822   Timer &   timer,
00823   MPI_Comm    mpi_comm,
00824   bool      start_timer)
00825   : m_timer(timer),
00826     m_mpiComm(mpi_comm),
00827     m_started(start_timer)
00828 {
00829   if (m_timer.m_timerImpl->shouldRecord()) {
00830 #ifdef STK_HAS_MPI
00831     if (mpi_comm != MPI_COMM_NULL)
00832       MPI_Barrier(mpi_comm);
00833 #endif
00834 
00835     if (start_timer)
00836       m_timer.start();
00837   }
00838 }
00839 
00840 
00841 TimeBlockSynchronized::~TimeBlockSynchronized()
00842 {
00843   if (m_started) {
00844     try {
00845       m_timer.stop();
00846     }
00847     catch (...) {
00848     }
00849   }
00850 }
00851 
00852 
00853 void
00854 TimeBlockSynchronized::start()
00855 {
00856   // Place barrier here
00857   MPI_Barrier(m_mpiComm);
00858   m_started = true;
00859   m_timer.start();
00860 }
00861 
00862 
00863 void
00864 TimeBlockSynchronized::stop()
00865 {
00866   m_started = false;
00867   m_timer.stop();
00868   // Does a barrier need to be here?
00869   // MPI_Barrier(Env::parallel_comm());
00870 }
00871 
00872 } // namespace diag
00873 } // namespace stk

Generated on Tue Jul 13 09:27:32 2010 for Sierra Toolkit by  doxygen 1.4.7