diff --git a/src/test/app/TxQ_test.cpp b/src/test/app/TxQ_test.cpp index 13feceb74ea..c598b10392a 100644 --- a/src/test/app/TxQ_test.cpp +++ b/src/test/app/TxQ_test.cpp @@ -679,9 +679,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, 30001ms); env.fund(XRP(1000), noripple(edgar, felicia)); - env.close(env.now() + 5s, 10000ms); + env.close(env.now() + 5s, 60002ms); checkMetrics(*this, env, 0, std::nullopt, 0, 2); env(noop(bob)); @@ -796,7 +796,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, 30001ms); // Fill the ledger env(noop(alice)); @@ -3636,19 +3636,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, 30001ms); 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, 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, 10000ms); + env.close(env.now() + 5s, 150s); 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 35f8eec1a3f..0f588095a76 100644 --- a/src/xrpld/app/consensus/RCLConsensus.cpp +++ b/src/xrpld/app/consensus/RCLConsensus.cpp @@ -670,7 +670,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 7da26ada405..5eb114abfdb 100644 --- a/src/xrpld/app/misc/NetworkOPs.cpp +++ b/src/xrpld/app/misc/NetworkOPs.cpp @@ -1799,7 +1799,7 @@ NetworkOPsImp::switchLastClosedLedger(std::shared_ptr const& newLC 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 004cd085fce..1497220928e 100644 --- a/src/xrpld/app/misc/TxQ.h +++ b/src/xrpld/app/misc/TxQ.h @@ -279,9 +279,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 @@ -363,12 +372,19 @@ 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}; + static constexpr std::uint32_t timeLeapFactor{3}; + public: /// Constructor FeeMetrics(Setup const& setup, beast::Journal j) @@ -380,6 +396,7 @@ class TxQ : std::optional(std::nullopt)) , txnsExpected_(minimumTxnCount_) , recentTxnCounts_(setup.ledgersInQueue) + , recentRoundTimes_(setup.ledgersInQueue) , escalationMultiplier_(setup.minimumEscalationMultiplier) , j_(j) { @@ -391,12 +408,20 @@ 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 - update(Application& app, ReadView const& view, bool timeLeap, TxQ::Setup const& setup); + [[nodiscard]] bool + update( + Application& app, + ReadView const& view, + std::optional const& roundTime, + TxQ::Setup const& setup); /// Snapshot of the externally relevant FeeMetrics /// fields at any given time. diff --git a/src/xrpld/app/misc/detail/TxQ.cpp b/src/xrpld/app/misc/detail/TxQ.cpp index 61741b73f0a..4750578e4d6 100644 --- a/src/xrpld/app/misc/detail/TxQ.cpp +++ b/src/xrpld/app/misc/detail/TxQ.cpp @@ -60,8 +60,12 @@ increase(FeeLevel64 level, std::uint32_t increasePercent) ////////////////////////////////////////////////////////////////////////// -std::size_t -TxQ::FeeMetrics::update(Application& app, ReadView const& view, bool timeLeap, TxQ::Setup const& setup) +bool +TxQ::FeeMetrics::update( + Application& app, + ReadView const& view, + std::optional const& roundTime, + TxQ::Setup const& setup) { std::vector feeLevels; auto const txBegin = view.txs.begin(); @@ -72,9 +76,21 @@ TxQ::FeeMetrics::update(Application& app, ReadView const& view, bool timeLeap, T std::sort(feeLevels.begin(), feeLevels.end()); XRPL_ASSERT(size == feeLevels.size(), "xrpl::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 * 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") << ". Expected transactions is currently " + << "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) @@ -129,7 +145,7 @@ TxQ::FeeMetrics::update(Application& app, ReadView const& view, bool timeLeap, T JLOG(j_.debug()) << "Expected transactions updated to " << txnsExpected_ << " and multiplier updated to " << escalationMultiplier_; - return size; + return timeLeap; } FeeLevel64 @@ -1233,11 +1249,14 @@ TxQ::apply(Application& app, OpenView& view, std::shared_ptr const& */ 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.header().seq;