Log transaction set acquisition details.

Author: mtrippled

src/test/app/LedgerReplay_test.cpp

@@ -419,6 +419,11 @@ struct TestPeerSet : public PeerSet
         return emptyPeers;
     }
 
+    std::string
+    to_string() const override {
+        return "";
+    }
+
     LedgerReplayMsgHandler& local;
     LedgerReplayMsgHandler& remote;
     std::shared_ptr<TestPeer> dummyPeer;

src/xrpld/app/ledger/detail/TransactionAcquire.cpp

@@ -52,6 +52,7 @@ TransactionAcquire::TransactionAcquire(
           app.journal("TransactionAcquire"))
     , mHaveRoot(false)
     , mPeerSet(std::move(peerSet))
+    , startTime_(std::chrono::steady_clock::now())
 {
     mMap = std::make_shared<SHAMap>(
         SHAMapType::TRANSACTION, hash, app_.getNodeFamily());
@@ -65,11 +66,21 @@ TransactionAcquire::done()
 
     if (failed_)
     {
-        JLOG(journal_.debug()) << "Failed to acquire TX set " << hash_;
+        JLOG(journal_.debug()) << "ACQUIRE done Failed to acquire TX set " << hash_
+        << " duration " << to_string(std::chrono::duration_cast<std::chrono::nanoseconds>(
+            std::chrono::steady_clock::now() - startTime_).count()) << "ns total nodes " << nodeCount_
+        << " total peers " << mPeerSet->getPeerIds().size()
+        << " peers " << mPeerSet->to_string();
+
     }
     else
     {
-        JLOG(journal_.debug()) << "Acquired TX set " << hash_;
+        JLOG(journal_.debug()) << "ACQUIRE done Acquired TX set " << hash_
+            << " duration " << to_string(std::chrono::duration_cast<std::chrono::nanoseconds>(
+                std::chrono::steady_clock::now() - startTime_).count()) << "ns total nodes " << nodeCount_
+            << " total peers " << mPeerSet->getPeerIds().size()
+            << " peers " << mPeerSet->to_string();
+
         mMap->setImmutable();
 
         uint256 const& hash(hash_);
@@ -101,6 +112,8 @@ TransactionAcquire::onTimer(bool progress, ScopedLockType& psl)
         trigger(nullptr);
 
     addPeers(1);
+    JLOG(journal_.debug()) << "ACQUIRE onTimer " << hash_ << " num peers: " << mPeerSet->getPeerIds().size()
+        << " peers " << mPeerSet->to_string();
 }
 
 std::weak_ptr<TimeoutCounter>
@@ -137,6 +150,7 @@ TransactionAcquire::trigger(std::shared_ptr<Peer> const& peer)
 
         *(tmGL.add_nodeids()) = SHAMapNodeID().getRawString();
         mPeerSet->sendRequest(tmGL, peer);
+    JLOG(journal_.debug()) << "ACQUIRE trigger " << hash_ << " no root sending to: " << peer.get()->id();
     }
     else if (!mMap->isValid())
     {
@@ -171,6 +185,9 @@ TransactionAcquire::trigger(std::shared_ptr<Peer> const& peer)
             *tmGL.add_nodeids() = node.first.getRawString();
         }
         mPeerSet->sendRequest(tmGL, peer);
+        nodeCount_ +=  nodes.size();
+        JLOG(journal_.debug()) << "ACQUIRE trigger " << hash_ << " need " << nodes.size()
+            << " nodes sending to: " << peer.get()->id();
     }
 }
 
@@ -225,6 +242,8 @@ TransactionAcquire::takeNodes(
 
         trigger(peer);
         progress_ = true;
+        JLOG(journal_.debug()) << "ACQUIRE takeNodes " << hash_ << " got " << data.size()
+            << " nodes from " << peer.get()->id();
         return SHAMapAddNode::useful();
     }
     catch (std::exception const& ex)
@@ -251,6 +270,8 @@ TransactionAcquire::init(int numPeers)
     ScopedLockType sl(mtx_);
 
     addPeers(numPeers);
+    JLOG(journal_.debug()) << "ACQUIRE init " << hash_ << " num peers: " << mPeerSet->getPeerIds().size()
+        << " peers " << mPeerSet->to_string();
 
     setTimer(sl);
 }

src/xrpld/app/ledger/detail/TransactionAcquire.h

@@ -23,6 +23,8 @@
 #include <xrpld/app/main/Application.h>
 #include <xrpld/overlay/PeerSet.h>
 #include <xrpld/shamap/SHAMap.h>
+#include <chrono>
+#include <sstream>
 
 namespace ripple {
 
@@ -58,6 +60,10 @@ class TransactionAcquire final
     bool mHaveRoot;
     std::unique_ptr<PeerSet> mPeerSet;
 
+    std::chrono::steady_clock::time_point startTime_;
+    std::atomic<std::size_t> nodeCount_;
+    std::stringstream ss_;
+
     void
     onTimer(bool progress, ScopedLockType& peerSetLock) override;
 

src/xrpld/app/main/Application.cpp

@@ -258,8 +258,8 @@ class ApplicationImp : public Application, public BasicApp
         if ((cores == 1) || ((config.NODE_SIZE == 0) && (cores == 2)))
             return 1;
 
-        // Otherwise, prefer two threads.
-        return 2;
+        // Otherwise, prefer six threads.
+        return 6;
 #endif
     }
 

src/xrpld/overlay/PeerSet.h

@@ -75,6 +75,9 @@ class PeerSet
     /** get the set of ids of previously added peers */
     virtual const std::set<Peer::id_t>&
     getPeerIds() const = 0;
+
+    virtual std::string
+    to_string() const = 0;
 };
 
 class PeerSetBuilder

src/xrpld/overlay/detail/PeerSet.cpp

@@ -21,6 +21,7 @@
 #include <xrpld/core/JobQueue.h>
 #include <xrpld/overlay/Overlay.h>
 #include <xrpld/overlay/PeerSet.h>
+#include <sstream>
 
 namespace ripple {
 
@@ -45,6 +46,9 @@ class PeerSetImpl : public PeerSet
     const std::set<Peer::id_t>&
     getPeerIds() const override;
 
+    std::string
+    to_string() const override;
+
 private:
     // Used in this class for access to boost::asio::io_service and
     // ripple::Overlay.
@@ -123,6 +127,20 @@ PeerSetImpl::getPeerIds() const
     return peers_;
 }
 
+std::string
+PeerSetImpl::to_string() const {
+    std::stringstream ss;
+    bool first = true;
+    for (auto const& peer : peers_) {
+        if (first)
+            first = false;
+        else
+            ss << ',';
+        ss << peer;
+    }
+    return ss.str();
+}
+
 class PeerSetBuilderImpl : public PeerSetBuilder
 {
 public:
@@ -179,6 +197,12 @@ class DummyPeerSet : public PeerSet
         return emptyPeers;
     }
 
+    std::string
+    to_string() const override {
+        return "DummyPeerSet to_string should not be called";
+    }
+
+
 private:
     beast::Journal j_;
 };