Batch log queries and metrics

src/herder/HerderImpl.h

@@ -9,6 +9,7 @@
 #include "herder/PendingEnvelopes.h"
 #include "herder/TransactionQueue.h"
 #include "herder/Upgrades.h"
+#include "util/BatchMetrics.h"
 #include "util/Timer.h"
 #include "util/XDROperators.h"
 #include <deque>
@@ -173,18 +174,18 @@ class HerderImpl : public Herder
 
     struct SCPMetrics
     {
-        medida::Meter& mLostSync;
+        BatchMeter mLostSync;
 
-        medida::Meter& mEnvelopeEmit;
-        medida::Meter& mEnvelopeReceive;
+        BatchMeter mEnvelopeEmit;
+        BatchMeter mEnvelopeReceive;
 
         // Counters for things reached-through the
         // SCP maps: Slots and Nodes
         medida::Counter& mCumulativeStatements;
 
         // envelope signature verification
-        medida::Meter& mEnvelopeValidSig;
-        medida::Meter& mEnvelopeInvalidSig;
+        BatchMeter mEnvelopeValidSig;
+        BatchMeter mEnvelopeInvalidSig;
 
         SCPMetrics(Application& app);
     };

src/herder/HerderSCPDriver.cpp

@@ -923,7 +923,7 @@ HerderSCPDriver::recordSCPExecutionMetrics(uint64_t slotIndex)
     mPrepareTimeout.Update(SCPTiming.mPrepareTimeoutCount);
 
     auto recordTiming = [&](VirtualClock::time_point start,
-                            VirtualClock::time_point end, medida::Timer& timer,
+                            VirtualClock::time_point end, BatchTimer& timer,
                             std::string const& logStr) {
         auto delta =
             std::chrono::duration_cast<std::chrono::nanoseconds>(end - start);

src/herder/HerderSCPDriver.h

@@ -7,6 +7,7 @@
 #include "herder/Herder.h"
 #include "herder/TxSetFrame.h"
 #include "scp/SCPDriver.h"
+#include "util/BatchMetrics.h"
 #include "xdr/Stellar-ledger.h"
 
 namespace medida
@@ -153,17 +154,17 @@ class HerderSCPDriver : public SCPDriver
 
     struct SCPMetrics
     {
-        medida::Meter& mEnvelopeSign;
+        BatchMeter mEnvelopeSign;
 
-        medida::Meter& mValueValid;
-        medida::Meter& mValueInvalid;
+        BatchMeter mValueValid;
+        BatchMeter mValueInvalid;
 
         // listeners
-        medida::Meter& mCombinedCandidates;
+        BatchMeter mCombinedCandidates;
 
         // Timers for nomination and ballot protocols
-        medida::Timer& mNominateToPrepare;
-        medida::Timer& mPrepareToExternalize;
+        BatchTimer mNominateToPrepare;
+        BatchTimer mPrepareToExternalize;
 
         SCPMetrics(Application& app);
     };

src/ledger/LedgerManagerImpl.h

@@ -10,6 +10,7 @@
 #include "ledger/SyncingLedgerChain.h"
 #include "main/PersistentState.h"
 #include "transactions/TransactionFrame.h"
+#include "util/BatchMetrics.h"
 #include "xdr/Stellar-ledger.h"
 #include <string>
 
@@ -41,7 +42,7 @@ class LedgerManagerImpl : public LedgerManager
     Application& mApp;
 
   private:
-    medida::Timer& mTransactionApply;
+    BatchTimer mTransactionApply;
     medida::Histogram& mTransactionCount;
     medida::Histogram& mOperationCount;
     medida::Counter& mInternalErrorCount;

src/overlay/LoadManager.cpp

@@ -70,9 +70,12 @@ LoadManager::reportLoads(std::map<NodeID, Peer::pointer> const& peers,
         CLOG(INFO, "Overlay") << fmt::format(
             "{:>10s} {:>10s} {:>10s} {:>10s} {:>10d}",
             app.getConfig().toShortString(peer.first),
-            timeMag(static_cast<uint64_t>(cost->mTimeSpent.one_minute_rate())),
-            byteMag(static_cast<uint64_t>(cost->mBytesSend.one_minute_rate())),
-            byteMag(static_cast<uint64_t>(cost->mBytesRecv.one_minute_rate())),
+            timeMag(
+                static_cast<uint64_t>(cost->mTimeSpentBase.one_minute_rate())),
+            byteMag(
+                static_cast<uint64_t>(cost->mBytesSendBase.one_minute_rate())),
+            byteMag(
+                static_cast<uint64_t>(cost->mBytesRecvBase.one_minute_rate())),
             cost->mSQLQueries.count());
     }
     CLOG(INFO, "Overlay") << "";
@@ -134,23 +137,28 @@ LoadManager::maybeShedExcessLoad(Application& app)
 }
 
 LoadManager::PeerCosts::PeerCosts()
-    : mTimeSpent("nanoseconds")
-    , mBytesSend("byte")
-    , mBytesRecv("byte")
-    , mSQLQueries("query")
+    : mTimeSpentBase("nanoseconds")
+    , mBytesSendBase("byte")
+    , mBytesRecvBase("byte")
+    , mSQLQueriesBase("query")
+    , mTimeSpent(mTimeSpentBase)
+    , mBytesSend(mBytesSendBase)
+    , mBytesRecv(mBytesRecvBase)
+    , mSQLQueries(mSQLQueriesBase)
 {
 }
 
 bool
 LoadManager::PeerCosts::isLessThan(
     std::shared_ptr<LoadManager::PeerCosts> other)
 {
-    double ownRates[4] = {
-        mTimeSpent.one_minute_rate(), mBytesSend.one_minute_rate(),
-        mBytesRecv.one_minute_rate(), static_cast<double>(mSQLQueries.count())};
-    double otherRates[4] = {other->mTimeSpent.one_minute_rate(),
-                            other->mBytesSend.one_minute_rate(),
-                            other->mBytesRecv.one_minute_rate(),
+    double ownRates[4] = {mTimeSpentBase.one_minute_rate(),
+                          mBytesSendBase.one_minute_rate(),
+                          mBytesRecvBase.one_minute_rate(),
+                          static_cast<double>(mSQLQueries.count())};
+    double otherRates[4] = {other->mTimeSpentBase.one_minute_rate(),
+                            other->mBytesSendBase.one_minute_rate(),
+                            other->mBytesRecvBase.one_minute_rate(),
                             static_cast<double>(other->mSQLQueries.count())};
     return std::lexicographical_compare(ownRates, ownRates + 4, otherRates,
                                         otherRates + 4);
@@ -184,18 +192,15 @@ LoadManager::PeerContext::~PeerContext()
 {
     if (!isZero(mNode.ed25519()))
     {
+        auto& metrics = mApp.getOverlayManager().getOverlayMetrics();
         auto pc = mApp.getOverlayManager().getLoadManager().getPeerCosts(mNode);
         auto time = std::chrono::duration_cast<std::chrono::nanoseconds>(
             mApp.getClock().now() - mWorkStart);
-        auto send =
-            mApp.getOverlayManager().getOverlayMetrics().mByteWrite.count() -
-            mBytesSendStart;
-        auto recv =
-            mApp.getOverlayManager().getOverlayMetrics().mByteRead.count() -
-            mBytesRecvStart;
+        auto send = metrics.mByteWrite.count() - mBytesSendStart;
+        auto recv = metrics.mByteRead.count() - mBytesRecvStart;
         auto query =
             (mApp.getDatabase().getQueryMeter().count() - mSQLQueriesStart);
-        if (Logging::logTrace("Overlay"))
+        if (metrics.mLogLevel.logTrace())
             CLOG(TRACE, "Overlay")
                 << "Debiting peer " << mApp.getConfig().toShortString(mNode)
                 << " time:" << timeMag(time.count())

src/overlay/LoadManager.h

@@ -6,6 +6,7 @@
 
 #include "crypto/SecretKey.h"
 #include "overlay/Peer.h"
+#include "util/BatchMetrics.h"
 #include "util/HashOfHash.h"
 #include "util/lrucache.hpp"
 #include "xdr/Stellar-types.h"
@@ -48,10 +49,14 @@ class LoadManager
     {
         PeerCosts();
         bool isLessThan(std::shared_ptr<PeerCosts> other);
-        medida::Meter mTimeSpent;
-        medida::Meter mBytesSend;
-        medida::Meter mBytesRecv;
-        medida::Meter mSQLQueries;
+        medida::Meter mTimeSpentBase;
+        medida::Meter mBytesSendBase;
+        medida::Meter mBytesRecvBase;
+        medida::Meter mSQLQueriesBase;
+        BatchMeter mTimeSpent;
+        BatchMeter mBytesSend;
+        BatchMeter mBytesRecv;
+        BatchMeter mSQLQueries;
     };
 
     std::shared_ptr<PeerCosts> getPeerCosts(NodeID const& peer);

src/overlay/OverlayMetrics.h

@@ -9,6 +9,9 @@
 // tabulated at a per-peer level for purposes of identifying and
 // disconnecting overloading peers, see LoadManager for details.
 
+#include "util/BatchMetrics.h"
+#include "util/Logging.h"
+
 namespace medida
 {
 class Timer;
@@ -24,55 +27,56 @@ class Application;
 struct OverlayMetrics
 {
     OverlayMetrics(Application& app);
-    medida::Meter& mMessageRead;
-    medida::Meter& mMessageWrite;
-    medida::Meter& mByteRead;
-    medida::Meter& mByteWrite;
-    medida::Meter& mErrorRead;
-    medida::Meter& mErrorWrite;
-    medida::Meter& mTimeoutIdle;
-    medida::Meter& mTimeoutStraggler;
+    CachedLogLevel mLogLevel{"Overlay"};
+    BatchMeter mMessageRead;
+    BatchMeter mMessageWrite;
+    BatchMeter mByteRead;
+    BatchMeter mByteWrite;
+    BatchMeter mErrorRead;
+    BatchMeter mErrorWrite;
+    BatchMeter mTimeoutIdle;
+    BatchMeter mTimeoutStraggler;
 
-    medida::Timer& mRecvErrorTimer;
-    medida::Timer& mRecvHelloTimer;
-    medida::Timer& mRecvAuthTimer;
-    medida::Timer& mRecvDontHaveTimer;
-    medida::Timer& mRecvGetPeersTimer;
-    medida::Timer& mRecvPeersTimer;
-    medida::Timer& mRecvGetTxSetTimer;
-    medida::Timer& mRecvTxSetTimer;
-    medida::Timer& mRecvTransactionTimer;
-    medida::Timer& mRecvGetSCPQuorumSetTimer;
-    medida::Timer& mRecvSCPQuorumSetTimer;
-    medida::Timer& mRecvSCPMessageTimer;
-    medida::Timer& mRecvGetSCPStateTimer;
+    BatchTimer mRecvErrorTimer;
+    BatchTimer mRecvHelloTimer;
+    BatchTimer mRecvAuthTimer;
+    BatchTimer mRecvDontHaveTimer;
+    BatchTimer mRecvGetPeersTimer;
+    BatchTimer mRecvPeersTimer;
+    BatchTimer mRecvGetTxSetTimer;
+    BatchTimer mRecvTxSetTimer;
+    BatchTimer mRecvTransactionTimer;
+    BatchTimer mRecvGetSCPQuorumSetTimer;
+    BatchTimer mRecvSCPQuorumSetTimer;
+    BatchTimer mRecvSCPMessageTimer;
+    BatchTimer mRecvGetSCPStateTimer;
 
-    medida::Timer& mRecvSCPPrepareTimer;
-    medida::Timer& mRecvSCPConfirmTimer;
-    medida::Timer& mRecvSCPNominateTimer;
-    medida::Timer& mRecvSCPExternalizeTimer;
+    BatchTimer mRecvSCPPrepareTimer;
+    BatchTimer mRecvSCPConfirmTimer;
+    BatchTimer mRecvSCPNominateTimer;
+    BatchTimer mRecvSCPExternalizeTimer;
 
-    medida::Meter& mSendErrorMeter;
-    medida::Meter& mSendHelloMeter;
-    medida::Meter& mSendAuthMeter;
-    medida::Meter& mSendDontHaveMeter;
-    medida::Meter& mSendGetPeersMeter;
-    medida::Meter& mSendPeersMeter;
-    medida::Meter& mSendGetTxSetMeter;
-    medida::Meter& mSendTransactionMeter;
-    medida::Meter& mSendTxSetMeter;
-    medida::Meter& mSendGetSCPQuorumSetMeter;
-    medida::Meter& mSendSCPQuorumSetMeter;
-    medida::Meter& mSendSCPMessageSetMeter;
-    medida::Meter& mSendGetSCPStateMeter;
+    BatchMeter mSendErrorMeter;
+    BatchMeter mSendHelloMeter;
+    BatchMeter mSendAuthMeter;
+    BatchMeter mSendDontHaveMeter;
+    BatchMeter mSendGetPeersMeter;
+    BatchMeter mSendPeersMeter;
+    BatchMeter mSendGetTxSetMeter;
+    BatchMeter mSendTransactionMeter;
+    BatchMeter mSendTxSetMeter;
+    BatchMeter mSendGetSCPQuorumSetMeter;
+    BatchMeter mSendSCPQuorumSetMeter;
+    BatchMeter mSendSCPMessageSetMeter;
+    BatchMeter mSendGetSCPStateMeter;
 
-    medida::Meter& mMessagesBroadcast;
+    BatchMeter mMessagesBroadcast;
     medida::Counter& mPendingPeersSize;
     medida::Counter& mAuthenticatedPeersSize;
 
-    medida::Meter& mUniqueFloodBytesRecv;
-    medida::Meter& mDuplicateFloodBytesRecv;
-    medida::Meter& mUniqueFetchBytesRecv;
-    medida::Meter& mDuplicateFetchBytesRecv;
+    BatchMeter mUniqueFloodBytesRecv;
+    BatchMeter mDuplicateFloodBytesRecv;
+    BatchMeter mUniqueFetchBytesRecv;
+    BatchMeter mDuplicateFetchBytesRecv;
 };
 }