From 6bae42ff01b82911a7fd4b64984530eeb48cedea Mon Sep 17 00:00:00 2001 From: Nicholas Dudfield Date: Wed, 25 Feb 2026 11:53:27 +0700 Subject: [PATCH] fix: restore CLOG consensus logging removed during merge The merge with origin/dev accidentally stripped all CLOG diagnostic statements from the consensus code path. This restores the clog parameter to internal Consensus.h functions (checkLedger, phaseOpen, closeLedger, updateOurPositions, handleWrongLedger, leaveConsensus, createDisputes) and re-adds all 46 CLOG statements that provide per-round diagnostic detail for phase transitions, convergence progress, dispute tracking, and pause decisions. Also restores the origin/dev structure of Consensus.cpp by removing the anonymous-namespace wrapper and forwarding overloads that were merge artifacts. --- src/xrpld/app/consensus/RCLConsensus.cpp | 5 +- src/xrpld/consensus/Consensus.cpp | 58 +---- src/xrpld/consensus/Consensus.h | 272 +++++++++++++++++------ 3 files changed, 203 insertions(+), 132 deletions(-) diff --git a/src/xrpld/app/consensus/RCLConsensus.cpp b/src/xrpld/app/consensus/RCLConsensus.cpp index 17cb8fc0a..dd88f2904 100644 --- a/src/xrpld/app/consensus/RCLConsensus.cpp +++ b/src/xrpld/app/consensus/RCLConsensus.cpp @@ -1067,7 +1067,10 @@ RCLConsensus::timerEntry( catch (SHAMapMissingNode const& mn) { // This should never happen - JLOG(j_.error()) << "During consensus timerEntry: " << mn.what(); + std::stringstream ss; + ss << "During consensus timerEntry: " << mn.what(); + JLOG(j_.error()) << ss.str(); + CLOG(clog) << ss.str(); Rethrow(); } } diff --git a/src/xrpld/consensus/Consensus.cpp b/src/xrpld/consensus/Consensus.cpp index 887240fc6..3720062fd 100644 --- a/src/xrpld/consensus/Consensus.cpp +++ b/src/xrpld/consensus/Consensus.cpp @@ -22,10 +22,8 @@ namespace ripple { -namespace { - bool -shouldCloseLedgerImpl( +shouldCloseLedger( bool anyTransactions, std::size_t prevProposers, std::size_t proposersClosed, @@ -240,58 +238,4 @@ checkConsensus( return ConsensusState::No; } -} // namespace - -bool -shouldCloseLedger( - bool anyTransactions, - std::size_t prevProposers, - std::size_t proposersClosed, - std::size_t proposersValidated, - std::chrono::milliseconds prevRoundTime, - std::chrono::milliseconds timeSincePrevClose, - std::chrono::milliseconds openTime, - std::chrono::milliseconds idleInterval, - ConsensusParms const& parms, - beast::Journal j) -{ - return shouldCloseLedgerImpl( - anyTransactions, - prevProposers, - proposersClosed, - proposersValidated, - prevRoundTime, - timeSincePrevClose, - openTime, - idleInterval, - parms, - j, - nullptr); -} - -ConsensusState -checkConsensus( - std::size_t prevProposers, - std::size_t currentProposers, - std::size_t currentAgree, - std::size_t currentFinished, - std::chrono::milliseconds previousAgreeTime, - std::chrono::milliseconds currentAgreeTime, - ConsensusParms const& parms, - bool proposing, - beast::Journal j) -{ - return checkConsensus( - prevProposers, - currentProposers, - currentAgree, - currentFinished, - previousAgreeTime, - currentAgreeTime, - parms, - proposing, - j, - nullptr); -} - } // namespace ripple diff --git a/src/xrpld/consensus/Consensus.h b/src/xrpld/consensus/Consensus.h index 7c17ea04b..a108e0cae 100644 --- a/src/xrpld/consensus/Consensus.h +++ b/src/xrpld/consensus/Consensus.h @@ -31,6 +31,8 @@ #include #include #include + +#include #include #include #include @@ -81,6 +83,7 @@ enum class EstablishState { @param idleInterval the network's desired idle interval @param parms Consensus constant parameters @param j journal for logging + @param clog log object to which to append */ bool shouldCloseLedger( @@ -93,7 +96,8 @@ shouldCloseLedger( std::chrono::milliseconds openTime, std::chrono::milliseconds idleInterval, ConsensusParms const& parms, - beast::Journal j); + beast::Journal j, + std::unique_ptr const& clog = {}); /** Determine whether the network reached consensus and whether we joined. @@ -108,6 +112,7 @@ shouldCloseLedger( @param parms Consensus constant parameters @param proposing whether we should count ourselves @param j journal for logging + @param clog log object to which to append */ ConsensusState checkConsensus( @@ -119,7 +124,8 @@ checkConsensus( std::chrono::milliseconds currentAgreeTime, ConsensusParms const& parms, bool proposing, - beast::Journal j); + beast::Journal j, + std::unique_ptr const& clog = {}); /** Generic implementation of consensus algorithm. @@ -367,11 +373,13 @@ public: Called by the client code to start each round of consensus. - @param now The network adjusted time + @param now The network adjusted time @param prevLedgerID the ID of the last ledger - @param prevLedger The last ledger + @param prevLedger The last ledger @param nowUntrusted ID of nodes that are newly untrusted this round - @param proposing Whether we want to send proposals to peers this round. + @param proposing Whether we want to send proposals to peers this + round. + @param clog log object to which to append @note @b prevLedgerID is not required to the ID of @b prevLedger since the ID may be known locally before the contents of the ledger arrive @@ -398,7 +406,8 @@ public: /** Call periodically to drive consensus forward. - @param now The network adjusted time + @param now The network adjusted time + @param clog log object to which to append */ void timerEntry( @@ -481,11 +490,14 @@ private: NetClock::time_point const& now, typename Ledger_t::ID const& prevLedgerID, Ledger_t const& prevLedger, - ConsensusMode mode); + ConsensusMode mode, + std::unique_ptr const& clog); // Change our view of the previous ledger void - handleWrongLedger(typename Ledger_t::ID const& lgrId); + handleWrongLedger( + typename Ledger_t::ID const& lgrId, + std::unique_ptr const& clog); /** Check if our previous ledger matches the network's. @@ -493,7 +505,7 @@ private: the network and need to bow out/switch modes. */ void - checkLedger(); + checkLedger(std::unique_ptr const& clog); /** If we radically changed our consensus context for some reason, we need to replay recent proposals so that they're not lost. @@ -515,7 +527,7 @@ private: switch to the establish phase and start the consensus process. */ void - phaseOpen(); + phaseOpen(std::unique_ptr const& clog); /** Handle establish phase. @@ -526,7 +538,7 @@ private: If we have consensus, move to the accepted phase. */ void - phaseEstablish(std::unique_ptr const& clog = {}); + phaseEstablish(std::unique_ptr const& clog); /** Evaluate whether pausing increases likelihood of validation. * @@ -551,22 +563,24 @@ private: * @return Whether to pause to wait for lagging proposers. */ bool - shouldPause(std::unique_ptr const& clog = {}) const; + shouldPause(std::unique_ptr const& clog) const; // Close the open ledger and establish initial position. void - closeLedger(); + closeLedger(std::unique_ptr const& clog); // Adjust our positions to try to agree with other validators. void - updateOurPositions(); + updateOurPositions(std::unique_ptr const& clog); bool - haveConsensus(std::unique_ptr const& clog = {}); + haveConsensus(std::unique_ptr const& clog); // Create disputes between our position and the provided one. void - createDisputes(TxSet_t const& o); + createDisputes( + TxSet_t const& o, + std::unique_ptr const& clog = {}); // Update our disputes given that this node has adopted a new position. // Will call createDisputes as needed. @@ -576,7 +590,7 @@ private: // Revoke our outstanding proposal, if any, and cease proposing // until this round ends. void - leaveConsensus(); + leaveConsensus(std::unique_ptr const& clog); // The rounded or effective close time estimate from a proposer NetClock::time_point @@ -703,9 +717,7 @@ Consensus::startRound( } } - startRoundInternal(now, prevLedgerID, prevLedger, startMode); - if (clog) - timerEntry(now_, clog); + startRoundInternal(now, prevLedgerID, prevLedger, startMode, clog); } template void @@ -713,10 +725,14 @@ Consensus::startRoundInternal( NetClock::time_point const& now, typename Ledger_t::ID const& prevLedgerID, Ledger_t const& prevLedger, - ConsensusMode mode) + ConsensusMode mode, + std::unique_ptr const& clog) { phase_ = ConsensusPhase::open; - JLOG(j_.debug()) << "transitioned to ConsensusPhase::open"; + JLOG(j_.debug()) << "transitioned to ConsensusPhase::open "; + CLOG(clog) << "startRoundInternal transitioned to ConsensusPhase::open, " + "previous ledgerID: " + << prevLedgerID << ", seq: " << prevLedger.seq() << ". "; mode_.set(mode, adaptor_); now_ = now; prevLedgerID_ = prevLedgerID; @@ -765,11 +781,14 @@ Consensus::startRoundInternal( previousLedger_.seq() + typename Ledger_t::Seq{1}); playbackProposals(); + CLOG(clog) << "number of peer proposals,previous proposers: " + << currPeerPositions_.size() << ',' << prevProposers_ << ". "; if (currPeerPositions_.size() > (prevProposers_ / 2)) { // We may be falling behind, don't wait for the timer // consider closing the ledger immediately - timerEntry(now_); + CLOG(clog) << "consider closing the ledger immediately. "; + timerEntry(now_, clog); } } @@ -779,6 +798,7 @@ Consensus::peerProposal( NetClock::time_point const& now, PeerPosition_t const& newPeerPos) { + JLOG(j_.debug()) << "PROPOSAL " << newPeerPos.render(); auto const& peerID = newPeerPos.proposal().nodeID(); // Always need to store recent positions @@ -946,23 +966,31 @@ Consensus::timerEntry( NetClock::time_point const& now, std::unique_ptr const& clog) { + CLOG(clog) << "Consensus::timerEntry. "; // Nothing to do if we are currently working on a ledger if (phase_ == ConsensusPhase::accepted) + { + CLOG(clog) << "Nothing to do during accepted phase. "; return; + } now_ = now; + CLOG(clog) << "Set network adjusted time to " << to_string(now) << ". "; // Check we are on the proper ledger (this may change phase_) - checkLedger(); + const auto phaseOrig = phase_; + CLOG(clog) << "Phase " << to_string(phaseOrig) << ". "; + checkLedger(clog); + if (phaseOrig != phase_) + { + CLOG(clog) << "Changed phase to << " << to_string(phase_) << ". "; + } if (phase_ == ConsensusPhase::open) - { - phaseOpen(); - } + phaseOpen(clog); else if (phase_ == ConsensusPhase::establish) - { phaseEstablish(clog); - } + CLOG(clog) << "timerEntry finishing in phase " << to_string(phase_) << ". "; } template @@ -1020,7 +1048,7 @@ Consensus::simulate( using namespace std::chrono_literals; JLOG(j_.info()) << "Simulating consensus"; now_ = now; - closeLedger(); + closeLedger({}); result_->roundTime.tick(consensusDelay.value_or(1ms)); result_->proposers = prevProposers_ = currPeerPositions_.size(); prevRoundTime_ = result_->roundTime.read(); @@ -1135,12 +1163,15 @@ Consensus::getJson(bool full) const // Handle a change in the prior ledger during a consensus round template void -Consensus::handleWrongLedger(typename Ledger_t::ID const& lgrId) +Consensus::handleWrongLedger( + typename Ledger_t::ID const& lgrId, + std::unique_ptr const& clog) { + CLOG(clog) << "handleWrongLedger. "; assert(lgrId != prevLedgerID_ || previousLedger_.id() != lgrId); // Stop proposing because we are out of sync - leaveConsensus(); + leaveConsensus(clog); // First time switching to this ledger if (prevLedgerID_ != lgrId) @@ -1163,42 +1194,58 @@ Consensus::handleWrongLedger(typename Ledger_t::ID const& lgrId) } if (previousLedger_.id() == prevLedgerID_) + { + CLOG(clog) << "previousLedger_.id() == prevLeverID_ " << prevLedgerID_ + << ". "; return; + } // we need to switch the ledger we're working from if (auto newLedger = adaptor_.acquireLedger(prevLedgerID_)) { JLOG(j_.info()) << "Have the consensus ledger " << prevLedgerID_; + CLOG(clog) << "Have the consensus ledger " << prevLedgerID_ << ". "; startRoundInternal( - now_, lgrId, *newLedger, ConsensusMode::switchedLedger); + now_, lgrId, *newLedger, ConsensusMode::switchedLedger, clog); } else { + CLOG(clog) << "Still on wrong ledger. "; mode_.set(ConsensusMode::wrongLedger, adaptor_); } } template void -Consensus::checkLedger() +Consensus::checkLedger(std::unique_ptr const& clog) { + CLOG(clog) << "checkLedger. "; + auto netLgr = adaptor_.getPrevLedger(prevLedgerID_, previousLedger_, mode_.get()); + CLOG(clog) << "network ledgerid " << netLgr << ", " << "previous ledger " + << prevLedgerID_ << ". "; if (netLgr != prevLedgerID_) { - JLOG(j_.warn()) << "View of consensus changed during " - << to_string(phase_) << " status=" << to_string(phase_) - << ", " - << " mode=" << to_string(mode_.get()); - JLOG(j_.warn()) << prevLedgerID_ << " to " << netLgr; - JLOG(j_.warn()) << Json::Compact{previousLedger_.getJson()}; - JLOG(j_.debug()) << "State on consensus change " - << Json::Compact{getJson(true)}; - handleWrongLedger(netLgr); + std::stringstream ss; + ss << "View of consensus changed during " << to_string(phase_) + << " mode=" << to_string(mode_.get()) << ", " << prevLedgerID_ + << " to " << netLgr << ", " + << Json::Compact{previousLedger_.getJson()} << ". "; + JLOG(j_.warn()) << ss.str(); + CLOG(clog) << ss.str(); + CLOG(clog) << "State on consensus change " + << Json::Compact{getJson(true)} << ". "; + handleWrongLedger(netLgr, clog); } else if (previousLedger_.id() != prevLedgerID_) - handleWrongLedger(netLgr); + { + CLOG(clog) << "previousLedger_.id() != prevLedgerID_: " + << previousLedger_.id() << ',' << to_string(prevLedgerID_) + << ". "; + handleWrongLedger(netLgr, clog); + } } template @@ -1220,8 +1267,9 @@ Consensus::playbackProposals() template void -Consensus::phaseOpen() +Consensus::phaseOpen(std::unique_ptr const& clog) { + CLOG(clog) << "phaseOpen. "; using namespace std::chrono; // it is shortly before ledger close time @@ -1234,25 +1282,44 @@ Consensus::phaseOpen() // This computes how long since last ledger's close time milliseconds sinceClose; { - bool previousCloseCorrect = - (mode_.get() != ConsensusMode::wrongLedger) && - previousLedger_.closeAgree() && - (previousLedger_.closeTime() != - (previousLedger_.parentCloseTime() + 1s)); + auto const mode = mode_.get(); + bool const closeAgree = previousLedger_.closeAgree(); + auto const prevCloseTime = previousLedger_.closeTime(); + auto const prevParentCloseTimePlus1 = + previousLedger_.parentCloseTime() + 1s; + bool const previousCloseCorrect = + (mode != ConsensusMode::wrongLedger) && closeAgree && + (prevCloseTime != prevParentCloseTimePlus1); - auto lastCloseTime = previousCloseCorrect - ? previousLedger_.closeTime() // use consensus timing - : prevCloseTime_; // use the time we saw internally + auto const lastCloseTime = previousCloseCorrect + ? prevCloseTime // use consensus timing + : prevCloseTime_; // use the time we saw internally if (now_ >= lastCloseTime) sinceClose = duration_cast(now_ - lastCloseTime); else sinceClose = -duration_cast(lastCloseTime - now_); + CLOG(clog) << "calculating how long since last ledger's close time " + "based on mode : " + << to_string(mode) << ", previous closeAgree: " << closeAgree + << ", previous close time: " << to_string(prevCloseTime) + << ", previous parent close time + 1s: " + << to_string(prevParentCloseTimePlus1) + << ", previous close time seen internally: " + << to_string(prevCloseTime_) + << ", last close time: " << to_string(lastCloseTime) + << ", since close: " << sinceClose.count() << ". "; } auto const idleInterval = std::max( adaptor_.parms().ledgerIDLE_INTERVAL, 2 * previousLedger_.closeTimeResolution()); + CLOG(clog) << "idle interval set to " << idleInterval.count() + << "ms based on " + << "ledgerIDLE_INTERVAL: " + << adaptor_.parms().ledgerIDLE_INTERVAL.count() + << ", previous ledger close time resolution: " + << previousLedger_.closeTimeResolution().count() << "ms. "; // Decide if we should close the ledger if (shouldCloseLedger( @@ -1265,9 +1332,11 @@ Consensus::phaseOpen() openTime_.read(), idleInterval, adaptor_.parms(), - j_)) + j_, + clog)) { - closeLedger(); + CLOG(clog) << "closing ledger. "; + closeLedger(clog); } } @@ -1276,6 +1345,7 @@ bool Consensus::shouldPause( std::unique_ptr const& clog) const { + CLOG(clog) << "shouldPause? "; auto const& parms = adaptor_.parms(); std::uint32_t const ahead( previousLedger_.seq() - @@ -1287,7 +1357,7 @@ Consensus::shouldPause( std::size_t const offline = trustedKeys.size(); std::stringstream vars; - vars << " (working seq: " << previousLedger_.seq() << ", " + vars << " consensuslog (working seq: " << previousLedger_.seq() << ", " << "validated seq: " << adaptor_.getValidLedgerIndex() << ", " << "am validator: " << adaptor_.validator() << ", " << "have validated: " << adaptor_.haveValidated() << ", " @@ -1303,6 +1373,7 @@ Consensus::shouldPause( result_->roundTime.read() > parms.ledgerMAX_CONSENSUS) { j_.debug() << "not pausing (early)" << vars.str(); + CLOG(clog) << "Not pausing (early). "; return false; } @@ -1380,9 +1451,15 @@ Consensus::shouldPause( } if (willPause) + { j_.warn() << "pausing" << vars.str(); + CLOG(clog) << "pausing " << vars.str() << ". "; + } else + { j_.debug() << "not pausing" << vars.str(); + CLOG(clog) << "not pausing. "; + } return willPause; } @@ -1391,6 +1468,7 @@ void Consensus::phaseEstablish( std::unique_ptr const& clog) { + CLOG(clog) << "phaseEstablish. "; // can only establish consensus if we already took a stance assert(result_); @@ -1402,12 +1480,23 @@ Consensus::phaseEstablish( convergePercent_ = result_->roundTime.read() * 100 / std::max(prevRoundTime_, parms.avMIN_CONSENSUS_TIME); + CLOG(clog) << "convergePercent_ " << convergePercent_ + << " is based on round duration so far: " + << result_->roundTime.read().count() << "ms, " + << "previous round duration: " << prevRoundTime_.count() + << "ms, " + << "avMIN_CONSENSUS_TIME: " << parms.avMIN_CONSENSUS_TIME.count() + << "ms. "; // Give everyone a chance to take an initial position if (result_->roundTime.read() < parms.ledgerMIN_CONSENSUS) + { + CLOG(clog) << "ledgerMIN_CONSENSUS not reached: " + << parms.ledgerMIN_CONSENSUS.count() << "ms. "; return; + } - updateOurPositions(); + updateOurPositions(clog); // Nothing to do if too many laggards or we don't have consensus. if (shouldPause(clog) || !haveConsensus(clog)) @@ -1416,6 +1505,7 @@ Consensus::phaseEstablish( if (!haveCloseTimeConsensus_) { JLOG(j_.info()) << "We have TX consensus but not CT consensus"; + CLOG(clog) << "We have TX consensus but not CT consensus. "; return; } @@ -1575,7 +1665,7 @@ Consensus::phaseEstablish( bool timeout = elapsed > parms.rngREVEAL_TIMEOUT; bool ready = false; - if ((haveConsensus() && adaptor_.hasMinimumReveals()) || timeout) + if ((haveConsensus(clog) && adaptor_.hasMinimumReveals()) || timeout) { if (timeout && !adaptor_.hasAnyReveals()) { @@ -1605,6 +1695,8 @@ Consensus::phaseEstablish( JLOG(j_.info()) << "Converge cutoff (" << currPeerPositions_.size() << " participants)"; + CLOG(clog) << "Converge cutoff (" << currPeerPositions_.size() + << " participants). Transitioned to ConsensusPhase::accepted. "; adaptor_.updateOperatingMode(currPeerPositions_.size()); prevProposers_ = currPeerPositions_.size(); prevRoundTime_ = result_->roundTime.read(); @@ -1622,7 +1714,7 @@ Consensus::phaseEstablish( template void -Consensus::closeLedger() +Consensus::closeLedger(std::unique_ptr const& clog) { // We should not be closing if we already have a position assert(!result_); @@ -1639,7 +1731,12 @@ Consensus::closeLedger() if (acquired_.emplace(result_->txns.id(), result_->txns).second) adaptor_.share(result_->txns); - if (mode_.get() == ConsensusMode::proposing) + const auto mode = mode_.get(); + CLOG(clog) + << "closeLedger transitioned to ConsensusPhase::establish, mode: " + << to_string(mode) + << ", number of peer positions: " << currPeerPositions_.size() << ". "; + if (mode == ConsensusMode::proposing) adaptor_.propose(result_->position); // Create disputes with any peer positions we have transactions for @@ -1648,9 +1745,7 @@ Consensus::closeLedger() auto const& pos = pit.second.proposal().position(); auto const it = acquired_.find(pos); if (it != acquired_.end()) - { - createDisputes(it->second); - } + createDisputes(it->second, clog); } } @@ -1676,7 +1771,8 @@ participantsNeeded(int participants, int percent) template void -Consensus::updateOurPositions() +Consensus::updateOurPositions( + std::unique_ptr const& clog) { // We must have a position if we are updating it assert(result_); @@ -1685,6 +1781,8 @@ Consensus::updateOurPositions() // Compute a cutoff time auto const peerCutoff = now_ - parms.proposeFRESHNESS; auto const ourCutoff = now_ - parms.proposeINTERVAL; + CLOG(clog) << "updateOurPositions. peerCutoff " << to_string(peerCutoff) + << ", ourCutoff " << to_string(ourCutoff) << ". "; // Verify freshness of peer positions and compute close times std::map closeTimeVotes; @@ -1767,6 +1865,7 @@ Consensus::updateOurPositions() neededWeight = parms.avLATE_CONSENSUS_PCT; else neededWeight = parms.avSTUCK_CONSENSUS_PCT; + CLOG(clog) << "neededWeight " << neededWeight << ". "; int participants = currPeerPositions_.size(); if (mode_.get() == ConsensusMode::proposing) @@ -1782,9 +1881,12 @@ Consensus::updateOurPositions() int const threshConsensus = participantsNeeded(participants, parms.avCT_CONSENSUS_PCT); - JLOG(j_.info()) << "Proposers:" << currPeerPositions_.size() - << " nw:" << neededWeight << " thrV:" << threshVote - << " thrC:" << threshConsensus; + std::stringstream ss; + ss << "Proposers:" << currPeerPositions_.size() + << " nw:" << neededWeight << " thrV:" << threshVote + << " thrC:" << threshConsensus; + JLOG(j_.info()) << ss.str(); + CLOG(clog) << ss.str(); for (auto const& [t, v] : closeTimeVotes) { @@ -1813,6 +1915,7 @@ Consensus::updateOurPositions() << " Mode:" << to_string(mode_.get()) << " Thresh:" << threshConsensus << " Pos:" << consensusCloseTime.time_since_epoch().count(); + CLOG(clog) << "No close time consensus. "; } } @@ -1830,9 +1933,11 @@ Consensus::updateOurPositions() result_->txns = std::move(*ourNewSet); - JLOG(j_.info()) << "Position change: CTime " - << consensusCloseTime.time_since_epoch().count() - << ", tx " << newID; + std::stringstream ss; + ss << "Position change: CTime " + << consensusCloseTime.time_since_epoch().count() << ", tx " << newID; + JLOG(j_.info()) << ss.str(); + CLOG(clog) << ss.str(); // Preserve sidecar data (RNG fields), only update txSetHash // Use type traits to conditionally handle ExtendedPosition vs simple ID @@ -1915,10 +2020,14 @@ Consensus::haveConsensus( result_->roundTime.read(), adaptor_.parms(), mode_.get() == ConsensusMode::proposing, - j_); + j_, + clog); if (result_->state == ConsensusState::No) + { + CLOG(clog) << "No consensus. "; return false; + } // There is consensus, but we need to track if the network moved on // without us. @@ -1926,14 +2035,18 @@ Consensus::haveConsensus( { JLOG(j_.error()) << "Unable to reach consensus"; JLOG(j_.error()) << Json::Compact{getJson(true)}; + CLOG(clog) << "Unable to reach consensus " + << Json::Compact{getJson(true)} << ". "; } + CLOG(clog) << "Consensus has been reached. "; return true; } template void -Consensus::leaveConsensus() +Consensus::leaveConsensus( + std::unique_ptr const& clog) { if (mode_.get() == ConsensusMode::proposing) { @@ -1945,24 +2058,34 @@ Consensus::leaveConsensus() mode_.set(ConsensusMode::observing, adaptor_); JLOG(j_.info()) << "Bowing out of consensus"; + CLOG(clog) << "Bowing out of consensus. "; } } template void -Consensus::createDisputes(TxSet_t const& o) +Consensus::createDisputes( + TxSet_t const& o, + std::unique_ptr const& clog) { // Cannot create disputes without our stance assert(result_); // Only create disputes if this is a new set - if (!result_->compares.emplace(o.id()).second) + auto const emplaced = result_->compares.emplace(o.id()).second; + CLOG(clog) << "createDisputes: new set? " << !emplaced << ". "; + if (!emplaced) return; // Nothing to dispute if we agree if (result_->txns.id() == o.id()) + { + CLOG(clog) << "both sets are identical. "; return; + } + CLOG(clog) << "comparing existing with new set: " << result_->txns.id() + << ',' << o.id() << ". "; JLOG(j_.debug()) << "createDisputes " << result_->txns.id() << " to " << o.id(); @@ -2005,6 +2128,7 @@ Consensus::createDisputes(TxSet_t const& o) result_->disputes.emplace(txID, std::move(dtx)); } JLOG(j_.debug()) << dc << " differences found"; + CLOG(clog) << "disputes: " << dc << ". "; } template