From 3757829f8e1f763f60ec71517019dc228c0a8813 Mon Sep 17 00:00:00 2001 From: Howard Hinnant Date: Thu, 28 Sep 2017 13:38:46 -0400 Subject: [PATCH] Convert more timing code to * LoadMonitor * Entry * Import --- src/ripple/app/main/Application.cpp | 12 ++-- src/ripple/app/misc/impl/ValidatorSite.cpp | 4 +- src/ripple/basics/KeyCache.h | 4 +- src/ripple/core/JobTypeInfo.h | 11 ++-- src/ripple/core/JobTypes.h | 77 +++++++++++----------- src/ripple/core/LoadMonitor.h | 28 ++++---- src/ripple/core/impl/JobQueue.cpp | 19 +++--- src/ripple/core/impl/LoadMonitor.cpp | 27 ++++---- src/ripple/resource/impl/Entry.h | 8 +-- src/ripple/resource/impl/Import.h | 4 +- src/ripple/resource/impl/Logic.h | 8 +-- src/ripple/resource/impl/Tuning.h | 14 ++-- src/ripple/shamap/impl/SHAMapSync.cpp | 3 +- src/test/resource/Logic_test.cpp | 5 +- 14 files changed, 120 insertions(+), 104 deletions(-) diff --git a/src/ripple/app/main/Application.cpp b/src/ripple/app/main/Application.cpp index 360fac71b6..40b3311b57 100644 --- a/src/ripple/app/main/Application.cpp +++ b/src/ripple/app/main/Application.cpp @@ -247,16 +247,16 @@ private: void operator() (Duration const& elapsed) { using namespace std::chrono; - auto const ms (ceil (elapsed)); + auto const lastSample = ceil(elapsed); - lastSample_ = ms; + lastSample_ = lastSample; - if (ms.count() >= 10) - m_event.notify (ms); - if (ms.count() >= 500) + if (lastSample >= 10ms) + m_event.notify (lastSample); + if (lastSample >= 500ms) { JLOG(m_journal.warn()) << - "io_service latency = " << ms.count(); + "io_service latency = " << lastSample.count(); } } diff --git a/src/ripple/app/misc/impl/ValidatorSite.cpp b/src/ripple/app/misc/impl/ValidatorSite.cpp index 82f1d910e2..58052ef840 100644 --- a/src/ripple/app/misc/impl/ValidatorSite.cpp +++ b/src/ripple/app/misc/impl/ValidatorSite.cpp @@ -49,7 +49,7 @@ ValidatorSite::ValidatorSite ( ValidatorSite::~ValidatorSite() { std::unique_lock lock{state_mutex_}; - if (timer_.expires_at().time_since_epoch().count()) + if (timer_.expires_at() > clock_type::time_point{}) { if (! stopping_) { @@ -100,7 +100,7 @@ void ValidatorSite::start () { std::lock_guard lock{state_mutex_}; - if (! timer_.expires_at().time_since_epoch().count()) + if (timer_.expires_at() == clock_type::time_point{}) setTimer (); } diff --git a/src/ripple/basics/KeyCache.h b/src/ripple/basics/KeyCache.h index 3cb0bb64a5..ed6560ab07 100644 --- a/src/ripple/basics/KeyCache.h +++ b/src/ripple/basics/KeyCache.h @@ -252,8 +252,8 @@ public: } else { - when_expire = now - clock_type::duration ( - m_target_age.count() * m_target_size / m_map.size ()); + when_expire = now - + m_target_age * m_target_size / m_map.size(); clock_type::duration const minimumAge ( std::chrono::seconds (1)); diff --git a/src/ripple/core/JobTypeInfo.h b/src/ripple/core/JobTypeInfo.h index cc251e384e..bb2e3f7352 100644 --- a/src/ripple/core/JobTypeInfo.h +++ b/src/ripple/core/JobTypeInfo.h @@ -37,15 +37,16 @@ private: bool const m_special; /** Average and peak latencies for this job type. 0 is none specified */ - std::uint64_t const m_avgLatency; - std::uint64_t const m_peakLatency; + std::chrono::milliseconds const m_avgLatency; + std::chrono::milliseconds const m_peakLatency; public: // Not default constructible JobTypeInfo () = delete; JobTypeInfo (JobType type, std::string name, int limit, - bool special, std::uint64_t avgLatency, std::uint64_t peakLatency) + bool special, std::chrono::milliseconds avgLatency, + std::chrono::milliseconds peakLatency) : m_type (type) , m_name (name) , m_limit (limit) @@ -76,12 +77,12 @@ public: return m_special; } - std::uint64_t getAverageLatency () const + std::chrono::milliseconds getAverageLatency () const { return m_avgLatency; } - std::uint64_t getPeakLatency () const + std::chrono::milliseconds getPeakLatency () const { return m_peakLatency; } diff --git a/src/ripple/core/JobTypes.h b/src/ripple/core/JobTypes.h index 6943412e43..b0b7c3083e 100644 --- a/src/ripple/core/JobTypes.h +++ b/src/ripple/core/JobTypes.h @@ -34,46 +34,48 @@ public: using const_iterator = Map::const_iterator; JobTypes () - : m_unknown (jtINVALID, "invalid", 0, true, 0, 0) + : m_unknown (jtINVALID, "invalid", 0, true, std::chrono::milliseconds{0}, + std::chrono::milliseconds{0}) { + using namespace std::chrono_literals; int maxLimit = std::numeric_limits ::max (); -add( jtPACK, "makeFetchPack", 1, false, 0, 0); -add( jtPUBOLDLEDGER, "publishAcqLedger", 2, false, 10000, 15000); -add( jtVALIDATION_ut, "untrustedValidation", maxLimit, false, 2000, 5000); -add( jtTRANSACTION_l, "localTransaction", maxLimit, false, 100, 500); -add( jtLEDGER_REQ, "ledgerRequest", 2, false, 0, 0); -add( jtPROPOSAL_ut, "untrustedProposal", maxLimit, false, 500, 1250); -add( jtLEDGER_DATA, "ledgerData", 2, false, 0, 0); -add( jtCLIENT, "clientCommand", maxLimit, false, 2000, 5000); -add( jtRPC, "RPC", maxLimit, false, 0, 0); -add( jtUPDATE_PF, "updatePaths", maxLimit, false, 0, 0); -add( jtTRANSACTION, "transaction", maxLimit, false, 250, 1000); -add( jtBATCH, "batch", maxLimit, false, 250, 1000); -add( jtADVANCE, "advanceLedger", maxLimit, false, 0, 0); -add( jtPUBLEDGER, "publishNewLedger", maxLimit, false, 3000, 4500); -add( jtTXN_DATA, "fetchTxnData", 1, false, 0, 0); -add( jtWAL, "writeAhead", maxLimit, false, 1000, 2500); -add( jtVALIDATION_t, "trustedValidation", maxLimit, false, 500, 1500); -add( jtWRITE, "writeObjects", maxLimit, false, 1750, 2500); -add( jtACCEPT, "acceptLedger", maxLimit, false, 0, 0); -add( jtPROPOSAL_t, "trustedProposal", maxLimit, false, 100, 500); -add( jtSWEEP, "sweep", maxLimit, false, 0, 0); -add( jtNETOP_CLUSTER, "clusterReport", 1, false, 9999, 9999); -add( jtNETOP_TIMER, "heartbeat", 1, false, 999, 999); -add( jtADMIN, "administration", maxLimit, false, 0, 0); +add( jtPACK, "makeFetchPack", 1, false, 0ms, 0ms); +add( jtPUBOLDLEDGER, "publishAcqLedger", 2, false, 10000ms, 15000ms); +add( jtVALIDATION_ut, "untrustedValidation", maxLimit, false, 2000ms, 5000ms); +add( jtTRANSACTION_l, "localTransaction", maxLimit, false, 100ms, 500ms); +add( jtLEDGER_REQ, "ledgerRequest", 2, false, 0ms, 0ms); +add( jtPROPOSAL_ut, "untrustedProposal", maxLimit, false, 500ms, 1250ms); +add( jtLEDGER_DATA, "ledgerData", 2, false, 0ms, 0ms); +add( jtCLIENT, "clientCommand", maxLimit, false, 2000ms, 5000ms); +add( jtRPC, "RPC", maxLimit, false, 0ms, 0ms); +add( jtUPDATE_PF, "updatePaths", maxLimit, false, 0ms, 0ms); +add( jtTRANSACTION, "transaction", maxLimit, false, 250ms, 1000ms); +add( jtBATCH, "batch", maxLimit, false, 250ms, 1000ms); +add( jtADVANCE, "advanceLedger", maxLimit, false, 0ms, 0ms); +add( jtPUBLEDGER, "publishNewLedger", maxLimit, false, 3000ms, 4500ms); +add( jtTXN_DATA, "fetchTxnData", 1, false, 0ms, 0ms); +add( jtWAL, "writeAhead", maxLimit, false, 1000ms, 2500ms); +add( jtVALIDATION_t, "trustedValidation", maxLimit, false, 500ms, 1500ms); +add( jtWRITE, "writeObjects", maxLimit, false, 1750ms, 2500ms); +add( jtACCEPT, "acceptLedger", maxLimit, false, 0ms, 0ms); +add( jtPROPOSAL_t, "trustedProposal", maxLimit, false, 100ms, 500ms); +add( jtSWEEP, "sweep", maxLimit, false, 0ms, 0ms); +add( jtNETOP_CLUSTER, "clusterReport", 1, false, 9999ms, 9999ms); +add( jtNETOP_TIMER, "heartbeat", 1, false, 999ms, 999ms); +add( jtADMIN, "administration", maxLimit, false, 0ms, 0ms); -add( jtPEER, "peerCommand", 0, true, 200, 2500); -add( jtDISK, "diskAccess", 0, true, 500, 1000); -add( jtTXN_PROC, "processTransaction", 0, true, 0, 0); -add( jtOB_SETUP, "orderBookSetup", 0, true, 0, 0); -add( jtPATH_FIND, "pathFind", 0, true, 0, 0); -add( jtHO_READ, "nodeRead", 0, true, 0, 0); -add( jtHO_WRITE, "nodeWrite", 0, true, 0, 0); -add( jtGENERIC, "generic", 0, true, 0, 0); -add( jtNS_SYNC_READ, "SyncReadNode", 0, true, 0, 0); -add( jtNS_ASYNC_READ, "AsyncReadNode", 0, true, 0, 0); -add( jtNS_WRITE, "WriteNode", 0, true, 0, 0); +add( jtPEER, "peerCommand", 0, true, 200ms, 2500ms); +add( jtDISK, "diskAccess", 0, true, 500ms, 1000ms); +add( jtTXN_PROC, "processTransaction", 0, true, 0ms, 0ms); +add( jtOB_SETUP, "orderBookSetup", 0, true, 0ms, 0ms); +add( jtPATH_FIND, "pathFind", 0, true, 0ms, 0ms); +add( jtHO_READ, "nodeRead", 0, true, 0ms, 0ms); +add( jtHO_WRITE, "nodeWrite", 0, true, 0ms, 0ms); +add( jtGENERIC, "generic", 0, true, 0ms, 0ms); +add( jtNS_SYNC_READ, "SyncReadNode", 0, true, 0ms, 0ms); +add( jtNS_ASYNC_READ, "AsyncReadNode", 0, true, 0ms, 0ms); +add( jtNS_WRITE, "WriteNode", 0, true, 0ms, 0ms); } @@ -115,7 +117,8 @@ add( jtNS_WRITE, "WriteNode", 0, true, 0, 0); private: void add(JobType jt, std::string name, int limit, - bool special, std::uint64_t avgLatency, std::uint64_t peakLatency) + bool special, std::chrono::milliseconds avgLatency, + std::chrono::milliseconds peakLatency) { assert (m_map.find (jt) == m_map.end ()); diff --git a/src/ripple/core/LoadMonitor.h b/src/ripple/core/LoadMonitor.h index db7058d86e..64d0a7e15e 100644 --- a/src/ripple/core/LoadMonitor.h +++ b/src/ripple/core/LoadMonitor.h @@ -41,19 +41,21 @@ public: void addSamples (int count, std::chrono::milliseconds latency); - void setTargetLatency (std::uint64_t avg, std::uint64_t pk); + void setTargetLatency (std::chrono::milliseconds avg, + std::chrono::milliseconds pk); - bool isOverTarget (std::uint64_t avg, std::uint64_t peak); + bool isOverTarget (std::chrono::milliseconds avg, + std::chrono::milliseconds peak); // VFALCO TODO make this return the values in a struct. struct Stats { Stats(); - std::uint64_t count; - std::uint64_t latencyAvg; - std::uint64_t latencyPeak; - bool isOverloaded; + std::uint64_t count; + std::chrono::milliseconds latencyAvg; + std::chrono::milliseconds latencyPeak; + bool isOverloaded; }; Stats getStats (); @@ -65,13 +67,13 @@ private: std::mutex mutex_; - std::uint64_t mCounts; - int mLatencyEvents; - std::uint64_t mLatencyMSAvg; - std::uint64_t mLatencyMSPeak; - std::uint64_t mTargetLatencyAvg; - std::uint64_t mTargetLatencyPk; - int mLastUpdate; + std::uint64_t mCounts; + int mLatencyEvents; + std::chrono::milliseconds mLatencyMSAvg; + std::chrono::milliseconds mLatencyMSPeak; + std::chrono::milliseconds mTargetLatencyAvg; + std::chrono::milliseconds mTargetLatencyPk; + int mLastUpdate; beast::Journal j_; }; diff --git a/src/ripple/core/impl/JobQueue.cpp b/src/ripple/core/impl/JobQueue.cpp index f68897e802..414624bbc9 100644 --- a/src/ripple/core/impl/JobQueue.cpp +++ b/src/ripple/core/impl/JobQueue.cpp @@ -221,6 +221,7 @@ JobQueue::isOverloaded () Json::Value JobQueue::getJson (int c) { + using namespace std::chrono_literals; Json::Value ret (Json::objectValue); ret["threads"] = m_workers.getNumberOfThreads (); @@ -244,7 +245,7 @@ JobQueue::getJson (int c) int running (data.running); if ((stats.count != 0) || (waiting != 0) || - (stats.latencyPeak != 0) || (running != 0)) + (stats.latencyPeak != 0ms) || (running != 0)) { Json::Value& pri = priorities.append (Json::objectValue); @@ -259,11 +260,11 @@ JobQueue::getJson (int c) if (stats.count != 0) pri["per_second"] = static_cast (stats.count); - if (stats.latencyPeak != 0) - pri["peak_time"] = static_cast (stats.latencyPeak); + if (stats.latencyPeak != 0ms) + pri["peak_time"] = static_cast (stats.latencyPeak.count()); - if (stats.latencyAvg != 0) - pri["avg_time"] = static_cast (stats.latencyAvg); + if (stats.latencyAvg != 0ms) + pri["avg_time"] = static_cast (stats.latencyAvg.count()); if (running != 0) pri["in_progress"] = running; @@ -408,9 +409,9 @@ void JobQueue::on_dequeue (JobType type, std::chrono::duration const& value) { using namespace std::chrono; - auto const ms (ceil (value)); + auto const ms = ceil(value); - if (ms.count() >= 10) + if (ms >= 10ms) getJobTypeData (type).dequeue.notify (ms); } @@ -419,9 +420,9 @@ void JobQueue::on_execute (JobType type, std::chrono::duration const& value) { using namespace std::chrono; - auto const ms (ceil (value)); + auto const ms (ceil (value)); - if (ms.count() >= 10) + if (ms >= 10ms) getJobTypeData (type).execute.notify (ms); } diff --git a/src/ripple/core/impl/LoadMonitor.cpp b/src/ripple/core/impl/LoadMonitor.cpp index 88aa3e7ef2..bb5c871db0 100644 --- a/src/ripple/core/impl/LoadMonitor.cpp +++ b/src/ripple/core/impl/LoadMonitor.cpp @@ -66,6 +66,7 @@ LoadMonitor::LoadMonitor (beast::Journal j) // call with the mutex void LoadMonitor::update () { + using namespace std::chrono_literals; int now = UptimeTimer::getInstance ().getElapsedSeconds (); if (now == mLastUpdate) // current return; @@ -76,8 +77,8 @@ void LoadMonitor::update () // way out of date mCounts = 0; mLatencyEvents = 0; - mLatencyMSAvg = 0; - mLatencyMSPeak = 0; + mLatencyMSAvg = 0ms; + mLatencyMSPeak = 0ms; mLastUpdate = now; // VFALCO TODO don't return from the middle... return; @@ -132,25 +133,28 @@ void LoadMonitor::addSamples (int count, std::chrono::milliseconds latency) update (); mCounts += count; mLatencyEvents += count; - mLatencyMSAvg += latency.count(); - mLatencyMSPeak += latency.count(); + mLatencyMSAvg += latency; + mLatencyMSPeak += latency; - int const latencyPeak = mLatencyEvents * latency.count() * 4 / count; + auto const latencyPeak = mLatencyEvents * latency * 4 / count; if (mLatencyMSPeak < latencyPeak) mLatencyMSPeak = latencyPeak; } -void LoadMonitor::setTargetLatency (std::uint64_t avg, std::uint64_t pk) +void LoadMonitor::setTargetLatency (std::chrono::milliseconds avg, + std::chrono::milliseconds pk) { mTargetLatencyAvg = avg; mTargetLatencyPk = pk; } -bool LoadMonitor::isOverTarget (std::uint64_t avg, std::uint64_t peak) +bool LoadMonitor::isOverTarget (std::chrono::milliseconds avg, + std::chrono::milliseconds peak) { - return (mTargetLatencyPk && (peak > mTargetLatencyPk)) || - (mTargetLatencyAvg && (avg > mTargetLatencyAvg)); + using namespace std::chrono_literals; + return (mTargetLatencyPk > 0ms && (peak > mTargetLatencyPk)) || + (mTargetLatencyAvg > 0ms && (avg > mTargetLatencyAvg)); } bool LoadMonitor::isOver () @@ -167,6 +171,7 @@ bool LoadMonitor::isOver () LoadMonitor::Stats LoadMonitor::getStats () { + using namespace std::chrono_literals; Stats stats; std::lock_guard sl (mutex_); @@ -177,8 +182,8 @@ LoadMonitor::Stats LoadMonitor::getStats () if (mLatencyEvents == 0) { - stats.latencyAvg = 0; - stats.latencyPeak = 0; + stats.latencyAvg = 0ms; + stats.latencyPeak = 0ms; } else { diff --git a/src/ripple/resource/impl/Entry.h b/src/ripple/resource/impl/Entry.h index db26cb783f..88e079be4c 100644 --- a/src/ripple/resource/impl/Entry.h +++ b/src/ripple/resource/impl/Entry.h @@ -46,8 +46,8 @@ struct Entry : refcount (0) , local_balance (now) , remote_balance (0) - , lastWarningTime (0) - , whenExpires (0) + , lastWarningTime () + , whenExpires () { } @@ -101,10 +101,10 @@ struct Entry int remote_balance; // Time of the last warning - clock_type::rep lastWarningTime; + clock_type::time_point lastWarningTime; // For inactive entries, time after which this entry will be erased - clock_type::rep whenExpires; + clock_type::time_point whenExpires; }; inline std::ostream& operator<< (std::ostream& os, Entry const& v) diff --git a/src/ripple/resource/impl/Import.h b/src/ripple/resource/impl/Import.h index 3ed72f7934..6b6d22fa63 100644 --- a/src/ripple/resource/impl/Import.h +++ b/src/ripple/resource/impl/Import.h @@ -36,12 +36,12 @@ struct Import // Dummy argument required for zero-copy construction Import (int = 0) - : whenExpires (0) + : whenExpires () { } // When the imported data expires - clock_type::rep whenExpires; + clock_type::time_point whenExpires; // List of remote entries std::vector items; diff --git a/src/ripple/resource/impl/Logic.h b/src/ripple/resource/impl/Logic.h index af9640151a..27249ddc87 100644 --- a/src/ripple/resource/impl/Logic.h +++ b/src/ripple/resource/impl/Logic.h @@ -281,7 +281,7 @@ public: void importConsumers (std::string const& origin, Gossip const& gossip) { - clock_type::rep const elapsed (m_clock.now().time_since_epoch().count()); + auto const elapsed = m_clock.now(); { std::lock_guard _(lock_); auto result = @@ -341,7 +341,7 @@ public: { std::lock_guard _(lock_); - clock_type::rep const elapsed (m_clock.now().time_since_epoch().count()); + auto const elapsed = m_clock.now(); for (auto iter (inactive_.begin()); iter != inactive_.end();) { @@ -435,7 +435,7 @@ public: break; } inactive_.push_back (entry); - entry.whenExpires = m_clock.now().time_since_epoch().count() + secondsUntilExpiration; + entry.whenExpires = m_clock.now() + secondsUntilExpiration; } } @@ -456,7 +456,7 @@ public: std::lock_guard _(lock_); bool notify (false); - clock_type::rep const elapsed (m_clock.now().time_since_epoch().count()); + auto const elapsed = m_clock.now(); if (entry.balance (m_clock.now()) >= warningThreshold && elapsed != entry.lastWarningTime) { diff --git a/src/ripple/resource/impl/Tuning.h b/src/ripple/resource/impl/Tuning.h index 9b300be8fa..894bd8d09f 100644 --- a/src/ripple/resource/impl/Tuning.h +++ b/src/ripple/resource/impl/Tuning.h @@ -20,6 +20,8 @@ #ifndef RIPPLE_RESOURCE_TUNING_H_INCLUDED #define RIPPLE_RESOURCE_TUNING_H_INCLUDED +#include + namespace ripple { namespace Resource { @@ -32,20 +34,20 @@ enum // Balance at which the consumer is disconnected ,dropThreshold = 1500 - // The number of seconds until an inactive table item is removed - ,secondsUntilExpiration = 300 - // The number of seconds in the exponential decay window // (This should be a power of two) ,decayWindowSeconds = 32 // The minimum balance required in order to include a load source in gossip ,minimumGossipBalance = 100 - - // Number of seconds until imported gossip expires - ,gossipExpirationSeconds = 30 }; +// The number of seconds until an inactive table item is removed +std::chrono::seconds constexpr secondsUntilExpiration{300}; + +// Number of seconds until imported gossip expires +std::chrono::seconds constexpr gossipExpirationSeconds{30}; + } } diff --git a/src/ripple/shamap/impl/SHAMapSync.cpp b/src/ripple/shamap/impl/SHAMapSync.cpp index c889a09994..53fc8f2eae 100644 --- a/src/ripple/shamap/impl/SHAMapSync.cpp +++ b/src/ripple/shamap/impl/SHAMapSync.cpp @@ -227,7 +227,8 @@ void SHAMap::gmn_ProcessDeferredReads (MissingNodes& mn) auto const process_time = std::chrono::duration_cast (std::chrono::steady_clock::now() - after); - if ((count > 50) || (elapsed.count() > 50)) + using namespace std::chrono_literals; + if ((count > 50) || (elapsed > 50ms)) { JLOG(journal_.debug()) << "getMissingNodes reads " << count << " nodes (" << hits << " hits) in " diff --git a/src/test/resource/Logic_test.cpp b/src/test/resource/Logic_test.cpp index 66eb2309c9..7199b4542a 100644 --- a/src/test/resource/Logic_test.cpp +++ b/src/test/resource/Logic_test.cpp @@ -144,10 +144,11 @@ public: // Makes sure the Consumer is eventually removed from blacklist bool readmitted = false; { + using namespace std::chrono_literals; // Give Consumer time to become readmitted. Should never // exceed expiration time. - std::size_t n (secondsUntilExpiration + 1); - while (--n > 0) + auto n = secondsUntilExpiration + 1s; + while (--n > 0s) { ++logic.clock (); logic.periodicActivity();