Changeset 3f06bb for src


Ignore:
Timestamp:
Mar 2, 2013, 10:45:46 PM (13 years ago)
Author:
Frederik Heber <heber@…>
Children:
b9273a
Parents:
8f60da
git-author:
Frederik Heber <heber@…> (03/01/13 13:41:05)
git-committer:
Frederik Heber <heber@…> (03/02/13 22:45:46)
Message:

Enhanced Chronos for more accurate timekeeping.

  • Chronos is now safe to use w.r.t. recursive function calls.
  • Chronos now gets const ref of token name in each function.
  • TESTFIX: dummyTest() now checks on recursive function.
  • Chronos now offers its internal timekeeping via const ref to outside.
  • Chronos also now has up to nanoseconds precision when either time.h or sys/time.h is present.
  • librt required from clock_gettime().
Location:
src
Files:
8 edited

Legend:

Unmodified
Added
Removed
  • src/CodePatterns/Chronos.hpp

    r8f60da r3f06bb  
    1616#include <iosfwd>
    1717#include <map>
     18#include <string>
    1819
    1920#include "CodePatterns/Singleton.hpp"
     
    2930  friend std::ostream& operator<<(std::ostream &ost, const Chronos &_time);
    3031public :
     32  //!> typedef for the map storing times per token
     33  typedef std::map<const std::string, double> TimekeepingMap;
    3134
    3235  /** Returns current kept time of function \a _name.
     
    3538   * @return current amount of time passed for this function, 0 if unknown, -1 if currently running
    3639   */
    37   double getTime(const std::string _name) const;
     40  double getTime(const std::string &_name) const;
    3841
    3942  /** Resets time counter for this function \a _name to zero.
     
    4144   * @param _name name of function
    4245   */
    43   void resetTime(const std::string _name);
     46  void resetTime(const std::string &_name);
    4447
    4548  /** Starts Timing for this function \a _name.
     
    4750   * @param _name name of function
    4851   */
    49   void startTiming(const std::string _name);
     52  void startTiming(const std::string &_name);
    5053
    5154  /** Finishes Timing for this function \a _name.
     
    5356   * @param _name name of function
    5457   */
    55   void endTiming(const std::string _name);
     58  void endTiming(const std::string &_name);
     59
     60  /** Returns const reference to time keeping map.
     61   *
     62   * \return const ref to timekeeping map
     63   */
     64  const TimekeepingMap& getTimekeepingMap() const;
    5665
    5766  /** Sums up total time accounted for.
     
    8695  double getCurrentTime() const;
    8796
     97  //!> typedef for the map storing status of time keeping per token
     98  typedef std::map<const std::string, double> TimerMap;
    8899
    89   typedef std::map<const std::string, double> TimekeepingMap;
    90   typedef std::map<const std::string, double> TimerStatusMap;
     100  //!> typedef for the map storing number of recursive calls to this token
     101  typedef std::map<const std::string, size_t> TimerRecursionMap;
    91102
     103  //!> map storing times per token
    92104  TimekeepingMap AccountedTime;
    93   TimerStatusMap TimeRunning;
     105  //!> map storing time keeping status per token
     106  TimerMap StartingTime;
     107  //!> map storing level of recursion per token
     108  TimerRecursionMap RecursionMap;
     109
     110#ifdef HAVE_TIME_H
     111  timespec basetime;
     112#else
     113#ifdef HAVE_SYS_TIME_H
     114  struct timezone basetime;
     115#else
     116#ifdef HAVE_SYS_TIMES_H
     117  struct tms *basetime;
     118#endif
     119#endif
     120#endif
    94121};
    95122
     
    102129std::ostream& operator<<(std::ostream &ost, const Chronos &_time);
    103130
     131// inline functions
     132
     133inline
     134const Chronos::TimekeepingMap& Chronos::getTimekeepingMap() const
     135{
     136  return AccountedTime;
     137}
     138
    104139#endif /* CHRONOS_HPP_ */
  • src/Helpers/Chronos.cpp

    r8f60da r3f06bb  
    3939
    4040Chronos::Chronos()
    41 {}
     41{
     42  // get time and store it internally as base time
     43#ifdef HAVE_TIME_H
     44  clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &basetime);
     45#else
     46#ifdef HAVE_SYS_TIME_H
     47  struct timezone timezone1;
     48  gettimeofday(&basetime, &timezone1);
     49#else
     50#ifdef HAVE_SYS_TIMES_H
     51  struct tms *basetime = new tms;
     52  times(basetime);
     53#endif
     54#endif
     55#endif
     56}
    4257
    4358Chronos::~Chronos()
    44 {}
    45 
    46 double Chronos::getTime(const std::string _name) const
     59{
     60#ifndef HAVE_TIME_H
     61#ifndef HAVE_SYS_TIME_H
     62#ifdef HAVE_SYS_TIMES_H
     63  delete basetime;
     64#endif
     65#endif
     66#endif
     67}
     68
     69double Chronos::getTime(const std::string &_name) const
    4770{
    4871  // only those functions have a time that have run already
    49   if (TimeRunning.count(_name)) {
     72  if (AccountedTime.count(_name) != 0) {
    5073    // return -1 if function is currently running
    51     if (TimeRunning.count(_name) != 0.)
     74    if (StartingTime.count(_name) == 0.)
    5275      return AccountedTime.at(_name);
    5376    else
     
    5780}
    5881
    59 void Chronos::resetTime(const std::string _name)
    60 {
    61   if (TimeRunning.count(_name)) {
     82void Chronos::resetTime(const std::string &_name)
     83{
     84  // set accounted time to zero
     85  if (AccountedTime.count(_name) != 0) {
    6286    AccountedTime[_name] = 0.;
    6387  }
    64 }
    65 
    66 void Chronos::startTiming(const std::string _name)
     88  // and end if it's currently running
     89  StartingTime.erase(_name);
     90  RecursionMap.erase(_name);
     91}
     92
     93void Chronos::startTiming(const std::string &_name)
    6794{
    6895  // start time keeping
    69   TimeRunning[_name] = getCurrentTime();
     96  if ((RecursionMap.count(_name) == 0) || (RecursionMap[_name] == 0)) {
     97    StartingTime[_name] = getCurrentTime();
     98    RecursionMap[_name] = 1;
     99  } else {
     100    ++RecursionMap[_name];
     101  }
    70102}
    71103
    72104double Chronos::getCurrentTime() const
    73105{
    74 #ifdef HAVE_SYS_TIMES_H
     106#ifdef HAVE_TIME_H
     107  // clock_gettime gives nanoseconds accuracy
     108  timespec time1;
     109  clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &time1);
     110  double currenttime;
     111  if (time1.tv_nsec < basetime.tv_nsec)
     112    currenttime = (time1.tv_sec - basetime.tv_sec - 1)
     113        + (basetime.tv_nsec - time1.tv_nsec) * 1.e-9;
     114  else
     115    currenttime = (time1.tv_sec - basetime.tv_sec)
     116        + (time1.tv_nsec - basetime.tv_nsec) * 1.e-9;
     117#else
     118#ifdef HAVE_SYS_TIME_H
     119  struct timezone timezone1;
     120  timeval time1;
     121  // gettimeofday gives microseconds accuracy
     122  gettimeofday(&time1, &timezone1);
     123  double currenttime;
     124  if (time1.tv_usec < basetime.tv_usec)
     125    currenttime = (time1.tv_sec - basetime.tv_sec - 1)
     126        + (basetime.tv_usec - time1.tv_usec) * 1.e-6;
     127  else
     128    currenttime = (time1.tv_sec - basetime.tv_sec)
     129        + (time1.tv_usec - basetime.tv_usec) * 1.e-6;
     130#else
     131#ifdef HAVE_SYS_TIMES_H
     132  // clock is only accurate up to milliseconds
    75133  struct tms *buffer = new tms;
    76134  double currenttime;
    77135  if (times(buffer) != (clock_t)(-1))
    78     currenttime = ((double)buffer->tms_utime/(double)sysconf(_SC_CLK_TCK));
     136    currenttime =
     137        (double)(buffer->tms_utime - basetime->tms_utime)/(double)sysconf(_SC_CLK_TCK);
    79138  else
    80139    currenttime = 0.;
    81140  delete buffer;
    82141#else
    83   const double currenttime = (clock()/(double)CLOCKS_PER_SEC);
     142  // no time keeping possible
     143  const double currenttime = 0.;
     144#endif
     145#endif
    84146#endif
    85147  //std::cout << "Current time is " << currenttime << std::endl;
     
    87149}
    88150
    89 void Chronos::endTiming(const std::string _name)
    90 {
     151void Chronos::endTiming(const std::string &_name)
     152{
     153  // check whether we are the topmost function, return if not
     154  if (--RecursionMap[_name] != 0)
     155    return;
     156
     157  // if present
     158  ASSERT(StartingTime.count(_name), "Chronos::endTiming() - no timer under "
     159      +_name+" running.");
     160  ASSERT(RecursionMap.count(_name), "Chronos::endTiming() - negative recursion level for "
     161      +_name+".");
     162
     163  // finish time keeping
    91164  const double endtime = getCurrentTime();
    92   const double starttime = TimeRunning[_name];
    93 
    94   // if present
    95   ASSERT(TimeRunning.count(_name), "Chronos::endTiming() - no timer under "+_name+" running.");
    96   // finish time keeping
     165  const double starttime = StartingTime[_name];
    97166  const double RunTime = ((double)endtime - starttime);
    98   TimekeepingMap::iterator iter = AccountedTime.find(_name);
    99   if (iter != AccountedTime.end())
     167  if (AccountedTime.count(_name) != 0)
    100168    AccountedTime[_name] += RunTime;
    101169  else
     
    103171
    104172  // and zero for next run
    105   TimeRunning[_name] = 0.;
     173  StartingTime.erase(_name);
    106174}
    107175
     
    119187size_t Chronos::SumUpTotalFunctions() const
    120188{
    121   return TimeRunning.size();
     189  return AccountedTime.size();
    122190}
    123191
  • src/Helpers/Makefile.am

    r8f60da r3f06bb  
    4444        $(BOOST_THREAD_LDFLAGS)
    4545libCodePatterns_Helpers_la_LIBADD = \
     46        $(LIBRT) \
    4647        $(BOOST_THREAD_LIBS)
    4748libCodePatterns_Helpers_debug_la_LIBADD = \
     49        $(LIBRT) \
    4850        $(BOOST_THREAD_LIBS)
    4951
  • src/Helpers/unittests/ChronosUnitTest.cpp

    r8f60da r3f06bb  
    5454}
    5555
     56static size_t level = 0;
     57
     58void dummyRecursion()
     59{
     60  if (level > 2)
     61    return;
     62  ++level;
     63  Chronos::getInstance().startTiming(__func__);
     64  for (int i=0;i<10;++i) {
     65    std::cout << "";
     66    dummyRecursion();
     67  }
     68  Chronos::getInstance().endTiming(__func__);
     69  --level;
     70}
     71
    5672
    5773void ChronosTest::setUp()
     
    7894void ChronosTest::dummyTest()
    7995{
    80   double timings[4];
     96  double timings[5];
    8197  // first dummy
    8298  dummy();
    83   CPPUNIT_ASSERT( Chronos::getInstance().TimeRunning.find(std::string("dummy"))
    84       != Chronos::getInstance().TimeRunning.end() );
     99  CPPUNIT_ASSERT( Chronos::getInstance().StartingTime.find(std::string("dummy"))
     100      == Chronos::getInstance().StartingTime.end() );
     101  CPPUNIT_ASSERT( Chronos::getInstance().AccountedTime.find(std::string("dummy"))
     102      != Chronos::getInstance().AccountedTime.end() );
    85103  CPPUNIT_ASSERT_EQUAL( (size_t) 1, Chronos::getInstance().SumUpTotalFunctions() );
    86104  timings[0] = Chronos::getInstance().AccountedTime[std::string("dummy")];
    87105  std::cout << "Timing[0]: " << timings[0] << std::endl;
    88106  CPPUNIT_ASSERT(timings[0] > 0.);
     107
     108  // second call goes to same entry
    89109  dummy();
    90   // second call goes to same entry
    91110  CPPUNIT_ASSERT_EQUAL( (size_t) 1, Chronos::getInstance().SumUpTotalFunctions() );
    92111  timings[1] = Chronos::getInstance().AccountedTime[std::string("dummy")] - timings[0];
     
    94113  CPPUNIT_ASSERT(timings[1] > 0.);
    95114
    96 
    97115  // second dummy
    98116  dummy_two();
    99   CPPUNIT_ASSERT( Chronos::getInstance().TimeRunning.find(std::string("dummy_two"))
    100       != Chronos::getInstance().TimeRunning.end() );
     117  CPPUNIT_ASSERT( Chronos::getInstance().AccountedTime.find(std::string("dummy_two"))
     118      != Chronos::getInstance().AccountedTime.end() );
    101119  CPPUNIT_ASSERT_EQUAL( (size_t) 2, Chronos::getInstance().SumUpTotalFunctions() );
    102120  timings[2] = Chronos::getInstance().AccountedTime[std::string("dummy_two")];
    103121  std::cout << "Timing[2]: " << timings[2] << std::endl;
    104122  CPPUNIT_ASSERT(timings[2] > 0.);
     123
     124  // recursive dummy
     125  dummyRecursion();
     126  CPPUNIT_ASSERT( Chronos::getInstance().RecursionMap.find(std::string("dummyRecursion"))
     127      != Chronos::getInstance().RecursionMap.end() );
     128  CPPUNIT_ASSERT( Chronos::getInstance().AccountedTime.find(std::string("dummyRecursion"))
     129      != Chronos::getInstance().AccountedTime.end() );
     130  CPPUNIT_ASSERT_EQUAL( (size_t) 3, Chronos::getInstance().SumUpTotalFunctions() );
     131  timings[3] = Chronos::getInstance().AccountedTime[std::string("dummyRecursion")];
     132  std::cout << "Timing[3]: " << timings[3] << std::endl;
     133  CPPUNIT_ASSERT(timings[3] > 0.);
    105134
    106135  // "inline" dummy
     
    111140    Chronos::getInstance().endTiming("dummy_three");
    112141  }
    113   CPPUNIT_ASSERT( Chronos::getInstance().TimeRunning.find(std::string("dummy_three"))
    114       != Chronos::getInstance().TimeRunning.end() );
    115   CPPUNIT_ASSERT_EQUAL( (size_t) 3, Chronos::getInstance().SumUpTotalFunctions() );
    116   timings[3] = Chronos::getInstance().AccountedTime[std::string("dummy_three")];
    117   std::cout << "Timing[3]: " << timings[3] << std::endl;
    118   CPPUNIT_ASSERT(timings[3] > 0.);
     142  CPPUNIT_ASSERT( Chronos::getInstance().AccountedTime.find(std::string("dummy_three"))
     143      != Chronos::getInstance().AccountedTime.end() );
     144  CPPUNIT_ASSERT_EQUAL( (size_t) 4, Chronos::getInstance().SumUpTotalFunctions() );
     145  timings[4] = Chronos::getInstance().AccountedTime[std::string("dummy_three")];
     146  std::cout << "Timing[4]: " << timings[4] << std::endl;
     147  CPPUNIT_ASSERT(timings[4] > 0.);
    119148
    120149  // check summing of times
    121   CPPUNIT_ASSERT( fabs(timings[0] + timings[1] + timings[2] + timings[3]- Chronos::getInstance().SumUpTotalTime()) < numeric_limits<double>::epsilon());
     150  CPPUNIT_ASSERT( fabs(timings[0] + timings[1] + timings[2] + timings[3] + timings[4]- Chronos::getInstance().SumUpTotalTime()) < numeric_limits<double>::epsilon());
    122151
    123152  std::cout << Chronos::getInstance() << std::endl;
  • src/Helpers/unittests/Makefile.am

    r8f60da r3f06bb  
    4646        $(top_srcdir)/src/CodePatterns/Info.hpp
    4747ChronosUnitTest_LDADD = \
    48         ../Helpers/libCodePatterns-Helpers-debug.la
     48        ../Helpers/libCodePatterns-Helpers-debug.la \
     49        $(LIBRT)
    4950
    5051InfoUnitTest_SOURCES = UnitTestMain.cpp \
  • src/Helpers/unittests/stubs/ChronosStub.cpp

    r8f60da r3f06bb  
    2828{}
    2929
    30 double Chronos::getTime(const std::string _name) const
     30double Chronos::getTime(const std::string &_name) const
    3131{
    3232  return 0.;
    3333}
    3434
    35 void Chronos::resetTime(const std::string _name)
     35void Chronos::resetTime(const std::string &_name)
    3636{}
    3737
    38 void Chronos::startTiming(const std::string _name)
     38void Chronos::startTiming(const std::string &_name)
    3939{}
    4040
     
    4444}
    4545
    46 void Chronos::endTiming(const std::string _name)
     46void Chronos::endTiming(const std::string &_name)
    4747{}
    4848
  • src/Makefile.am

    r8f60da r3f06bb  
    5858        Patterns/libCodePatterns-Patterns.la \
    5959        Observer/libCodePatterns-Observer.la \
    60         Helpers/libCodePatterns-Helpers.la
     60        Helpers/libCodePatterns-Helpers.la \
     61        $(LIBRT)
    6162libCodePatterns_debug_la_LIBADD = \
    6263        Patterns/libCodePatterns-Patterns-debug.la \
    6364        Observer/libCodePatterns-Observer-debug.la \
    64         Helpers/libCodePatterns-Helpers-debug.la
     65        Helpers/libCodePatterns-Helpers-debug.la \
     66        $(LIBRT)
    6567
    6668libCodePatterns_la_CPPFLAGS = -DNDEBUG -DNO_MEMDEBUG $(AM_CPPFLAGS)
  • src/unittests/Makefile.am

    r8f60da r3f06bb  
    2929        ../Patterns/libCodePatterns-Patterns-debug.la \
    3030        ../Observer/libCodePatterns-Observer-debug.la \
    31         ../Helpers/libCodePatterns-Helpers-debug.la
     31        ../Helpers/libCodePatterns-Helpers-debug.la \
     32        $(LIBRT)
    3233
    3334#AUTOMAKE_OPTIONS = parallel-tests
Note: See TracChangeset for help on using the changeset viewer.