Add logging for exceptions: (#4400)

Log exception messages at several locations.

Previously, these were locations where an exception was caught, but the
exception message was not logged. Logging the exception messages can be
useful for analysis or debugging. The additional logging could have a
small negative performance impact.

Fix #3213.
This commit is contained in:
drlongle
2023-03-30 19:13:30 +02:00
committed by GitHub
parent 135b63dbe0
commit 8bfdbcbab5
17 changed files with 99 additions and 52 deletions

View File

@@ -498,10 +498,11 @@ RCLConsensus::Adaptor::doAccept(
std::make_shared<STTx const>(SerialIter{item.slice()}));
JLOG(j_.debug()) << " Tx: " << item.key();
}
catch (std::exception const&)
catch (std::exception const& ex)
{
failed.insert(item.key());
JLOG(j_.warn()) << " Tx: " << item.key() << " throws!";
JLOG(j_.warn())
<< " Tx: " << item.key() << " throws: " << ex.what();
}
}
@@ -615,10 +616,11 @@ RCLConsensus::Adaptor::doAccept(
anyDisputes = true;
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(j_.debug())
<< "Failed to apply transaction we voted NO on";
JLOG(j_.debug()) << "Failed to apply transaction we voted "
"NO on. Exception: "
<< ex.what();
}
}
}

View File

@@ -66,9 +66,11 @@ ConsensusTransSetSF::gotNode(
pap->getOPs().submitTransaction(stx);
});
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(j_.warn()) << "Fetched invalid transaction in proposed set";
JLOG(j_.warn())
<< "Fetched invalid transaction in proposed set. Exception: "
<< ex.what();
}
}
}

View File

@@ -186,6 +186,7 @@ Ledger::Ledger(
, txMap_(std::make_shared<SHAMap>(SHAMapType::TRANSACTION, family))
, stateMap_(std::make_shared<SHAMap>(SHAMapType::STATE, family))
, rules_{config.features}
, j_(beast::Journal(beast::Journal::getNullSink()))
{
info_.seq = 1;
info_.drops = INITIAL_XRP;
@@ -255,6 +256,7 @@ Ledger::Ledger(
std::make_shared<SHAMap>(SHAMapType::STATE, info.accountHash, family))
, rules_(config.features)
, info_(info)
, j_(j)
{
loaded = true;
@@ -306,6 +308,7 @@ Ledger::Ledger(Ledger const& prevLedger, NetClock::time_point closeTime)
, stateMap_(prevLedger.stateMap_->snapShot(true))
, fees_(prevLedger.fees_)
, rules_(prevLedger.rules_)
, j_(beast::Journal(beast::Journal::getNullSink()))
{
info_.seq = prevLedger.info_.seq + 1;
info_.parentCloseTime = prevLedger.info_.closeTime;
@@ -339,6 +342,7 @@ Ledger::Ledger(LedgerInfo const& info, Config const& config, Family& family)
std::make_shared<SHAMap>(SHAMapType::STATE, info.accountHash, family))
, rules_{config.features}
, info_(info)
, j_(beast::Journal(beast::Journal::getNullSink()))
{
info_.hash = calculateLedgerHash(info_);
}
@@ -352,6 +356,7 @@ Ledger::Ledger(
, txMap_(std::make_shared<SHAMap>(SHAMapType::TRANSACTION, family))
, stateMap_(std::make_shared<SHAMap>(SHAMapType::STATE, family))
, rules_{config.features}
, j_(beast::Journal(beast::Journal::getNullSink()))
{
info_.seq = ledgerSeq;
info_.closeTime = closeTime;
@@ -626,8 +631,9 @@ Ledger::setup()
{
ret = false;
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(j_.error()) << "Exception in " << __func__ << ": " << ex.what();
Rethrow();
}
@@ -682,8 +688,9 @@ Ledger::setup()
{
ret = false;
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(j_.error()) << "Exception in " << __func__ << ": " << ex.what();
Rethrow();
}

View File

@@ -410,6 +410,7 @@ private:
Fees fees_;
Rules rules_;
LedgerInfo info_;
beast::Journal j_;
};
/** A ledger wrapped in a CachedView. */

View File

@@ -143,9 +143,10 @@ applyTransactions(
++it;
}
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(j.warn()) << "Transaction " << txid << " throws";
JLOG(j.warn())
<< "Transaction " << txid << " throws: " << ex.what();
failed.insert(txid);
it = txns.erase(it);
}

View File

@@ -866,10 +866,11 @@ LedgerMaster::fixMismatch(ReadView const& ledger)
{
hash = hashOfSeq(ledger, lSeq, m_journal);
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(m_journal.warn())
<< "fixMismatch encounters partial ledger";
<< "fixMismatch encounters partial ledger. Exception: "
<< ex.what();
clearLedger(lSeq);
return;
}
@@ -1407,10 +1408,11 @@ LedgerMaster::findNewLedgersToPublish(
JLOG(m_journal.trace())
<< "ready to publish " << ret.size() << " ledgers.";
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(m_journal.error())
<< "Exception while trying to find ledgers to publish.";
<< "Exception while trying to find ledgers to publish: "
<< ex.what();
}
if (app_.config().LEDGER_REPLAY)
@@ -2009,9 +2011,10 @@ LedgerMaster::fetchForHistory(
}
}
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(m_journal.warn()) << "Threw while prefetching";
JLOG(m_journal.warn())
<< "Threw while prefetching: " << ex.what();
}
}
}
@@ -2346,9 +2349,10 @@ LedgerMaster::makeFetchPack(
peer->send(msg);
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(m_journal.warn()) << "Exception building fetch pach";
JLOG(m_journal.warn())
<< "Exception building fetch pach. Exception: " << ex.what();
}
}

View File

@@ -192,9 +192,14 @@ fillJsonTx(Object& json, LedgerFill const& fill)
appendAll(fill.ledger.txs);
}
}
catch (std::exception const&)
catch (std::exception const& ex)
{
// Nothing the user can do about this.
if (fill.context)
{
JLOG(fill.context->j.error())
<< "Exception in " << __func__ << ": " << ex.what();
}
}
}

View File

@@ -206,9 +206,9 @@ debugTostr(SHAMap const& set)
auto const tx = std::make_shared<STTx const>(sit);
ss << debugTxstr(tx) << ", ";
}
catch (std::exception const&)
catch (std::exception const& ex)
{
ss << "THRO, ";
ss << "THROW:" << ex.what() << ", ";
}
}
return ss.str();

View File

@@ -138,12 +138,14 @@ to_string(Manifest const& m);
*/
/** @{ */
std::optional<Manifest>
deserializeManifest(Slice s);
deserializeManifest(Slice s, beast::Journal journal);
inline std::optional<Manifest>
deserializeManifest(std::string const& s)
deserializeManifest(
std::string const& s,
beast::Journal journal = beast::Journal(beast::Journal::getNullSink()))
{
return deserializeManifest(makeSlice(s));
return deserializeManifest(makeSlice(s), journal);
}
template <
@@ -151,9 +153,11 @@ template <
class = std::enable_if_t<
std::is_same<T, char>::value || std::is_same<T, unsigned char>::value>>
std::optional<Manifest>
deserializeManifest(std::vector<T> const& v)
deserializeManifest(
std::vector<T> const& v,
beast::Journal journal = beast::Journal(beast::Journal::getNullSink()))
{
return deserializeManifest(makeSlice(v));
return deserializeManifest(makeSlice(v), journal);
}
/** @} */
@@ -180,7 +184,9 @@ struct ValidatorToken
};
std::optional<ValidatorToken>
loadValidatorToken(std::vector<std::string> const& blob);
loadValidatorToken(
std::vector<std::string> const& blob,
beast::Journal journal = beast::Journal(beast::Journal::getNullSink()));
enum class ManifestDisposition {
/// Manifest is valid

View File

@@ -1162,9 +1162,10 @@ NetworkOPsImp::submitTransaction(std::shared_ptr<STTx const> const& iTrans)
return;
}
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(m_journal.warn()) << "Exception checking transaction" << txid;
JLOG(m_journal.warn())
<< "Exception checking transaction " << txid << ": " << ex.what();
return;
}

View File

@@ -50,7 +50,7 @@ to_string(Manifest const& m)
}
std::optional<Manifest>
deserializeManifest(Slice s)
deserializeManifest(Slice s, beast::Journal journal)
{
if (s.empty())
return std::nullopt;
@@ -148,8 +148,10 @@ deserializeManifest(Slice s)
return m;
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(journal.error())
<< "Exception in " << __func__ << ": " << ex.what();
return std::nullopt;
}
}
@@ -239,7 +241,7 @@ Manifest::getMasterSignature() const
}
std::optional<ValidatorToken>
loadValidatorToken(std::vector<std::string> const& blob)
loadValidatorToken(std::vector<std::string> const& blob, beast::Journal journal)
{
try
{
@@ -277,8 +279,10 @@ loadValidatorToken(std::vector<std::string> const& blob)
return std::nullopt;
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(journal.error())
<< "Exception in " << __func__ << ": " << ex.what();
return std::nullopt;
}
}

View File

@@ -357,8 +357,9 @@ ValidatorSite::onTimer(std::size_t siteIdx, error_code const& ec)
// the WorkSSL client ctor can throw if SSL init fails
makeRequest(sites_[siteIdx].startingResource, siteIdx, lock);
}
catch (std::exception&)
catch (std::exception const& ex)
{
JLOG(j_.error()) << "Exception in " << __func__ << ": " << ex.what();
onSiteFetch(
boost::system::error_code{-1, boost::system::generic_category()},
{},
@@ -526,7 +527,7 @@ ValidatorSite::processRedirect(
throw std::runtime_error(
"invalid scheme in redirect " + newLocation->pUrl.scheme);
}
catch (std::exception&)
catch (std::exception const& ex)
{
JLOG(j_.error()) << "Invalid redirect location: "
<< res[field::location];
@@ -606,8 +607,10 @@ ValidatorSite::onSiteFetch(
}
}
}
catch (std::exception& ex)
catch (std::exception const& ex)
{
JLOG(j_.error())
<< "Exception in " << __func__ << ": " << ex.what();
onError(ex.what(), false);
}
}
@@ -643,8 +646,10 @@ ValidatorSite::onTextFetch(
parseJsonResponse(res, siteIdx, lock_sites);
}
catch (std::exception& ex)
catch (std::exception const& ex)
{
JLOG(j_.error())
<< "Exception in " << __func__ << ": " << ex.what();
sites_[siteIdx].lastRefreshStatus.emplace(Site::Status{
clock_type::now(), ListDisposition::invalid, ex.what()});
}

View File

@@ -159,9 +159,9 @@ applyTransaction(
JLOG(j.debug()) << "Transaction retry: " << transHuman(result.first);
return ApplyResult::Retry;
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(j.warn()) << "Throws";
JLOG(j.warn()) << "Throws: " << ex.what();
return ApplyResult::Fail;
}
}

View File

@@ -292,10 +292,13 @@ initAuthenticated(
fclose(f);
}
catch (std::exception const&)
catch (std::exception const& ex)
{
fclose(f);
LogicError("Reading the SSL chain file generated an exception.");
LogicError(
std::string(
"Reading the SSL chain file generated an exception: ") +
ex.what());
}
}

View File

@@ -1608,10 +1608,11 @@ PeerImp::handleTransaction(
});
}
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(p_journal_.warn())
<< "Transaction invalid: " << strHex(m->rawtransaction());
<< "Transaction invalid: " << strHex(m->rawtransaction())
<< ". Exception: " << ex.what();
}
}
@@ -3110,8 +3111,10 @@ PeerImp::checkTransaction(
app_.getOPs().processTransaction(
tx, trusted, false, NetworkOPs::FailHard::no);
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(p_journal_.warn())
<< "Exception in " << __func__ << ": " << ex.what();
app_.getHashRouter().setFlags(stx->getTransactionID(), SF_BAD);
charge(Resource::feeBadData);
}
@@ -3195,9 +3198,10 @@ PeerImp::checkValidation(
}
}
}
catch (std::exception const&)
catch (std::exception const& ex)
{
JLOG(p_journal_.trace()) << "Exception processing validation";
JLOG(p_journal_.trace())
<< "Exception processing validation: " << ex.what();
charge(Resource::feeInvalidRequest);
}
}
@@ -3566,7 +3570,7 @@ PeerImp::processLedgerRequest(std::shared_ptr<protocol::TMGetLedger> const& m)
<< "processLedgerRequest: getNodeFat returns false";
}
}
catch (std::exception& e)
catch (std::exception const& e)
{
std::string info;
switch (itype)

View File

@@ -80,10 +80,11 @@ doChannelAuthorize(RPC::JsonContext& context)
auto const buf = sign(pk, sk, msg.slice());
result[jss::signature] = strHex(buf);
}
catch (std::exception&)
catch (std::exception const& ex)
{
result =
RPC::make_error(rpcINTERNAL, "Exception occurred during signing.");
result = RPC::make_error(
rpcINTERNAL,
"Exception occurred during signing: " + std::string(ex.what()));
}
return result;
}

View File

@@ -193,13 +193,14 @@ SHAMap::finishFetch(
canonicalize(hash, node);
return node;
}
catch (SHAMapMissingNode const& e)
{
JLOG(journal_.warn()) << "Missing node: " << hash << " : " << e.what();
}
catch (std::runtime_error const& e)
{
JLOG(journal_.warn()) << e.what();
JLOG(journal_.warn()) << __func__ << " : " << e.what();
}
catch (...)
{