From 81760bc9f4b6c8e5e1bec6e5d049edea64b169f8 Mon Sep 17 00:00:00 2001 From: Mark Travis Date: Wed, 7 Feb 2024 12:32:45 -0800 Subject: [PATCH] 2.0.0-rcX-debugrelay-6: log whether duplicate messages are being relayed and whether peers' send queue is being modified correctly. --- src/ripple/app/main/Application.cpp | 3 ++- src/ripple/app/misc/HashRouter.cpp | 18 ++++++++++++++++-- src/ripple/app/misc/HashRouter.h | 6 +++++- src/ripple/overlay/impl/OverlayImpl.cpp | 2 ++ src/ripple/overlay/impl/PeerImp.cpp | 10 +++++++++- src/ripple/protocol/impl/BuildInfo.cpp | 2 +- src/test/app/HashRouter_test.cpp | 13 +++++++------ 7 files changed, 42 insertions(+), 12 deletions(-) diff --git a/src/ripple/app/main/Application.cpp b/src/ripple/app/main/Application.cpp index 08ba296b271..70f9de36752 100644 --- a/src/ripple/app/main/Application.cpp +++ b/src/ripple/app/main/Application.cpp @@ -457,7 +457,8 @@ class ApplicationImp : public Application, public BasicApp , hashRouter_(std::make_unique( stopwatch(), - HashRouter::getDefaultHoldTime())) + HashRouter::getDefaultHoldTime(), + logs_->journal("HashRouter"))) , mValidations( ValidationParms(), diff --git a/src/ripple/app/misc/HashRouter.cpp b/src/ripple/app/misc/HashRouter.cpp index 8085d6892ab..35932cea4da 100644 --- a/src/ripple/app/misc/HashRouter.cpp +++ b/src/ripple/app/misc/HashRouter.cpp @@ -18,6 +18,8 @@ //============================================================================== #include +#include +#include namespace ripple { @@ -122,10 +124,22 @@ HashRouter::shouldRelay(uint256 const& key) auto& s = emplace(key).first; + std::stringstream ss; + ss << "shouldRelay " << key; + std::optional> ret; if (!s.shouldRelay(suppressionMap_.clock().now(), holdTime_)) - return {}; + { + ss << " not recently relayed."; + } + else + { + ss << " recently relayed."; + ret = s.releasePeerSet(); + } - return s.releasePeerSet(); + ss << " relaying: " << (ret.has_value() ? "true" : "false"); + JLOG(j_.debug()) << ss.str(); + return ret; } } // namespace ripple diff --git a/src/ripple/app/misc/HashRouter.h b/src/ripple/app/misc/HashRouter.h index 8c546b2c51d..f3a98cb6374 100644 --- a/src/ripple/app/misc/HashRouter.h +++ b/src/ripple/app/misc/HashRouter.h @@ -25,6 +25,7 @@ #include #include #include +#include #include @@ -143,8 +144,10 @@ class HashRouter return 300s; } - HashRouter(Stopwatch& clock, std::chrono::seconds entryHoldTimeInSeconds) + HashRouter(Stopwatch& clock, std::chrono::seconds entryHoldTimeInSeconds, + beast::Journal j) : suppressionMap_(clock), holdTime_(entryHoldTimeInSeconds) + , j_(j) { } @@ -221,6 +224,7 @@ class HashRouter suppressionMap_; std::chrono::seconds const holdTime_; + beast::Journal j_; }; } // namespace ripple diff --git a/src/ripple/overlay/impl/OverlayImpl.cpp b/src/ripple/overlay/impl/OverlayImpl.cpp index a0fe6175119..558a7f87e85 100644 --- a/src/ripple/overlay/impl/OverlayImpl.cpp +++ b/src/ripple/overlay/impl/OverlayImpl.cpp @@ -1246,8 +1246,10 @@ OverlayImpl::relay( std::make_shared(m, protocol::mtPROPOSE_LEDGER, validator); for_each([&](std::shared_ptr&& p) { if (toSkip->find(p->id()) == toSkip->end()) + { JLOG(journal_.debug()) << "debugrelay send() 9"; p->send(sm); + } }); return *toSkip; } diff --git a/src/ripple/overlay/impl/PeerImp.cpp b/src/ripple/overlay/impl/PeerImp.cpp index 79d662b43d8..1b622a8a89c 100644 --- a/src/ripple/overlay/impl/PeerImp.cpp +++ b/src/ripple/overlay/impl/PeerImp.cpp @@ -281,9 +281,16 @@ PeerImp::send(std::shared_ptr const& m) send_queue_.push(m); if (sendq_size != 0) + { + JLOG(journal_.debug()) << "send not sending type: " + << protocolMessageName(m->getType(&m->getBuffer(Compressed::Off)[0])) + << ". Prior to push, q size was " << sendq_size << ". now it's " + << send_queue_.size(); return; + } - JLOG(journal_.debug()) << "sending message type " << protocolMessageName(m->getType(&m->getBuffer(Compressed::Off)[0])); + JLOG(journal_.debug()) << "sending message type " << protocolMessageName(m->getType(&m->getBuffer(Compressed::Off)[0])) + << ". just pushed q size " << send_queue_.size(); boost::asio::async_write( stream_, boost::asio::buffer( @@ -978,6 +985,7 @@ PeerImp::onWriteMessage(error_code ec, std::size_t bytes_transferred) assert(!send_queue_.empty()); send_queue_.pop(); + JLOG(journal_.debug()) << "onWriteMessage just popped q size " << send_queue_.size(); if (!send_queue_.empty()) { // Timeout on writes only diff --git a/src/ripple/protocol/impl/BuildInfo.cpp b/src/ripple/protocol/impl/BuildInfo.cpp index 9646ac5ea10..5d7e3db6139 100644 --- a/src/ripple/protocol/impl/BuildInfo.cpp +++ b/src/ripple/protocol/impl/BuildInfo.cpp @@ -33,7 +33,7 @@ namespace BuildInfo { // and follow the format described at http://semver.org/ //------------------------------------------------------------------------------ // clang-format off -char const* const versionString = "2.0.0-rcX-debugrelay-5" +char const* const versionString = "2.0.0-rcX-debugrelay-6" // clang-format on #if defined(DEBUG) || defined(SANITIZER) diff --git a/src/test/app/HashRouter_test.cpp b/src/test/app/HashRouter_test.cpp index 96d14e824cf..9b06e6c0253 100644 --- a/src/test/app/HashRouter_test.cpp +++ b/src/test/app/HashRouter_test.cpp @@ -20,6 +20,7 @@ #include #include #include +#include namespace ripple { namespace test { @@ -31,7 +32,7 @@ class HashRouter_test : public beast::unit_test::suite { using namespace std::chrono_literals; TestStopwatch stopwatch; - HashRouter router(stopwatch, 2s); + HashRouter router(stopwatch, 2s, test::SuiteJournal("TestHashRouter", *this)); uint256 const key1(1); uint256 const key2(2); @@ -68,7 +69,7 @@ class HashRouter_test : public beast::unit_test::suite { using namespace std::chrono_literals; TestStopwatch stopwatch; - HashRouter router(stopwatch, 2s); + HashRouter router(stopwatch, 2s, test::SuiteJournal("TestHashRouter", *this)); uint256 const key1(1); uint256 const key2(2); @@ -146,7 +147,7 @@ class HashRouter_test : public beast::unit_test::suite // Normal HashRouter using namespace std::chrono_literals; TestStopwatch stopwatch; - HashRouter router(stopwatch, 2s); + HashRouter router(stopwatch, 2s, test::SuiteJournal("TestHashRouter", *this)); uint256 const key1(1); uint256 const key2(2); @@ -174,7 +175,7 @@ class HashRouter_test : public beast::unit_test::suite { using namespace std::chrono_literals; TestStopwatch stopwatch; - HashRouter router(stopwatch, 2s); + HashRouter router(stopwatch, 2s, test::SuiteJournal("TestHashRouter", *this)); uint256 const key1(1); BEAST_EXPECT(router.setFlags(key1, 10)); @@ -187,7 +188,7 @@ class HashRouter_test : public beast::unit_test::suite { using namespace std::chrono_literals; TestStopwatch stopwatch; - HashRouter router(stopwatch, 1s); + HashRouter router(stopwatch, 1s, test::SuiteJournal("TestHashRouter", *this)); uint256 const key1(1); @@ -230,7 +231,7 @@ class HashRouter_test : public beast::unit_test::suite { using namespace std::chrono_literals; TestStopwatch stopwatch; - HashRouter router(stopwatch, 5s); + HashRouter router(stopwatch, 5s, test::SuiteJournal("TestHashRouter", *this)); uint256 const key(1); HashRouter::PeerShortID peer = 1; int flags;