Dismiss Notice
Join Physics Forums Today!
The friendliest, high quality science and math community on the planet! Everyone who loves science is here!

Problem with timer.

  1. Jul 22, 2008 #1
    Hi everyone,

    I have been measuring some times for an application I'm doing, using some source code I found on the internet for measuring system time and user time used by an application. I am getting some very strange results though, and I wanted to ask if they were possible or were maybe due to some programming error.

    The results

    User time greater than real time, that's weird

    Reading from Dataset
    User time was: 19.333 /
    System time was: 1.29179
    Real time was: 18

    Their sum isn't close to the real time, where is this time being spent?
    Inserting to Database with engine MyISAM
    User time was: 0.396942
    System time was: 0.849879
    Real time was: 9

    Their sum isn't close to the real time, where is this time being spent?
    Inserting to Database with engine InnoDB
    User time was: 0.440937
    System time was: 1.70573
    Real time was: 211

    This is the source I'm using to measure time
    Code (Text):

    /* -------------------------------------------------------------

       Timer.hpp

       Implementation of a Timer class.

       (P)1999-2000  Laurentiu Cristofor

       -------------------------------------------------------------*/

    #ifndef _TIMER_HPP_
    #define _TIMER_HPP_

    extern "C"
    {
    #include <stdio.h>
    #include <string.h>
    #include <sys/types.h>
    #include <sys/time.h>
    #include <sys/resource.h>
    }

    #include <iostream>

    // This class is a container for time results
    class TimeElapsed
    {
     friend std::ostream& operator<<(std::ostream& os, TimeElapsed& t);

    private:
      long userTime, systemTime, realTime;

    public:
      TimeElapsed(long user, long system, long real)
        {
          userTime = user;
          systemTime = system;
          realTime = real;
        }

      long getUserTime()
        {
          return userTime;
        }

      long getSystemTime()
        {
          return systemTime;
        }

      long getRealTime()
        {
          return realTime;
        }
    };
    class Timer
    {
     private:
      time_t begin, end;
      struct rusage beginusage, endusage;
      // the time counted so far
      long utime, stime, rtime;

      // indicate whether the timer has been started
      bool started;

      // if true then return number of microseconds
      // for user and system time;
      // else return number of seconds.
      bool precision;

     public:
      // if precision is set to true, then the real and system time
      // will be measured in microseconds
      Timer(bool precision = false)
        {
          utime = stime = rtime = 0;
          started = false;
          this->precision = precision;
        }

      // start timer, if already started then do nothing
      void start()
        {
          if (started)
        return;

          started = true;
          begin = time(NULL);
          if (getrusage(RUSAGE_SELF, &beginusage) == -1)
        puts("getrusage error!");
        }

      // stop timer and return time measured so far.
      // if timer was stopped the time returned will be 0.
      TimeElapsed stop()
        {
          if (!started)
        return TimeElapsed(0, 0, 0);

          if (getrusage(RUSAGE_SELF, &endusage) == -1)
        puts("getrusage error!");
          end = time(NULL);
          started = false;

          if (precision)
        {
          long uusecs = (endusage.ru_utime.tv_sec
                 - beginusage.ru_utime.tv_sec) * 1000000
            + endusage.ru_utime.tv_usec - beginusage.ru_utime.tv_usec;
          utime += uusecs;

          long susecs = (endusage.ru_stime.tv_sec
                 - beginusage.ru_stime.tv_sec) * 1000000
            + endusage.ru_stime.tv_usec - beginusage.ru_stime.tv_usec;
          stime += susecs;
        }
          else
        {
          long usecs = (endusage.ru_utime.tv_sec
                - beginusage.ru_utime.tv_sec);
          utime += usecs;

          long ssecs = (endusage.ru_stime.tv_sec
                - beginusage.ru_stime.tv_sec);
          stime += ssecs;
        }

          rtime += (end - begin);

          return TimeElapsed(utime, stime, rtime);
        }

      // reset the timer, this will reset the time measured to 0 and
      // will leave the timer in the same status (started or stopped).
      void reset()
        {
          utime = stime = rtime = 0;

          if (started)
        {
          begin = time(NULL);
          if (getrusage(RUSAGE_SELF, &beginusage) == -1)
            puts("getrusage error!");
        }
        }

      // return time measured up to this point.
      TimeElapsed getTime()
      {
        if (!started)
          return TimeElapsed(utime, stime, rtime);

        if (getrusage(RUSAGE_SELF, &endusage) == -1)
          puts("getrusage error!");
        end = time(NULL);

        if (precision)
          {
        long uusecs = (endusage.ru_utime.tv_sec
                   - beginusage.ru_utime.tv_sec) * 1000000
          + endusage.ru_utime.tv_usec - beginusage.ru_utime.tv_usec;

        long susecs = (endusage.ru_stime.tv_sec
                   - beginusage.ru_stime.tv_sec) * 1000000
          + endusage.ru_stime.tv_usec - beginusage.ru_stime.tv_usec;

        return TimeElapsed(utime + uusecs,
                   stime + susecs,
                   rtime + end - begin);
          }
        else
          {
        long usecs = (endusage.ru_utime.tv_sec
                  - beginusage.ru_utime.tv_sec);
       
        long ssecs = (endusage.ru_stime.tv_sec
                  - beginusage.ru_stime.tv_sec);
       
        return TimeElapsed(utime + usecs,
                   stime + ssecs,
                   rtime + end - begin);
          }
      }

      bool isStarted()
      {
        return started;
      }
    };

    inline std::ostream& operator<<(std::ostream& os, TimeElapsed& t)
    {
        float userTime = t.getUserTime()/1000000.0;
        float sysTime  = t.getSystemTime()/1000000.0;
       
        os << "User time was: " << userTime << std::endl
           << "System time was: " << sysTime << std::endl
           << "Real time was: " << t.getRealTime() << std::endl;

        return os;
    }

    #endif // _TIMER_HPP_
     
     
  2. jcsd
  3. Jul 23, 2008 #2
    I analyzed this further, and I don't know if maybe someone knows what could be happening. With the previous program I was sending a query inserting rows to a table in MySQL, row by row (each row gets an insert query), and on the latest version I created an insert query with 500 rows. There is no major difference in inserting row by row in the MyISAM table type, but when doing that with InnoDB or Berkeley DB the times shoot up awfully high. Could this be attributed to the fact that InnoDB and BDB are transactional?

    o_O?
     
Know someone interested in this topic? Share this thread via Reddit, Google+, Twitter, or Facebook

Have something to add?



Similar Discussions: Problem with timer.
Loading...