Better logging of built/validated discrepancies:

If we built a different ledger from the one we ultimately
validate, log the status of the consensus round. This will
make it easier to rule out transaction processing issues
as the cause of these discrepancies and generally make them
easier to diagnose.
This commit is contained in:
JoelKatz
2015-11-02 06:35:58 -08:00
committed by Nik Bougalis
parent 0458d1910e
commit 269008b311
5 changed files with 40 additions and 33 deletions

View File

@@ -301,7 +301,7 @@ leaves (SHAMap const& sm)
void LedgerHistory::handleMismatch (
LedgerHash const& built, LedgerHash const& valid)
LedgerHash const& built, LedgerHash const& valid, Json::Value const& consensus)
{
assert (built != valid);
++mismatch_counter_;
@@ -319,6 +319,13 @@ void LedgerHistory::handleMismatch (
assert (builtLedger->info().seq == validLedger->info().seq);
if (j_.debug)
{
j_.debug << "Built: " << getJson (*builtLedger);
j_.debug << "Valid: " << getJson (*validLedger);
j_.debug << "Consensus: " << consensus;
}
// Determine the mismatch reason
// Distinguish Byzantine failure from transaction processing difference
@@ -384,7 +391,7 @@ void LedgerHistory::handleMismatch (
log_one (validLedger, (*v)->key(), "built", j_);
}
void LedgerHistory::builtLedger (Ledger::ref ledger)
void LedgerHistory::builtLedger (Ledger::ref ledger, Json::Value consensus)
{
LedgerIndex index = ledger->info().seq;
LedgerHash hash = ledger->getHash();
@@ -392,20 +399,18 @@ void LedgerHistory::builtLedger (Ledger::ref ledger)
ConsensusValidated::ScopedLockType sl (
m_consensus_validated.peekMutex());
auto entry = std::make_shared<std::pair< LedgerHash, LedgerHash >>();
auto entry = std::make_shared<cv_entry>();
m_consensus_validated.canonicalize(index, entry, false);
if (entry->first != hash)
if (entry->validated && (entry->validated.get() != hash))
{
if (entry->second.isNonZero() && (entry->second != hash))
{
JLOG (j_.error) << "MISMATCH: seq=" << index
<< " validated:" << entry->second
<< " then:" << hash;
handleMismatch (hash, entry->first);
}
entry->first = hash;
JLOG (j_.error) << "MISMATCH: seq=" << index
<< " validated:" << entry->validated.get()
<< " then:" << hash;
handleMismatch (hash, entry->validated.get(), consensus);
}
entry->built.emplace (hash);
entry->consensus.emplace (std::move (consensus));
}
void LedgerHistory::validatedLedger (Ledger::ref ledger)
@@ -416,21 +421,18 @@ void LedgerHistory::validatedLedger (Ledger::ref ledger)
ConsensusValidated::ScopedLockType sl (
m_consensus_validated.peekMutex());
auto entry = std::make_shared<std::pair<LedgerHash, LedgerHash>>();
auto entry = std::make_shared<cv_entry>();
m_consensus_validated.canonicalize(index, entry, false);
if (entry->second != hash)
if (entry->built && (entry->built.get() != hash))
{
if (entry->first.isNonZero() && (entry->first != hash))
{
JLOG (j_.error) << "MISMATCH: seq=" << index
<< " built:" << entry->first
<< " then:" << hash;
handleMismatch (entry->first, hash);
}
entry->second = hash;
JLOG (j_.error) << "MISMATCH: seq=" << index
<< " built:" << entry->built.get()
<< " then:" << hash;
handleMismatch (entry->built.get(), hash, entry->consensus.get());
}
entry->validated.emplace (hash);
}
/** Ensure m_ledgers_by_hash doesn't have the wrong hash for a particular index

View File

@@ -83,7 +83,7 @@ public:
/** Report that we have locally built a particular ledger
*/
void builtLedger (Ledger::ref);
void builtLedger (Ledger::ref, Json::Value);
/** Report that we have validated a particular ledger
*/
@@ -104,8 +104,10 @@ private:
validate a different one.
@param built The hash of the ledger we built
@param valid The hash of the ledger we deemed fully valid
@param consensus The status of the consensus round
*/
void handleMismatch (LedgerHash const& built, LedgerHash const& valid);
void handleMismatch (LedgerHash const& built, LedgerHash const& valid,
Json::Value const& consensus);
Application& app_;
beast::insight::Collector::ptr collector_;
@@ -117,10 +119,13 @@ private:
// Maps ledger indexes to the corresponding hashes
// For debug and logging purposes
// 1) The hash of a ledger with that index we build
// 2) The hash of a ledger with that index we validated
using ConsensusValidated = TaggedCache <LedgerIndex,
std::pair< LedgerHash, LedgerHash >>;
struct cv_entry
{
boost::optional<LedgerHash> built;
boost::optional<LedgerHash> validated;
boost::optional<Json::Value> consensus;
};
using ConsensusValidated = TaggedCache <LedgerIndex, cv_entry>;
ConsensusValidated m_consensus_validated;

View File

@@ -153,7 +153,7 @@ public:
virtual void checkAccept (Ledger::ref ledger) = 0;
virtual void checkAccept (uint256 const& hash, std::uint32_t seq) = 0;
virtual void consensusBuilt (Ledger::ref ledger) = 0;
virtual void consensusBuilt (Ledger::ref ledger, Json::Value consensus) = 0;
virtual LedgerIndex getBuildingLedger () = 0;
virtual void setBuildingLedger (LedgerIndex index) = 0;

View File

@@ -1144,7 +1144,7 @@ void LedgerConsensusImp::accept (std::shared_ptr<SHAMap> set)
<< "CNF newLCL " << newLCLHash;
// See if we can accept a ledger as fully-validated
ledgerMaster_.consensusBuilt (newLCL);
ledgerMaster_.consensusBuilt (newLCL, getJson (true));
{
// Apply disputed transactions that didn't get in

View File

@@ -877,7 +877,7 @@ public:
}
/** Report that the consensus process built a particular ledger */
void consensusBuilt (Ledger::ref ledger) override
void consensusBuilt (Ledger::ref ledger, Json::Value consensus) override
{
// Because we just built a ledger, we are no longer building one
@@ -970,7 +970,7 @@ public:
checkAccept (maxLedger, maxSeq);
}
mLedgerHistory.builtLedger (ledger);
mLedgerHistory.builtLedger (ledger, std::move (consensus));
}
void advanceThread()