Track run and wait times for load samples

src/ripple_core/functional/LoadEvent.cpp

@@ -17,40 +17,74 @@
 */
 //==============================================================================
 
-
 LoadEvent::LoadEvent (LoadMonitor& monitor, const std::string& name, bool shouldStart)
-    : mMonitor (monitor)
-    , mRunning (false)
-    , mName (name)
+    : m_loadMonitor (monitor)
+    , m_isRunning (false)
+    , m_name (name)
+    , m_timeStopped (Time::getCurrentTime())
+    , m_secondsWaiting (0)
+    , m_secondsRunning (0)
 {
-    mStartTime = boost::posix_time::microsec_clock::universal_time ();
-
     if (shouldStart)
         start ();
 }
 
 LoadEvent::~LoadEvent ()
 {
-    if (mRunning)
+    if (m_isRunning)
         stop ();
 }
 
+std::string const& LoadEvent::name () const
+{
+    return m_name;
+}
+
+std::size_t LoadEvent::getSecondsWaiting() const
+{
+    return m_secondsWaiting;
+}
+
+std::size_t LoadEvent::getSecondsRunning() const
+{
+    return m_secondsRunning;
+}
+
+std::size_t LoadEvent::getSecondsTotal() const
+{
+    return m_secondsWaiting + m_secondsRunning;
+}
+
 void LoadEvent::reName (const std::string& name)
 {
-    mName = name;
+    m_name = name;
 }
 
 void LoadEvent::start ()
 {
-    mRunning = true;
-    mStartTime = boost::posix_time::microsec_clock::universal_time ();
+    Time currentTime (Time::getCurrentTime());
+
+    // If we already called start, this call will replace the previous one.
+    if (m_isRunning)
+    {
+        m_secondsWaiting += (currentTime - m_timeStarted).inSeconds();
+    }
+    else
+    {
+        m_secondsWaiting += (currentTime - m_timeStopped).inSeconds();
+        m_isRunning = true;
+    }
+
+    m_timeStarted = currentTime;
 }
 
 void LoadEvent::stop ()
 {
-    assert (mRunning);
+    bassert (m_isRunning);
 
-    mRunning = false;
-    mMonitor.addCountAndLatency (mName,
-                                 static_cast<int> ((boost::posix_time::microsec_clock::universal_time () - mStartTime).total_milliseconds ()));
+    m_timeStopped = Time::getCurrentTime();
+    m_secondsRunning += (m_timeStopped - m_timeStarted).inSeconds();
+
+    m_isRunning = false;
+    m_loadMonitor.addLoadSample (*this);
 }

src/ripple_core/functional/LoadEvent.h

@@ -48,19 +48,33 @@ public:
 
     ~LoadEvent ();
 
+    std::string const& name () const;
+    std::size_t getSecondsWaiting() const;
+    std::size_t getSecondsRunning() const;
+    std::size_t getSecondsTotal() const;
+
     // VFALCO TODO rename this to setName () or setLabel ()
     void reName (const std::string& name);
 
-    // okay to call if already started
+    // Start the measurement. The constructor calls this automatically if
+    // shouldStart is true. If the operation is aborted, start() can be
+    // called again later.
+    //
     void start ();
 
+    // Stops the measurement and reports the results. The time reported is
+    // measured from the last call to start.
+    //
     void stop ();
 
 private:
-    LoadMonitor&                mMonitor;
-    bool                        mRunning;
-    std::string                 mName;
-    boost::posix_time::ptime    mStartTime;
+    LoadMonitor& m_loadMonitor;
+    bool m_isRunning;
+    std::string m_name;
+    Time m_timeStopped;
+    Time m_timeStarted;
+    std::size_t m_secondsWaiting;
+    std::size_t m_secondsRunning;
 };
 
 #endif

src/ripple_core/functional/LoadMonitor.cpp

@@ -108,12 +108,16 @@ void LoadMonitor::addLatency (int latency)
         mLatencyMSPeak = latencyPeak;
 }
 
-
-void LoadMonitor::addCountAndLatency (const std::string& name, int latency)
+void LoadMonitor::addLoadSample (LoadEvent const& sample)
 {
+    std::string const& name (sample.name());
+    std::size_t latency (sample.getSecondsTotal());
+
     if (latency > 500)
     {
-        WriteLog ((latency > 1000) ? lsWARNING : lsINFO, LoadMonitor) << "Job: " << name << " ExecutionTime: " << latency;
+        WriteLog ((latency > 1000) ? lsWARNING : lsINFO, LoadMonitor)
+            << "Job: " << name << " ExecutionTime: " << sample.getSecondsRunning() <<
+            " WaitingTime: " << sample.getSecondsWaiting();
     }
 
     // VFALCO NOTE Why does 1 become 0?

src/ripple_core/functional/LoadMonitor.h

@@ -34,7 +34,7 @@ public:
 
     void addLatency (int latency);
 
-    void addCountAndLatency (const std::string& name, int latency);
+    void addLoadSample (LoadEvent const& sample);
 
     void setTargetLatency (uint64 avg, uint64 pk);