From 8bfdbcbab5ac193a71ea10712d47a91ef1aaa8eb Mon Sep 17 00:00:00 2001 From: drlongle Date: Thu, 30 Mar 2023 19:13:30 +0200 Subject: [PATCH] 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. --- src/ripple/app/consensus/RCLConsensus.cpp | 12 ++++++----- src/ripple/app/ledger/ConsensusTransSetSF.cpp | 6 ++++-- src/ripple/app/ledger/Ledger.cpp | 11 ++++++++-- src/ripple/app/ledger/Ledger.h | 1 + src/ripple/app/ledger/impl/BuildLedger.cpp | 5 +++-- src/ripple/app/ledger/impl/LedgerMaster.cpp | 20 +++++++++++-------- src/ripple/app/ledger/impl/LedgerToJson.cpp | 7 ++++++- src/ripple/app/ledger/impl/OpenLedger.cpp | 4 ++-- src/ripple/app/misc/Manifest.h | 18 +++++++++++------ src/ripple/app/misc/NetworkOPs.cpp | 5 +++-- src/ripple/app/misc/impl/Manifest.cpp | 12 +++++++---- src/ripple/app/misc/impl/ValidatorSite.cpp | 13 ++++++++---- src/ripple/app/tx/impl/apply.cpp | 4 ++-- src/ripple/basics/impl/make_SSLContext.cpp | 7 +++++-- src/ripple/overlay/impl/PeerImp.cpp | 16 +++++++++------ src/ripple/rpc/handlers/PayChanClaim.cpp | 7 ++++--- src/ripple/shamap/impl/SHAMap.cpp | 3 ++- 17 files changed, 99 insertions(+), 52 deletions(-) diff --git a/src/ripple/app/consensus/RCLConsensus.cpp b/src/ripple/app/consensus/RCLConsensus.cpp index 7ba059881..4c80694cb 100644 --- a/src/ripple/app/consensus/RCLConsensus.cpp +++ b/src/ripple/app/consensus/RCLConsensus.cpp @@ -498,10 +498,11 @@ RCLConsensus::Adaptor::doAccept( std::make_shared(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(); } } } diff --git a/src/ripple/app/ledger/ConsensusTransSetSF.cpp b/src/ripple/app/ledger/ConsensusTransSetSF.cpp index 997a2aee1..476c75751 100644 --- a/src/ripple/app/ledger/ConsensusTransSetSF.cpp +++ b/src/ripple/app/ledger/ConsensusTransSetSF.cpp @@ -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(); } } } diff --git a/src/ripple/app/ledger/Ledger.cpp b/src/ripple/app/ledger/Ledger.cpp index 4de01cc90..d96bf5939 100644 --- a/src/ripple/app/ledger/Ledger.cpp +++ b/src/ripple/app/ledger/Ledger.cpp @@ -186,6 +186,7 @@ Ledger::Ledger( , txMap_(std::make_shared(SHAMapType::TRANSACTION, family)) , stateMap_(std::make_shared(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(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(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(SHAMapType::TRANSACTION, family)) , stateMap_(std::make_shared(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(); } diff --git a/src/ripple/app/ledger/Ledger.h b/src/ripple/app/ledger/Ledger.h index 0b0830df9..84e65ecff 100644 --- a/src/ripple/app/ledger/Ledger.h +++ b/src/ripple/app/ledger/Ledger.h @@ -410,6 +410,7 @@ private: Fees fees_; Rules rules_; LedgerInfo info_; + beast::Journal j_; }; /** A ledger wrapped in a CachedView. */ diff --git a/src/ripple/app/ledger/impl/BuildLedger.cpp b/src/ripple/app/ledger/impl/BuildLedger.cpp index 87960d16e..363c110cd 100644 --- a/src/ripple/app/ledger/impl/BuildLedger.cpp +++ b/src/ripple/app/ledger/impl/BuildLedger.cpp @@ -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); } diff --git a/src/ripple/app/ledger/impl/LedgerMaster.cpp b/src/ripple/app/ledger/impl/LedgerMaster.cpp index 7476698ee..7ae747694 100644 --- a/src/ripple/app/ledger/impl/LedgerMaster.cpp +++ b/src/ripple/app/ledger/impl/LedgerMaster.cpp @@ -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(); } } diff --git a/src/ripple/app/ledger/impl/LedgerToJson.cpp b/src/ripple/app/ledger/impl/LedgerToJson.cpp index f4fba08d7..e32303c49 100644 --- a/src/ripple/app/ledger/impl/LedgerToJson.cpp +++ b/src/ripple/app/ledger/impl/LedgerToJson.cpp @@ -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(); + } } } diff --git a/src/ripple/app/ledger/impl/OpenLedger.cpp b/src/ripple/app/ledger/impl/OpenLedger.cpp index 5bb6e53ac..7eef84fc5 100644 --- a/src/ripple/app/ledger/impl/OpenLedger.cpp +++ b/src/ripple/app/ledger/impl/OpenLedger.cpp @@ -206,9 +206,9 @@ debugTostr(SHAMap const& set) auto const tx = std::make_shared(sit); ss << debugTxstr(tx) << ", "; } - catch (std::exception const&) + catch (std::exception const& ex) { - ss << "THRO, "; + ss << "THROW:" << ex.what() << ", "; } } return ss.str(); diff --git a/src/ripple/app/misc/Manifest.h b/src/ripple/app/misc/Manifest.h index a1658428c..88452e5e0 100644 --- a/src/ripple/app/misc/Manifest.h +++ b/src/ripple/app/misc/Manifest.h @@ -138,12 +138,14 @@ to_string(Manifest const& m); */ /** @{ */ std::optional -deserializeManifest(Slice s); +deserializeManifest(Slice s, beast::Journal journal); inline std::optional -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::value || std::is_same::value>> std::optional -deserializeManifest(std::vector const& v) +deserializeManifest( + std::vector 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 -loadValidatorToken(std::vector const& blob); +loadValidatorToken( + std::vector const& blob, + beast::Journal journal = beast::Journal(beast::Journal::getNullSink())); enum class ManifestDisposition { /// Manifest is valid diff --git a/src/ripple/app/misc/NetworkOPs.cpp b/src/ripple/app/misc/NetworkOPs.cpp index d6816b1d4..6be11c7dd 100644 --- a/src/ripple/app/misc/NetworkOPs.cpp +++ b/src/ripple/app/misc/NetworkOPs.cpp @@ -1162,9 +1162,10 @@ NetworkOPsImp::submitTransaction(std::shared_ptr 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; } diff --git a/src/ripple/app/misc/impl/Manifest.cpp b/src/ripple/app/misc/impl/Manifest.cpp index 931b63215..60b521330 100644 --- a/src/ripple/app/misc/impl/Manifest.cpp +++ b/src/ripple/app/misc/impl/Manifest.cpp @@ -50,7 +50,7 @@ to_string(Manifest const& m) } std::optional -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 -loadValidatorToken(std::vector const& blob) +loadValidatorToken(std::vector const& blob, beast::Journal journal) { try { @@ -277,8 +279,10 @@ loadValidatorToken(std::vector 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; } } diff --git a/src/ripple/app/misc/impl/ValidatorSite.cpp b/src/ripple/app/misc/impl/ValidatorSite.cpp index a73d348ee..013d7e96f 100644 --- a/src/ripple/app/misc/impl/ValidatorSite.cpp +++ b/src/ripple/app/misc/impl/ValidatorSite.cpp @@ -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()}); } diff --git a/src/ripple/app/tx/impl/apply.cpp b/src/ripple/app/tx/impl/apply.cpp index 5144e05fe..c0704c5c3 100644 --- a/src/ripple/app/tx/impl/apply.cpp +++ b/src/ripple/app/tx/impl/apply.cpp @@ -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; } } diff --git a/src/ripple/basics/impl/make_SSLContext.cpp b/src/ripple/basics/impl/make_SSLContext.cpp index 79a0e9009..7d72d9e08 100644 --- a/src/ripple/basics/impl/make_SSLContext.cpp +++ b/src/ripple/basics/impl/make_SSLContext.cpp @@ -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()); } } diff --git a/src/ripple/overlay/impl/PeerImp.cpp b/src/ripple/overlay/impl/PeerImp.cpp index 8e014a10f..a07c45745 100644 --- a/src/ripple/overlay/impl/PeerImp.cpp +++ b/src/ripple/overlay/impl/PeerImp.cpp @@ -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 const& m) << "processLedgerRequest: getNodeFat returns false"; } } - catch (std::exception& e) + catch (std::exception const& e) { std::string info; switch (itype) diff --git a/src/ripple/rpc/handlers/PayChanClaim.cpp b/src/ripple/rpc/handlers/PayChanClaim.cpp index c5b1202fa..6353124cb 100644 --- a/src/ripple/rpc/handlers/PayChanClaim.cpp +++ b/src/ripple/rpc/handlers/PayChanClaim.cpp @@ -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; } diff --git a/src/ripple/shamap/impl/SHAMap.cpp b/src/ripple/shamap/impl/SHAMap.cpp index fa42c8e8f..ce031003c 100644 --- a/src/ripple/shamap/impl/SHAMap.cpp +++ b/src/ripple/shamap/impl/SHAMap.cpp @@ -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 (...) {