diff --git a/src/test/consensus/Consensus_test.cpp b/src/test/consensus/Consensus_test.cpp index db56ab58c6..7899336a6f 100644 --- a/src/test/consensus/Consensus_test.cpp +++ b/src/test/consensus/Consensus_test.cpp @@ -1136,6 +1136,10 @@ public: ConsensusParms p; std::size_t peersUnchanged = 0; + auto logs = std::make_unique(beast::severities::kError); + auto j = logs->journal("Test"); + auto clog = std::make_unique(); + // Three cases: // 1 proposing, initial vote yes // 2 proposing, initial vote no @@ -1172,10 +1176,15 @@ public: BEAST_EXPECT(proposingFalse.getOurVote() == false); BEAST_EXPECT(followingTrue.getOurVote() == true); BEAST_EXPECT(followingFalse.getOurVote() == false); - BEAST_EXPECT(!proposingTrue.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!proposingFalse.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!followingTrue.stalled(p, false, peersUnchanged)); - BEAST_EXPECT(!followingFalse.stalled(p, false, peersUnchanged)); + BEAST_EXPECT( + !proposingTrue.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !proposingFalse.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingTrue.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingFalse.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT(clog->str() == ""); // I'm in the majority, my vote should not change BEAST_EXPECT(!proposingTrue.updateVote(5, true, p)); @@ -1189,10 +1198,15 @@ public: BEAST_EXPECT(!followingFalse.updateVote(10, false, p)); peersUnchanged = 2; - BEAST_EXPECT(!proposingTrue.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!proposingFalse.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!followingTrue.stalled(p, false, peersUnchanged)); - BEAST_EXPECT(!followingFalse.stalled(p, false, peersUnchanged)); + BEAST_EXPECT( + !proposingTrue.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !proposingFalse.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingTrue.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingFalse.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT(clog->str() == ""); // Right now, the vote is 51%. The requirement is about to jump to // 65% @@ -1282,10 +1296,15 @@ public: BEAST_EXPECT(followingFalse.getOurVote() == false); peersUnchanged = 3; - BEAST_EXPECT(!proposingTrue.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!proposingFalse.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!followingTrue.stalled(p, false, peersUnchanged)); - BEAST_EXPECT(!followingFalse.stalled(p, false, peersUnchanged)); + BEAST_EXPECT( + !proposingTrue.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !proposingFalse.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingTrue.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingFalse.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT(clog->str() == ""); // Threshold jumps to 95% BEAST_EXPECT(proposingTrue.updateVote(220, true, p)); @@ -1322,12 +1341,60 @@ public: for (peersUnchanged = 0; peersUnchanged < 6; ++peersUnchanged) { - BEAST_EXPECT(!proposingTrue.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!proposingFalse.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(!followingTrue.stalled(p, false, peersUnchanged)); - BEAST_EXPECT(!followingFalse.stalled(p, false, peersUnchanged)); + BEAST_EXPECT( + !proposingTrue.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !proposingFalse.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingTrue.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT( + !followingFalse.stalled(p, false, peersUnchanged, j, clog)); + BEAST_EXPECT(clog->str() == ""); } + auto expectStalled = [this, &clog]( + int txid, + bool ourVote, + int ourTime, + int peerTime, + int support, + std::uint32_t line) { + using namespace std::string_literals; + + auto const s = clog->str(); + expect(s.find("stalled"), s, __FILE__, line); + expect( + s.starts_with("Transaction "s + std::to_string(txid)), + s, + __FILE__, + line); + expect( + s.find("voting "s + (ourVote ? "YES" : "NO")) != s.npos, + s, + __FILE__, + line); + expect( + s.find("for "s + std::to_string(ourTime) + " rounds."s) != + s.npos, + s, + __FILE__, + line); + expect( + s.find( + "votes in "s + std::to_string(peerTime) + " rounds.") != + s.npos, + s, + __FILE__, + line); + expect( + s.ends_with( + "has "s + std::to_string(support) + "% support. "s), + s, + __FILE__, + line); + clog = std::make_unique(); + }; + for (int i = 0; i < 1; ++i) { BEAST_EXPECT(!proposingTrue.updateVote(250 + 10 * i, true, p)); @@ -1342,22 +1409,34 @@ public: BEAST_EXPECT(followingFalse.getOurVote() == false); // true vote has changed recently, so not stalled - BEAST_EXPECT(!proposingTrue.stalled(p, true, 0)); + BEAST_EXPECT(!proposingTrue.stalled(p, true, 0, j, clog)); + BEAST_EXPECT(clog->str() == ""); // remaining votes have been unchanged in so long that we only // need to hit the second round at 95% to be stalled, regardless // of peers - BEAST_EXPECT(proposingFalse.stalled(p, true, 0)); - BEAST_EXPECT(followingTrue.stalled(p, false, 0)); - BEAST_EXPECT(followingFalse.stalled(p, false, 0)); + BEAST_EXPECT(proposingFalse.stalled(p, true, 0, j, clog)); + expectStalled(98, false, 11, 0, 2, __LINE__); + BEAST_EXPECT(followingTrue.stalled(p, false, 0, j, clog)); + expectStalled(97, true, 11, 0, 97, __LINE__); + BEAST_EXPECT(followingFalse.stalled(p, false, 0, j, clog)); + expectStalled(96, false, 11, 0, 3, __LINE__); // true vote has changed recently, so not stalled - BEAST_EXPECT(!proposingTrue.stalled(p, true, peersUnchanged)); + BEAST_EXPECT( + !proposingTrue.stalled(p, true, peersUnchanged, j, clog)); + BEAST_EXPECTS(clog->str() == "", clog->str()); // remaining votes have been unchanged in so long that we only // need to hit the second round at 95% to be stalled, regardless // of peers - BEAST_EXPECT(proposingFalse.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(followingTrue.stalled(p, false, peersUnchanged)); - BEAST_EXPECT(followingFalse.stalled(p, false, peersUnchanged)); + BEAST_EXPECT( + proposingFalse.stalled(p, true, peersUnchanged, j, clog)); + expectStalled(98, false, 11, 6, 2, __LINE__); + BEAST_EXPECT( + followingTrue.stalled(p, false, peersUnchanged, j, clog)); + expectStalled(97, true, 11, 6, 97, __LINE__); + BEAST_EXPECT( + followingFalse.stalled(p, false, peersUnchanged, j, clog)); + expectStalled(96, false, 11, 6, 3, __LINE__); } for (int i = 1; i < 3; ++i) { @@ -1374,19 +1453,31 @@ public: // true vote changed 2 rounds ago, and peers are changing, so // not stalled - BEAST_EXPECT(!proposingTrue.stalled(p, true, 0)); + BEAST_EXPECT(!proposingTrue.stalled(p, true, 0, j, clog)); + BEAST_EXPECTS(clog->str() == "", clog->str()); // still stalled - BEAST_EXPECT(proposingFalse.stalled(p, true, 0)); - BEAST_EXPECT(followingTrue.stalled(p, false, 0)); - BEAST_EXPECT(followingFalse.stalled(p, false, 0)); + BEAST_EXPECT(proposingFalse.stalled(p, true, 0, j, clog)); + expectStalled(98, false, 11 + i, 0, 2, __LINE__); + BEAST_EXPECT(followingTrue.stalled(p, false, 0, j, clog)); + expectStalled(97, true, 11 + i, 0, 97, __LINE__); + BEAST_EXPECT(followingFalse.stalled(p, false, 0, j, clog)); + expectStalled(96, false, 11 + i, 0, 3, __LINE__); // true vote changed 2 rounds ago, and peers are NOT changing, // so stalled - BEAST_EXPECT(proposingTrue.stalled(p, true, peersUnchanged)); + BEAST_EXPECT( + proposingTrue.stalled(p, true, peersUnchanged, j, clog)); + expectStalled(99, true, 1 + i, 6, 97, __LINE__); // still stalled - BEAST_EXPECT(proposingFalse.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(followingTrue.stalled(p, false, peersUnchanged)); - BEAST_EXPECT(followingFalse.stalled(p, false, peersUnchanged)); + BEAST_EXPECT( + proposingFalse.stalled(p, true, peersUnchanged, j, clog)); + expectStalled(98, false, 11 + i, 6, 2, __LINE__); + BEAST_EXPECT( + followingTrue.stalled(p, false, peersUnchanged, j, clog)); + expectStalled(97, true, 11 + i, 6, 97, __LINE__); + BEAST_EXPECT( + followingFalse.stalled(p, false, peersUnchanged, j, clog)); + expectStalled(96, false, 11 + i, 6, 3, __LINE__); } for (int i = 3; i < 5; ++i) { @@ -1401,15 +1492,27 @@ public: BEAST_EXPECT(followingTrue.getOurVote() == true); BEAST_EXPECT(followingFalse.getOurVote() == false); - BEAST_EXPECT(proposingTrue.stalled(p, true, 0)); - BEAST_EXPECT(proposingFalse.stalled(p, true, 0)); - BEAST_EXPECT(followingTrue.stalled(p, false, 0)); - BEAST_EXPECT(followingFalse.stalled(p, false, 0)); + BEAST_EXPECT(proposingTrue.stalled(p, true, 0, j, clog)); + expectStalled(99, true, 1 + i, 0, 97, __LINE__); + BEAST_EXPECT(proposingFalse.stalled(p, true, 0, j, clog)); + expectStalled(98, false, 11 + i, 0, 2, __LINE__); + BEAST_EXPECT(followingTrue.stalled(p, false, 0, j, clog)); + expectStalled(97, true, 11 + i, 0, 97, __LINE__); + BEAST_EXPECT(followingFalse.stalled(p, false, 0, j, clog)); + expectStalled(96, false, 11 + i, 0, 3, __LINE__); - BEAST_EXPECT(proposingTrue.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(proposingFalse.stalled(p, true, peersUnchanged)); - BEAST_EXPECT(followingTrue.stalled(p, false, peersUnchanged)); - BEAST_EXPECT(followingFalse.stalled(p, false, peersUnchanged)); + BEAST_EXPECT( + proposingTrue.stalled(p, true, peersUnchanged, j, clog)); + expectStalled(99, true, 1 + i, 6, 97, __LINE__); + BEAST_EXPECT( + proposingFalse.stalled(p, true, peersUnchanged, j, clog)); + expectStalled(98, false, 11 + i, 6, 2, __LINE__); + BEAST_EXPECT( + followingTrue.stalled(p, false, peersUnchanged, j, clog)); + expectStalled(97, true, 11 + i, 6, 97, __LINE__); + BEAST_EXPECT( + followingFalse.stalled(p, false, peersUnchanged, j, clog)); + expectStalled(96, false, 11 + i, 6, 3, __LINE__); } } } diff --git a/src/xrpld/app/consensus/RCLValidations.cpp b/src/xrpld/app/consensus/RCLValidations.cpp index a04047c78a..5305c95357 100644 --- a/src/xrpld/app/consensus/RCLValidations.cpp +++ b/src/xrpld/app/consensus/RCLValidations.cpp @@ -136,7 +136,7 @@ RCLValidationsAdaptor::acquire(LedgerHash const& hash) if (!ledger) { - JLOG(j_.debug()) + JLOG(j_.warn()) << "Need validated ledger for preferred ledger analysis " << hash; Application* pApp = &app_; diff --git a/src/xrpld/consensus/Consensus.cpp b/src/xrpld/consensus/Consensus.cpp index fb57687df0..d4edb1445c 100644 --- a/src/xrpld/consensus/Consensus.cpp +++ b/src/xrpld/consensus/Consensus.cpp @@ -139,11 +139,11 @@ checkConsensusReached( return false; } - // We only get stalled when every disputed transaction unequivocally has 80% - // (minConsensusPct) agreement, either for or against. That is: either under - // 20% or over 80% consensus (repectively "nay" or "yay"). This prevents - // manipulation by a minority of byzantine peers of which transactions make - // the cut to get into the ledger. + // We only get stalled when there are disputed transactions and all of them + // unequivocally have 80% (minConsensusPct) agreement, either for or + // against. That is: either under 20% or over 80% consensus (repectively + // "nay" or "yay"). This prevents manipulation by a minority of byzantine + // peers of which transactions make the cut to get into the ledger. if (stalled) { CLOG(clog) << "consensus stalled. "; diff --git a/src/xrpld/consensus/Consensus.h b/src/xrpld/consensus/Consensus.h index f3265cf381..df6cedccff 100644 --- a/src/xrpld/consensus/Consensus.h +++ b/src/xrpld/consensus/Consensus.h @@ -84,8 +84,8 @@ shouldCloseLedger( agree @param stalled the network appears to be stalled, where neither we nor our peers have changed their vote on any disputes in a - while. This is undesirable, and will cause us to end consensus - without 80% agreement. + while. This is undesirable, and should be rare, and will cause us to + end consensus without 80% agreement. @param parms Consensus constant parameters @param proposing whether we should count ourselves @param j journal for logging @@ -1712,15 +1712,29 @@ Consensus::haveConsensus( << ", disagree=" << disagree; ConsensusParms const& parms = adaptor_.parms(); - // Stalling is BAD + // Stalling is BAD. It means that we have a consensus on the close time, so + // peers are talking, but we have disputed transactions that peers are + // unable or unwilling to come to agreement on one way or the other. bool const stalled = haveCloseTimeConsensus_ && + !result_->disputes.empty() && std::ranges::all_of(result_->disputes, - [this, &parms](auto const& dispute) { + [this, &parms, &clog](auto const& dispute) { return dispute.second.stalled( parms, mode_.get() == ConsensusMode::proposing, - peerUnchangedCounter_); + peerUnchangedCounter_, + j_, + clog); }); + if (stalled) + { + std::stringstream ss; + ss << "Consensus detects as stalled with " << (agree + disagree) << "/" + << prevProposers_ << " proposers, and " << result_->disputes.size() + << " stalled disputed transactions."; + JLOG(j_.error()) << ss.str(); + CLOG(clog) << ss.str(); + } // Determine if we actually have consensus or not result_->state = checkConsensus( diff --git a/src/xrpld/consensus/DisputedTx.h b/src/xrpld/consensus/DisputedTx.h index 4ed31b77ca..e774c8366c 100644 --- a/src/xrpld/consensus/DisputedTx.h +++ b/src/xrpld/consensus/DisputedTx.h @@ -85,7 +85,12 @@ public: //! Are we and our peers "stalled" where we probably won't change //! our vote? bool - stalled(ConsensusParms const& p, bool proposing, int peersUnchanged) const + stalled( + ConsensusParms const& p, + bool proposing, + int peersUnchanged, + beast::Journal j, + std::unique_ptr const& clog) const { // at() can throw, but the map is built by hand to ensure all valid // values are available. @@ -123,8 +128,24 @@ public: int const weight = support / total; // Returns true if the tx has more than minCONSENSUS_PCT (80) percent // agreement. Either voting for _or_ voting against the tx. - return weight > p.minCONSENSUS_PCT || - weight < (100 - p.minCONSENSUS_PCT); + bool const stalled = + weight > p.minCONSENSUS_PCT || weight < (100 - p.minCONSENSUS_PCT); + + if (stalled) + { + // stalling is an error condition for even a single + // transaction. + std::stringstream s; + s << "Transaction " << ID() << " is stalled. We have been voting " + << (getOurVote() ? "YES" : "NO") << " for " << currentVoteCounter_ + << " rounds. Peers have not changed their votes in " + << peersUnchanged << " rounds. The transaction has " << weight + << "% support. "; + JLOG(j_.error()) << s.str(); + CLOG(clog) << s.str(); + } + + return stalled; } //! The disputed transaction.