diff --git a/src/herder/HerderImpl.cpp b/src/herder/HerderImpl.cpp index 475dedff35..e126ddb715 100644 --- a/src/herder/HerderImpl.cpp +++ b/src/herder/HerderImpl.cpp @@ -1485,7 +1485,7 @@ HerderImpl::dumpInfo(Json::Value& ret, size_t limit) mSCP.dumpInfo(ret, limit); - mPendingEnvelopes.dumpInfo(ret); + mPendingEnvelopes.dumpInfo(ret, limit); } void @@ -1665,6 +1665,12 @@ void HerderImpl::herderOutOfSync() { CLOG(INFO, "Herder") << "Lost track of consensus"; + + Json::Value v; + dumpInfo(v, 20); + std::string s = v.toStyledString(); + CLOG(INFO, "Herder") << "Out of sync context: " << s; + mSCPMetrics.mLostSync.Mark(); stateChanged(); diff --git a/src/herder/PendingEnvelopes.cpp b/src/herder/PendingEnvelopes.cpp index e27af589da..100e895825 100755 --- a/src/herder/PendingEnvelopes.cpp +++ b/src/herder/PendingEnvelopes.cpp @@ -286,22 +286,41 @@ PendingEnvelopes::getQSet(Hash const& hash) } void -PendingEnvelopes::dumpInfo(Json::Value& ret) +PendingEnvelopes::dumpInfo(Json::Value& ret, size_t limit) { - /* TODO.1 - int count = 0; - for(auto& entry : mFetching) + Json::Value& q = ret["queue"]; + { - for(auto& fRecord : entry.second) + auto it = mFetchingEnvelopes.rbegin(); + size_t l = limit; + while (it != mFetchingEnvelopes.rend() && l-- != 0) { - auto & envelope = fRecord->env; - ostringstream output; - output << "i:" << entry.first - << " n:" << binToHex(envelope->nodeID).substr(0, 6); - - ret["pending"][count++] = output.str(); + if (it->second.size() != 0) + { + Json::Value& slot = q[std::to_string(it->first)]["fetching"]; + for (auto const& e : it->second) + { + slot.append(mHerder.getSCP().envToStr(e)); + } + } + it++; + } + } + { + auto it = mPendingEnvelopes.rbegin(); + size_t l = limit; + while (it != mPendingEnvelopes.rend() && l-- != 0) + { + if (it->second.size() != 0) + { + Json::Value& slot = q[std::to_string(it->first)]["pending"]; + for (auto const& e : it->second) + { + slot.append(mHerder.getSCP().envToStr(e)); + } + } + it++; } } - */ -} } +} \ No newline at end of file diff --git a/src/herder/PendingEnvelopes.h b/src/herder/PendingEnvelopes.h index bbabbbabe1..21953c6fdf 100755 --- a/src/herder/PendingEnvelopes.h +++ b/src/herder/PendingEnvelopes.h @@ -70,7 +70,7 @@ class PendingEnvelopes std::vector readySlots(); - void dumpInfo(Json::Value& ret); + void dumpInfo(Json::Value& ret, size_t limit); TxSetFramePtr getTxSet(Hash const& hash); SCPQuorumSetPtr getQSet(Hash const& hash); diff --git a/src/main/Config.cpp b/src/main/Config.cpp index 1a5d53a1c3..675f11c9a8 100644 --- a/src/main/Config.cpp +++ b/src/main/Config.cpp @@ -628,7 +628,8 @@ Config::validateConfig() } // calculates nodes that would break quorum - auto r = LocalNode::findClosestVBlocking(QUORUM_SET, nodes); + auto selfID = NODE_SEED.getPublicKey(); + auto r = LocalNode::findClosestVBlocking(QUORUM_SET, nodes, &selfID); if (FAILURE_SAFETY == -1) { diff --git a/src/scp/BallotProtocol.cpp b/src/scp/BallotProtocol.cpp index 825418bcae..2620d0dbdf 100644 --- a/src/scp/BallotProtocol.cpp +++ b/src/scp/BallotProtocol.cpp @@ -352,7 +352,7 @@ BallotProtocol::bumpState(Value const& value, uint32 n) CLOG(DEBUG, "SCP") << "BallotProtocol::bumpState" << " i: " << mSlot.getSlotIndex() - << " v: " << mSlot.ballotToStr(newb); + << " v: " << mSlot.getSCP().ballotToStr(newb); bool updated = updateCurrentValue(newb); @@ -429,7 +429,7 @@ BallotProtocol::bumpToBallot(SCPBallot const& ballot, bool check) { CLOG(DEBUG, "SCP") << "BallotProtocol::bumpToBallot" << " i: " << mSlot.getSlotIndex() - << " b: " << mSlot.ballotToStr(ballot); + << " b: " << mSlot.getSCP().ballotToStr(ballot); // `bumpToBallot` should be never called once we committed. dbgAssert(mPhase != SCP_PHASE_EXTERNALIZE); @@ -835,7 +835,7 @@ BallotProtocol::setPreparedAccept(SCPBallot const& ballot) { CLOG(DEBUG, "SCP") << "BallotProtocol::setPreparedAccept" << " i: " << mSlot.getSlotIndex() - << " b: " << mSlot.ballotToStr(ballot); + << " b: " << mSlot.getSCP().ballotToStr(ballot); // update our state bool didWork = setPrepared(ballot); @@ -982,7 +982,7 @@ BallotProtocol::setPreparedConfirmed(SCPBallot const& newC, { CLOG(DEBUG, "SCP") << "BallotProtocol::setPreparedConfirmed" << " i: " << mSlot.getSlotIndex() - << " h: " << mSlot.ballotToStr(newH); + << " h: " << mSlot.getSCP().ballotToStr(newH); bool didWork = false; @@ -1231,8 +1231,8 @@ BallotProtocol::setAcceptCommit(SCPBallot const& c, SCPBallot const& h) { CLOG(DEBUG, "SCP") << "BallotProtocol::setAcceptCommit" << " i: " << mSlot.getSlotIndex() - << " new c: " << mSlot.ballotToStr(c) - << " new h: " << mSlot.ballotToStr(h); + << " new c: " << mSlot.getSCP().ballotToStr(c) + << " new h: " << mSlot.getSCP().ballotToStr(h); bool didWork = false; @@ -1437,8 +1437,8 @@ BallotProtocol::setConfirmCommit(SCPBallot const& c, SCPBallot const& h) { CLOG(DEBUG, "SCP") << "BallotProtocol::setConfirmCommit" << " i: " << mSlot.getSlotIndex() - << " new c: " << mSlot.ballotToStr(c) - << " new h: " << mSlot.ballotToStr(h); + << " new c: " << mSlot.getSCP().ballotToStr(c) + << " new h: " << mSlot.getSCP().ballotToStr(h); mCommit = make_unique(c); mHighBallot = make_unique(h); @@ -1911,7 +1911,7 @@ BallotProtocol::dumpInfo(Json::Value& ret) { Json::Value state; state["heard"] = mHeardFromQuorum; - state["ballot"] = mSlot.ballotToStr(mCurrentBallot); + state["ballot"] = mSlot.getSCP().ballotToStr(mCurrentBallot); state["phase"] = phaseNames[mPhase]; state["state"] = getLocalState(); @@ -2000,10 +2000,12 @@ BallotProtocol::dumpQuorumInfo(Json::Value& ret, NodeID const& id, bool summary) } auto f = LocalNode::findClosestVBlocking( - *qSet, mLatestEnvelopes, [&](SCPStatement const& st) + *qSet, mLatestEnvelopes, + [&](SCPStatement const& st) { return areBallotsCompatible(getWorkingBallot(st), b); - }); + }, + &id); ret["fail_at"] = static_cast(f.size()); if (!summary) @@ -2027,11 +2029,11 @@ BallotProtocol::getLocalState() const std::ostringstream oss; oss << "i: " << mSlot.getSlotIndex() << " | " << phaseNames[mPhase] - << " | b: " << mSlot.ballotToStr(mCurrentBallot) - << " | p: " << mSlot.ballotToStr(mPrepared) - << " | p': " << mSlot.ballotToStr(mPreparedPrime) - << " | h: " << mSlot.ballotToStr(mHighBallot) - << " | c: " << mSlot.ballotToStr(mCommit) + << " | b: " << mSlot.getSCP().ballotToStr(mCurrentBallot) + << " | p: " << mSlot.getSCP().ballotToStr(mPrepared) + << " | p': " << mSlot.getSCP().ballotToStr(mPreparedPrime) + << " | h: " << mSlot.getSCP().ballotToStr(mHighBallot) + << " | c: " << mSlot.getSCP().ballotToStr(mCommit) << " | M: " << mLatestEnvelopes.size(); return oss.str(); } diff --git a/src/scp/LocalNode.cpp b/src/scp/LocalNode.cpp index 7bb633e371..ddba2ff044 100755 --- a/src/scp/LocalNode.cpp +++ b/src/scp/LocalNode.cpp @@ -414,7 +414,8 @@ LocalNode::isQuorum( std::vector LocalNode::findClosestVBlocking( SCPQuorumSet const& qset, std::map const& map, - std::function const& filter) + std::function const& filter, + NodeID const* excluded) { std::set s; for (auto const& n : map) @@ -424,12 +425,13 @@ LocalNode::findClosestVBlocking( s.emplace(n.first); } } - return findClosestVBlocking(qset, s); + return findClosestVBlocking(qset, s, excluded); } std::vector LocalNode::findClosestVBlocking(SCPQuorumSet const& qset, - std::set const& nodes) + std::set const& nodes, + NodeID const* excluded) { size_t leftTillBlock = ((1 + qset.validators.size() + qset.innerSets.size()) - qset.threshold); @@ -439,20 +441,23 @@ LocalNode::findClosestVBlocking(SCPQuorumSet const& qset, // first, compute how many top level items need to be blocked for (auto const& validator : qset.validators) { - auto it = nodes.find(validator); - if (it == nodes.end()) + if (!excluded || !(validator == *excluded)) { - leftTillBlock--; - if (leftTillBlock == 0) + auto it = nodes.find(validator); + if (it == nodes.end()) { - // already blocked - return std::vector(); + leftTillBlock--; + if (leftTillBlock == 0) + { + // already blocked + return std::vector(); + } + } + else + { + // save this for later + res.emplace_back(validator); } - } - else - { - // save this for later - res.emplace_back(validator); } } @@ -469,7 +474,7 @@ LocalNode::findClosestVBlocking(SCPQuorumSet const& qset, for (auto const& inner : qset.innerSets) { - auto v = findClosestVBlocking(inner, nodes); + auto v = findClosestVBlocking(inner, nodes, excluded); if (v.size() == 0) { leftTillBlock--; diff --git a/src/scp/LocalNode.h b/src/scp/LocalNode.h index 2a7bdbf004..7e59e96804 100644 --- a/src/scp/LocalNode.h +++ b/src/scp/LocalNode.h @@ -103,17 +103,21 @@ class LocalNode return true; }); - // computes the distance to the set of v-blocking sets given a set of nodes + // computes the distance to the set of v-blocking sets given + // a set of nodes that agree (but can fail) + // excluded, if set will be skipped altogether static std::vector findClosestVBlocking(SCPQuorumSet const& qset, - std::set const& nodes); + std::set const& nodes, NodeID const* excluded); + static std::vector findClosestVBlocking( SCPQuorumSet const& qset, std::map const& map, std::function const& filter = [](SCPStatement const&) { return true; - }); + }, + NodeID const* excluded = nullptr); void toJson(SCPQuorumSet const& qSet, Json::Value& value) const; std::string to_string(SCPQuorumSet const& qSet) const; diff --git a/src/scp/NominationProtocol.cpp b/src/scp/NominationProtocol.cpp index 63f0cd0e9d..b874215899 100644 --- a/src/scp/NominationProtocol.cpp +++ b/src/scp/NominationProtocol.cpp @@ -442,7 +442,7 @@ NominationProtocol::nominate(Value const& value, Value const& previousValue, bool timedout) { CLOG(DEBUG, "SCP") << "NominationProtocol::nominate " - << mSlot.getValueString(value); + << mSlot.getSCP().getValueString(value); bool updated = false; @@ -530,31 +530,21 @@ NominationProtocol::dumpInfo(Json::Value& ret) int counter = 0; for (auto const& v : mVotes) { - nomState["X"][counter] = mSlot.getValueString(v); + nomState["X"][counter] = mSlot.getSCP().getValueString(v); counter++; } counter = 0; for (auto const& v : mAccepted) { - nomState["Y"][counter] = mSlot.getValueString(v); + nomState["Y"][counter] = mSlot.getSCP().getValueString(v); counter++; } counter = 0; for (auto const& v : mCandidates) { - nomState["Z"][counter] = mSlot.getValueString(v); - counter++; - } - - counter = 0; - for (auto const& v : mLatestNominations) - { - nomState["N"][counter]["id"] = - mSlot.getSCPDriver().toShortString(v.first); - nomState["N"][counter]["statement"] = mSlot.envToStr(v.second); - + nomState["Z"][counter] = mSlot.getSCP().getValueString(v); counter++; } diff --git a/src/scp/SCP.cpp b/src/scp/SCP.cpp index 9ec5fac8f1..6d4112e749 100644 --- a/src/scp/SCP.cpp +++ b/src/scp/SCP.cpp @@ -237,4 +237,103 @@ SCP::getExternalizingState(uint64 slotIndex) return std::vector(); } } + +std::string +SCP::getValueString(Value const& v) const +{ + return mDriver.getValueString(v); +} + +std::string +SCP::ballotToStr(SCPBallot const& ballot) const +{ + std::ostringstream oss; + + oss << "(" << ballot.counter << "," << getValueString(ballot.value) << ")"; + return oss.str(); +} + +std::string +SCP::ballotToStr(std::unique_ptr const& ballot) const +{ + std::string res; + if (ballot) + { + res = ballotToStr(*ballot); + } + else + { + res = "()"; + } + return res; +} + +std::string +SCP::envToStr(SCPEnvelope const& envelope) const +{ + return envToStr(envelope.statement); +} + +std::string +SCP::envToStr(SCPStatement const& st) const +{ + std::ostringstream oss; + + Hash const& qSetHash = Slot::getCompanionQuorumSetHashFromStatement(st); + + oss << "{ENV@" << mDriver.toShortString(st.nodeID) << " | " + << " i: " << st.slotIndex; + switch (st.pledges.type()) + { + case SCPStatementType::SCP_ST_PREPARE: + { + auto const& p = st.pledges.prepare(); + oss << " | PREPARE" + << " | D: " << hexAbbrev(qSetHash) + << " | b: " << ballotToStr(p.ballot) + << " | p: " << ballotToStr(p.prepared) + << " | p': " << ballotToStr(p.preparedPrime) << " | c.n: " << p.nC + << " | h.n: " << p.nH; + } + break; + case SCPStatementType::SCP_ST_CONFIRM: + { + auto const& c = st.pledges.confirm(); + oss << " | CONFIRM" + << " | D: " << hexAbbrev(qSetHash) + << " | b: " << ballotToStr(c.ballot) << " | p.n: " << c.nPrepared + << " | c.n: " << c.nCommit << " | h.n: " << c.nH; + } + break; + case SCPStatementType::SCP_ST_EXTERNALIZE: + { + auto const& ex = st.pledges.externalize(); + oss << " | EXTERNALIZE" + << " | c: " << ballotToStr(ex.commit) << " | h.n: " << ex.nH + << " | (lastD): " << hexAbbrev(qSetHash); + } + break; + case SCPStatementType::SCP_ST_NOMINATE: + { + auto const& nom = st.pledges.nominate(); + oss << " | NOMINATE" + << " | D: " << hexAbbrev(qSetHash) << " | X: {"; + for (auto const& v : nom.votes) + { + oss << " '" << getValueString(v) << "',"; + } + oss << "}" + << " | Y: {"; + for (auto const& a : nom.accepted) + { + oss << " '" << getValueString(a) << "',"; + } + oss << "}"; + } + break; + } + + oss << " }"; + return oss.str(); +} } diff --git a/src/scp/SCP.h b/src/scp/SCP.h index 9affb03c62..793e77e54f 100644 --- a/src/scp/SCP.h +++ b/src/scp/SCP.h @@ -110,6 +110,13 @@ class SCP // (or empty if the slot didn't externalize) std::vector getExternalizingState(uint64 slotIndex); + // ** helper methods to stringify ballot for logging + std::string getValueString(Value const& v) const; + std::string ballotToStr(SCPBallot const& ballot) const; + std::string ballotToStr(std::unique_ptr const& ballot) const; + std::string envToStr(SCPEnvelope const& envelope) const; + std::string envToStr(SCPStatement const& st) const; + protected: std::shared_ptr mLocalNode; std::map> mKnownSlots; diff --git a/src/scp/SCPTests.cpp b/src/scp/SCPTests.cpp index cb247a3c75..7331fd0beb 100644 --- a/src/scp/SCPTests.cpp +++ b/src/scp/SCPTests.cpp @@ -509,7 +509,7 @@ TEST_CASE("v-blocking distance", "[scp]") auto check = [&](SCPQuorumSet const& qSetCheck, std::set const& s, int expected) { - auto r = LocalNode::findClosestVBlocking(qSetCheck, s); + auto r = LocalNode::findClosestVBlocking(qSetCheck, s, nullptr); REQUIRE(expected == r.size()); }; diff --git a/src/scp/Slot.cpp b/src/scp/Slot.cpp index 9f06cab8ff..9267af1123 100644 --- a/src/scp/Slot.cpp +++ b/src/scp/Slot.cpp @@ -75,7 +75,8 @@ Slot::setStateFromEnvelope(SCPEnvelope const& e) else { CLOG(DEBUG, "SCP") << "Slot::setStateFromEnvelope invalid envelope" - << " i: " << getSlotIndex() << " " << envToStr(e); + << " i: " << getSlotIndex() << " " + << mSCP.envToStr(e); } } @@ -107,7 +108,8 @@ Slot::processEnvelope(SCPEnvelope const& envelope, bool self) dbgAssert(envelope.statement.slotIndex == mSlotIndex); CLOG(DEBUG, "SCP") << "Slot::processEnvelope" - << " i: " << getSlotIndex() << " " << envToStr(envelope); + << " i: " << getSlotIndex() << " " + << mSCP.envToStr(envelope); SCP::EnvelopeState res; @@ -132,7 +134,8 @@ Slot::processEnvelope(SCPEnvelope const& envelope, bool self) CLOG(ERROR, "SCP") << "Exception in processEnvelope " << "state: " << info.toStyledString() - << " processing envelope: " << envToStr(envelope); + << " processing envelope: " + << mSCP.envToStr(envelope); throw; } @@ -277,7 +280,7 @@ Slot::dumpInfo(Json::Value& ret) for (auto const& item : mStatementsHistory) { Json::Value& v = slotValue["statements"][count++]; - v.append(envToStr(item.first)); + v.append(mSCP.envToStr(item.first)); v.append(item.second); Hash const& qSetHash = @@ -305,105 +308,6 @@ Slot::dumpQuorumInfo(Json::Value& ret, NodeID const& id, bool summary) mBallotProtocol.dumpQuorumInfo(ret[i], id, summary); } -std::string -Slot::getValueString(Value const& v) const -{ - return getSCPDriver().getValueString(v); -} - -std::string -Slot::ballotToStr(SCPBallot const& ballot) const -{ - std::ostringstream oss; - - oss << "(" << ballot.counter << "," << getValueString(ballot.value) << ")"; - return oss.str(); -} - -std::string -Slot::ballotToStr(std::unique_ptr const& ballot) const -{ - std::string res; - if (ballot) - { - res = ballotToStr(*ballot); - } - else - { - res = "()"; - } - return res; -} - -std::string -Slot::envToStr(SCPEnvelope const& envelope) const -{ - return envToStr(envelope.statement); -} - -std::string -Slot::envToStr(SCPStatement const& st) const -{ - std::ostringstream oss; - - Hash const& qSetHash = getCompanionQuorumSetHashFromStatement(st); - - oss << "{ENV@" << getSCPDriver().toShortString(st.nodeID) << " | " - << " i: " << st.slotIndex; - switch (st.pledges.type()) - { - case SCPStatementType::SCP_ST_PREPARE: - { - auto const& p = st.pledges.prepare(); - oss << " | PREPARE" - << " | D: " << hexAbbrev(qSetHash) - << " | b: " << ballotToStr(p.ballot) - << " | p: " << ballotToStr(p.prepared) - << " | p': " << ballotToStr(p.preparedPrime) << " | c.n: " << p.nC - << " | h.n: " << p.nH; - } - break; - case SCPStatementType::SCP_ST_CONFIRM: - { - auto const& c = st.pledges.confirm(); - oss << " | CONFIRM" - << " | D: " << hexAbbrev(qSetHash) - << " | b: " << ballotToStr(c.ballot) << " | p.n: " << c.nPrepared - << " | c.n: " << c.nCommit << " | h.n: " << c.nH; - } - break; - case SCPStatementType::SCP_ST_EXTERNALIZE: - { - auto const& ex = st.pledges.externalize(); - oss << " | EXTERNALIZE" - << " | c: " << ballotToStr(ex.commit) << " | h.n: " << ex.nH - << " | (lastD): " << hexAbbrev(qSetHash); - } - break; - case SCPStatementType::SCP_ST_NOMINATE: - { - auto const& nom = st.pledges.nominate(); - oss << " | NOMINATE" - << " | D: " << hexAbbrev(qSetHash) << " | X: {"; - for (auto const& v : nom.votes) - { - oss << " '" << getValueString(v) << "',"; - } - oss << "}" - << " | Y: {"; - for (auto const& a : nom.accepted) - { - oss << " '" << getValueString(a) << "',"; - } - oss << "}"; - } - break; - } - - oss << " }"; - return oss.str(); -} - bool Slot::federatedAccept(StatementPredicate voted, StatementPredicate accepted, std::map const& envs) diff --git a/src/scp/Slot.h b/src/scp/Slot.h index 17e4d28301..211270d355 100644 --- a/src/scp/Slot.h +++ b/src/scp/Slot.h @@ -144,13 +144,6 @@ class Slot : public std::enable_shared_from_this // wraps a statement in an envelope (sign it, etc) SCPEnvelope createEnvelope(SCPStatement const& statement); - // ** helper methods to stringify ballot for logging - std::string getValueString(Value const& v) const; - std::string ballotToStr(SCPBallot const& ballot) const; - std::string ballotToStr(std::unique_ptr const& ballot) const; - std::string envToStr(SCPEnvelope const& envelope) const; - std::string envToStr(SCPStatement const& st) const; - // ** federated agreement helper functions // returns true if the statement defined by voted and accepted