From bcb9729990f8fd38df10a2758756d09666578971 Mon Sep 17 00:00:00 2001 From: Ed Hennis Date: Fri, 29 Sep 2023 13:15:21 -0400 Subject: [PATCH 1/6] Determine TxQ network "health" by average consensus round time * Instead of a hard cutoff at 5s * Network is "unhealthy" if consensus round took more than 5s *AND* more than twice the recent average. --- src/test/app/TxQ_test.cpp | 12 ++++----- src/xrpld/app/consensus/RCLConsensus.cpp | 2 +- src/xrpld/app/misc/NetworkOPs.cpp | 2 +- src/xrpld/app/misc/TxQ.h | 30 ++++++++++++++++++---- src/xrpld/app/misc/detail/TxQ.cpp | 32 +++++++++++++++++++----- 5 files changed, 59 insertions(+), 19 deletions(-) diff --git a/src/test/app/TxQ_test.cpp b/src/test/app/TxQ_test.cpp index d176744c5cb..09200931c31 100644 --- a/src/test/app/TxQ_test.cpp +++ b/src/test/app/TxQ_test.cpp @@ -716,9 +716,9 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(charlie, daria)); - env.close(env.now() + 5s, 10000ms); + env.close(env.now() + 5s, 20001ms); env.fund(XRP(1000), noripple(edgar, felicia)); - env.close(env.now() + 5s, 10000ms); + env.close(env.now() + 5s, 30002ms); checkMetrics(*this, env, 0, std::nullopt, 0, 2); env(noop(bob)); @@ -837,7 +837,7 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(carol)); - env.close(env.now() + 5s, 10000ms); + env.close(env.now() + 5s, 20001ms); // Fill the ledger env(noop(alice)); @@ -4082,19 +4082,19 @@ class TxQPosNegFlows_test : public beast::unit_test::suite checkMetrics(*this, env, txCount, 56, 15, 14); // Close the ledger with a delay. - env.close(env.now() + 5s, 10000ms); + env.close(env.now() + 5s, 20001ms); txCount -= 8; checkMetrics(*this, env, txCount, 56, 8, 7); // Close the ledger with a delay. - env.close(env.now() + 5s, 10000ms); + env.close(env.now() + 5s, 30002ms); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); // From 28 expected back down to 3 in 3 "slow" ledgers. // Confirm the minimum sticks - env.close(env.now() + 5s, 10000ms); + env.close(env.now() + 5s, 60003ms); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); diff --git a/src/xrpld/app/consensus/RCLConsensus.cpp b/src/xrpld/app/consensus/RCLConsensus.cpp index 7734ab790d4..c2523c87d87 100644 --- a/src/xrpld/app/consensus/RCLConsensus.cpp +++ b/src/xrpld/app/consensus/RCLConsensus.cpp @@ -783,7 +783,7 @@ RCLConsensus::Adaptor::buildLCL( // Update fee computations based on accepted txs using namespace std::chrono_literals; - app_.getTxQ().processClosedLedger(app_, *built, roundTime > 5s); + app_.getTxQ().processClosedLedger(app_, *built, roundTime); // And stash the ledger in the ledger master if (ledgerMaster_.storeLedger(built)) diff --git a/src/xrpld/app/misc/NetworkOPs.cpp b/src/xrpld/app/misc/NetworkOPs.cpp index ebe539523be..720e63d0971 100644 --- a/src/xrpld/app/misc/NetworkOPs.cpp +++ b/src/xrpld/app/misc/NetworkOPs.cpp @@ -1981,7 +1981,7 @@ NetworkOPsImp::switchLastClosedLedger( clearNeedNetworkLedger(); // Update fee computations. - app_.getTxQ().processClosedLedger(app_, *newLCL, true); + app_.getTxQ().processClosedLedger(app_, *newLCL, std::nullopt); // Caller must own master lock { diff --git a/src/xrpld/app/misc/TxQ.h b/src/xrpld/app/misc/TxQ.h index 4c4bb3c9237..14bf8dc9c55 100644 --- a/src/xrpld/app/misc/TxQ.h +++ b/src/xrpld/app/misc/TxQ.h @@ -284,9 +284,18 @@ class TxQ Any transactions for which the `LastLedgerSequence` has passed are removed from the queue, and any account objects that have no candidates under them are removed. + + @param app Rippled Application object. + @param view View of the LCL that was just closed or received. + @param roundTime Time it took for the current consensus round to + complete. If unseated, indicates "unusual" processing, such as + startup or re-syncing. */ void - processClosedLedger(Application& app, ReadView const& view, bool timeLeap); + processClosedLedger( + Application& app, + ReadView const& view, + std::optional const& roundTime); /** Return the next sequence that would go in the TxQ for an account. */ SeqProxy @@ -372,12 +381,18 @@ class TxQ /// Recent history of transaction counts that /// exceed the targetTxnCount_ boost::circular_buffer recentTxnCounts_; + /// Recent history of consensus round times + boost::circular_buffer recentRoundTimes_; /// Based on the median fee of the LCL. Used /// when fee escalation kicks in. FeeLevel64 escalationMultiplier_; /// Journal beast::Journal const j_; + /// Any round time less than 5 seconds is considered good, regardless of + /// recent history. + static constexpr std::chrono::seconds timeLeapCutoff{5}; + public: /// Constructor FeeMetrics(Setup const& setup, beast::Journal j) @@ -396,6 +411,7 @@ class TxQ : std::optional(std::nullopt)) , txnsExpected_(minimumTxnCount_) , recentTxnCounts_(setup.ledgersInQueue) + , recentRoundTimes_(setup.ledgersInQueue) , escalationMultiplier_(setup.minimumEscalationMultiplier) , j_(j) { @@ -407,15 +423,19 @@ class TxQ @param app Rippled Application object. @param view View of the LCL that was just closed or received. - @param timeLeap Indicates that rippled is under load so fees - should grow faster. + @param roundTime Time it took for the current consensus round to + complete. If unseated, indicates "unusual" processing, such as + startup or re-syncing. @param setup Customization params. + + @return bool indicating whether the round time was unusually high, + i.e. a "time leap". */ - std::size_t + [[nodiscard]] bool update( Application& app, ReadView const& view, - bool timeLeap, + std::optional const& roundTime, TxQ::Setup const& setup); /// Snapshot of the externally relevant FeeMetrics diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index fd975f9178d..21140e17a16 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -61,11 +61,11 @@ increase(FeeLevel64 level, std::uint32_t increasePercent) ////////////////////////////////////////////////////////////////////////// -std::size_t +bool TxQ::FeeMetrics::update( Application& app, ReadView const& view, - bool timeLeap, + std::optional const& roundTime, TxQ::Setup const& setup) { std::vector feeLevels; @@ -81,10 +81,27 @@ TxQ::FeeMetrics::update( size == feeLevels.size(), "ripple::TxQ::FeeMetrics::update : fee levels size"); + using namespace std::chrono; + + milliseconds const averageTime = recentRoundTimes_.empty() + ? 0ms + : milliseconds{ + std::accumulate( + recentRoundTimes_.begin(), recentRoundTimes_.end(), 0ms) / + recentRoundTimes_.size()}; + bool const timeLeap = !roundTime || + (roundTime > timeLeapCutoff && roundTime > averageTime * 2); + if (roundTime) + recentRoundTimes_.push_back(*roundTime); + JLOG((timeLeap ? j_.warn() : j_.debug())) << "Ledger " << view.info().seq << " has " << size << " transactions. " << "Ledgers are processing " << (timeLeap ? "slowly" : "as expected") - << ". Expected transactions is currently " << txnsExpected_ + << ". Current consensus round took " + << (roundTime ? to_string(roundTime->count()) + "ms" + : "INDETERMINATE TIME") + << " and recent average round time is " << averageTime.count() + << "ms. Expected transactions is currently " << txnsExpected_ << " and multiplier is " << escalationMultiplier_; if (timeLeap) @@ -147,7 +164,7 @@ TxQ::FeeMetrics::update( JLOG(j_.debug()) << "Expected transactions updated to " << txnsExpected_ << " and multiplier updated to " << escalationMultiplier_; - return size; + return timeLeap; } FeeLevel64 @@ -1342,11 +1359,14 @@ TxQ::apply( */ void -TxQ::processClosedLedger(Application& app, ReadView const& view, bool timeLeap) +TxQ::processClosedLedger( + Application& app, + ReadView const& view, + std::optional const& roundTime) { std::lock_guard lock(mutex_); - feeMetrics_.update(app, view, timeLeap, setup_); + bool const timeLeap = feeMetrics_.update(app, view, roundTime, setup_); auto const& snapshot = feeMetrics_.getSnapshot(); auto ledgerSeq = view.info().seq; From 97a93c3be0bbdf450d2b20292e5e902479ad0f0d Mon Sep 17 00:00:00 2001 From: Ed Hennis Date: Tue, 3 Oct 2023 12:36:42 -0400 Subject: [PATCH 2/6] [FOLD] Make the unhealthy factor a constexpr param, set to 3 --- src/test/app/TxQ_test.cpp | 12 ++++++------ src/xrpld/app/misc/TxQ.h | 1 + src/xrpld/app/misc/detail/TxQ.cpp | 3 ++- 3 files changed, 9 insertions(+), 7 deletions(-) diff --git a/src/test/app/TxQ_test.cpp b/src/test/app/TxQ_test.cpp index 09200931c31..960fc6d1485 100644 --- a/src/test/app/TxQ_test.cpp +++ b/src/test/app/TxQ_test.cpp @@ -716,9 +716,9 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(charlie, daria)); - env.close(env.now() + 5s, 20001ms); + env.close(env.now() + 5s, 30001ms); env.fund(XRP(1000), noripple(edgar, felicia)); - env.close(env.now() + 5s, 30002ms); + env.close(env.now() + 5s, 60002ms); checkMetrics(*this, env, 0, std::nullopt, 0, 2); env(noop(bob)); @@ -837,7 +837,7 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(carol)); - env.close(env.now() + 5s, 20001ms); + env.close(env.now() + 5s, 30001ms); // Fill the ledger env(noop(alice)); @@ -4082,19 +4082,19 @@ class TxQPosNegFlows_test : public beast::unit_test::suite checkMetrics(*this, env, txCount, 56, 15, 14); // Close the ledger with a delay. - env.close(env.now() + 5s, 20001ms); + env.close(env.now() + 5s, 30001ms); txCount -= 8; checkMetrics(*this, env, txCount, 56, 8, 7); // Close the ledger with a delay. - env.close(env.now() + 5s, 30002ms); + env.close(env.now() + 5s, 60002ms); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); // From 28 expected back down to 3 in 3 "slow" ledgers. // Confirm the minimum sticks - env.close(env.now() + 5s, 60003ms); + env.close(env.now() + 5s, 150s); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); diff --git a/src/xrpld/app/misc/TxQ.h b/src/xrpld/app/misc/TxQ.h index 14bf8dc9c55..45f24a1b4d9 100644 --- a/src/xrpld/app/misc/TxQ.h +++ b/src/xrpld/app/misc/TxQ.h @@ -392,6 +392,7 @@ class TxQ /// Any round time less than 5 seconds is considered good, regardless of /// recent history. static constexpr std::chrono::seconds timeLeapCutoff{5}; + static constexpr std::uint32_t timeLeapFactor{3}; public: /// Constructor diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index 21140e17a16..55c61d559c4 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -90,7 +90,8 @@ TxQ::FeeMetrics::update( recentRoundTimes_.begin(), recentRoundTimes_.end(), 0ms) / recentRoundTimes_.size()}; bool const timeLeap = !roundTime || - (roundTime > timeLeapCutoff && roundTime > averageTime * 2); + (roundTime > timeLeapCutoff && + roundTime > averageTime * timeLeapFactor); if (roundTime) recentRoundTimes_.push_back(*roundTime); From c55848ce0f0d11b19a0997b455dfa362fe26c192 Mon Sep 17 00:00:00 2001 From: Ed Hennis Date: Wed, 2 Oct 2024 14:03:02 -0400 Subject: [PATCH 3/6] Include the current round time in the average round time computation --- src/xrpld/app/misc/detail/TxQ.cpp | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index 55c61d559c4..a582df88920 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -83,6 +83,8 @@ TxQ::FeeMetrics::update( using namespace std::chrono; + if (roundTime) + recentRoundTimes_.push_back(*roundTime); milliseconds const averageTime = recentRoundTimes_.empty() ? 0ms : milliseconds{ @@ -92,8 +94,6 @@ TxQ::FeeMetrics::update( bool const timeLeap = !roundTime || (roundTime > timeLeapCutoff && roundTime > averageTime * timeLeapFactor); - if (roundTime) - recentRoundTimes_.push_back(*roundTime); JLOG((timeLeap ? j_.warn() : j_.debug())) << "Ledger " << view.info().seq << " has " << size << " transactions. " From f8329f81a8a1a14e2437b4127e87b3d4251dab88 Mon Sep 17 00:00:00 2001 From: Ed Hennis Date: Fri, 29 Sep 2023 13:15:21 -0400 Subject: [PATCH 4/6] Determine TxQ network "health" by average consensus round time * Instead of a hard cutoff at 5s * Network is "unhealthy" if consensus round took more than 5s *AND* more than twice the recent average. --- src/test/app/TxQ_test.cpp | 12 ++++++------ src/xrpld/app/misc/TxQ.h | 1 - src/xrpld/app/misc/detail/TxQ.cpp | 7 +++---- 3 files changed, 9 insertions(+), 11 deletions(-) diff --git a/src/test/app/TxQ_test.cpp b/src/test/app/TxQ_test.cpp index 960fc6d1485..09200931c31 100644 --- a/src/test/app/TxQ_test.cpp +++ b/src/test/app/TxQ_test.cpp @@ -716,9 +716,9 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(charlie, daria)); - env.close(env.now() + 5s, 30001ms); + env.close(env.now() + 5s, 20001ms); env.fund(XRP(1000), noripple(edgar, felicia)); - env.close(env.now() + 5s, 60002ms); + env.close(env.now() + 5s, 30002ms); checkMetrics(*this, env, 0, std::nullopt, 0, 2); env(noop(bob)); @@ -837,7 +837,7 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(carol)); - env.close(env.now() + 5s, 30001ms); + env.close(env.now() + 5s, 20001ms); // Fill the ledger env(noop(alice)); @@ -4082,19 +4082,19 @@ class TxQPosNegFlows_test : public beast::unit_test::suite checkMetrics(*this, env, txCount, 56, 15, 14); // Close the ledger with a delay. - env.close(env.now() + 5s, 30001ms); + env.close(env.now() + 5s, 20001ms); txCount -= 8; checkMetrics(*this, env, txCount, 56, 8, 7); // Close the ledger with a delay. - env.close(env.now() + 5s, 60002ms); + env.close(env.now() + 5s, 30002ms); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); // From 28 expected back down to 3 in 3 "slow" ledgers. // Confirm the minimum sticks - env.close(env.now() + 5s, 150s); + env.close(env.now() + 5s, 60003ms); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); diff --git a/src/xrpld/app/misc/TxQ.h b/src/xrpld/app/misc/TxQ.h index 45f24a1b4d9..14bf8dc9c55 100644 --- a/src/xrpld/app/misc/TxQ.h +++ b/src/xrpld/app/misc/TxQ.h @@ -392,7 +392,6 @@ class TxQ /// Any round time less than 5 seconds is considered good, regardless of /// recent history. static constexpr std::chrono::seconds timeLeapCutoff{5}; - static constexpr std::uint32_t timeLeapFactor{3}; public: /// Constructor diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index a582df88920..21140e17a16 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -83,8 +83,6 @@ TxQ::FeeMetrics::update( using namespace std::chrono; - if (roundTime) - recentRoundTimes_.push_back(*roundTime); milliseconds const averageTime = recentRoundTimes_.empty() ? 0ms : milliseconds{ @@ -92,8 +90,9 @@ TxQ::FeeMetrics::update( recentRoundTimes_.begin(), recentRoundTimes_.end(), 0ms) / recentRoundTimes_.size()}; bool const timeLeap = !roundTime || - (roundTime > timeLeapCutoff && - roundTime > averageTime * timeLeapFactor); + (roundTime > timeLeapCutoff && roundTime > averageTime * 2); + if (roundTime) + recentRoundTimes_.push_back(*roundTime); JLOG((timeLeap ? j_.warn() : j_.debug())) << "Ledger " << view.info().seq << " has " << size << " transactions. " From 9d689accaa499e797334920220646aa38b01573f Mon Sep 17 00:00:00 2001 From: Ed Hennis Date: Tue, 3 Oct 2023 12:36:42 -0400 Subject: [PATCH 5/6] [FOLD] Make the unhealthy factor a constexpr param, set to 3 --- src/test/app/TxQ_test.cpp | 12 ++++++------ src/xrpld/app/misc/TxQ.h | 1 + src/xrpld/app/misc/detail/TxQ.cpp | 3 ++- 3 files changed, 9 insertions(+), 7 deletions(-) diff --git a/src/test/app/TxQ_test.cpp b/src/test/app/TxQ_test.cpp index 09200931c31..960fc6d1485 100644 --- a/src/test/app/TxQ_test.cpp +++ b/src/test/app/TxQ_test.cpp @@ -716,9 +716,9 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(charlie, daria)); - env.close(env.now() + 5s, 20001ms); + env.close(env.now() + 5s, 30001ms); env.fund(XRP(1000), noripple(edgar, felicia)); - env.close(env.now() + 5s, 30002ms); + env.close(env.now() + 5s, 60002ms); checkMetrics(*this, env, 0, std::nullopt, 0, 2); env(noop(bob)); @@ -837,7 +837,7 @@ class TxQPosNegFlows_test : public beast::unit_test::suite env.fund(XRP(1000), noripple(alice, bob)); env.close(env.now() + 5s, 10000ms); env.fund(XRP(1000), noripple(carol)); - env.close(env.now() + 5s, 20001ms); + env.close(env.now() + 5s, 30001ms); // Fill the ledger env(noop(alice)); @@ -4082,19 +4082,19 @@ class TxQPosNegFlows_test : public beast::unit_test::suite checkMetrics(*this, env, txCount, 56, 15, 14); // Close the ledger with a delay. - env.close(env.now() + 5s, 20001ms); + env.close(env.now() + 5s, 30001ms); txCount -= 8; checkMetrics(*this, env, txCount, 56, 8, 7); // Close the ledger with a delay. - env.close(env.now() + 5s, 30002ms); + env.close(env.now() + 5s, 60002ms); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); // From 28 expected back down to 3 in 3 "slow" ledgers. // Confirm the minimum sticks - env.close(env.now() + 5s, 60003ms); + env.close(env.now() + 5s, 150s); txCount -= 4; checkMetrics(*this, env, txCount, 56, 4, 3); diff --git a/src/xrpld/app/misc/TxQ.h b/src/xrpld/app/misc/TxQ.h index 14bf8dc9c55..45f24a1b4d9 100644 --- a/src/xrpld/app/misc/TxQ.h +++ b/src/xrpld/app/misc/TxQ.h @@ -392,6 +392,7 @@ class TxQ /// Any round time less than 5 seconds is considered good, regardless of /// recent history. static constexpr std::chrono::seconds timeLeapCutoff{5}; + static constexpr std::uint32_t timeLeapFactor{3}; public: /// Constructor diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index 21140e17a16..55c61d559c4 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -90,7 +90,8 @@ TxQ::FeeMetrics::update( recentRoundTimes_.begin(), recentRoundTimes_.end(), 0ms) / recentRoundTimes_.size()}; bool const timeLeap = !roundTime || - (roundTime > timeLeapCutoff && roundTime > averageTime * 2); + (roundTime > timeLeapCutoff && + roundTime > averageTime * timeLeapFactor); if (roundTime) recentRoundTimes_.push_back(*roundTime); From 1a5dbd8318c71052a690c4fd83fa8aff79e217b0 Mon Sep 17 00:00:00 2001 From: Ed Hennis Date: Wed, 28 Jan 2026 20:25:10 -0500 Subject: [PATCH 6/6] Fix formatting --- src/xrpld/app/misc/detail/TxQ.cpp | 22 +++++++--------------- 1 file changed, 7 insertions(+), 15 deletions(-) diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index b72d46682a9..4750578e4d6 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -81,25 +81,17 @@ TxQ::FeeMetrics::update( milliseconds const averageTime = recentRoundTimes_.empty() ? 0ms : milliseconds{ - std::accumulate( - recentRoundTimes_.begin(), recentRoundTimes_.end(), 0ms) / - recentRoundTimes_.size()}; - bool const timeLeap = !roundTime || - (roundTime > timeLeapCutoff && - roundTime > averageTime * timeLeapFactor); + std::accumulate(recentRoundTimes_.begin(), recentRoundTimes_.end(), 0ms) / recentRoundTimes_.size()}; + bool const timeLeap = !roundTime || (roundTime > timeLeapCutoff && roundTime > averageTime * timeLeapFactor); if (roundTime) recentRoundTimes_.push_back(*roundTime); JLOG((timeLeap ? j_.warn() : j_.debug())) - << "Ledger " << view.header().seq << " has " << size - << " transactions. " - << "Ledgers are processing " << (timeLeap ? "slowly" : "as expected") - << ". Current consensus round took " - << (roundTime ? to_string(roundTime->count()) + "ms" - : "INDETERMINATE TIME") - << " and recent average round time is " << averageTime.count() - << "ms. Expected transactions is currently " << txnsExpected_ - << " and multiplier is " << escalationMultiplier_; + << "Ledger " << view.header().seq << " has " << size << " transactions. " + << "Ledgers are processing " << (timeLeap ? "slowly" : "as expected") << ". Current consensus round took " + << (roundTime ? to_string(roundTime->count()) + "ms" : "INDETERMINATE TIME") + << " and recent average round time is " << averageTime.count() << "ms. Expected transactions is currently " + << txnsExpected_ << " and multiplier is " << escalationMultiplier_; if (timeLeap) {