From 2d4cc8a19ee095d5c248c67681dcd0a1fe74d45f Mon Sep 17 00:00:00 2001
From: Alexander Block <ablock84@gmail.com>
Date: Tue, 7 Apr 2020 13:26:47 +0200
Subject: [PATCH] More logging for object request handling

---
 src/net_processing.cpp | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/src/net_processing.cpp b/src/net_processing.cpp
index 391875c4e9..cc7827df1b 100644
--- a/src/net_processing.cpp
+++ b/src/net_processing.cpp
@@ -662,6 +662,7 @@ void FindNextBlocksToDownload(NodeId nodeid, unsigned int count, std::vector<con
 void EraseObjectRequest(CNodeState* nodestate, const CInv& inv) EXCLUSIVE_LOCKS_REQUIRED(cs_main)
 {
     AssertLockHeld(cs_main);
+    LogPrint(BCLog::NET, "%s -- inv=(%s)\n", __func__, inv.ToString());
     g_already_asked_for.erase(inv.hash);
     g_erased_object_requests.insert(std::make_pair(inv.hash, GetTimeMillis()));
 
@@ -775,6 +776,8 @@ void RequestObject(CNodeState* state, const CInv& inv, int64_t nNow, bool fForce
         g_erased_object_requests.erase(inv.hash);
         g_already_asked_for.erase(inv.hash);
     }
+
+    LogPrint(BCLog::NET, "%s -- inv=(%s), nNow=%d, process_time=%d, delta=%d\n", __func__, inv.ToString(), nNow, process_time, process_time - nNow);
 }
 
 void RequestObject(NodeId nodeId, const CInv& inv, int64_t nNow, bool fForce) EXCLUSIVE_LOCKS_REQUIRED(cs_main)
@@ -4318,6 +4321,7 @@ bool PeerLogicValidation::SendMessages(CNode* pto, std::atomic<bool>& interruptM
             // processing at a later time, see below)
             tx_process_time.erase(tx_process_time.begin());
             if (g_erased_object_requests.count(inv.hash)) {
+                LogPrint(BCLog::NET, "%s -- GETDATA skipping inv=(%s), peer=%d\n", __func__, inv.ToString(), pto->GetId());
                 state.m_tx_download.m_tx_announced.erase(inv);
                 state.m_tx_download.m_tx_in_flight.erase(inv);
                 continue;
@@ -4342,11 +4346,13 @@ bool PeerLogicValidation::SendMessages(CNode* pto, std::atomic<bool>& interruptM
                     // requests to outbound peers).
                     int64_t next_process_time = CalculateObjectGetDataTime(inv, nNow, !state.fPreferredDownload);
                     tx_process_time.emplace(next_process_time, inv);
+                    LogPrint(BCLog::NET, "%s -- GETDATA re-queue inv=(%s), next_process_time=%d, delta=%d, peer=%d\n", __func__, inv.ToString(), next_process_time, next_process_time - nNow, pto->GetId());
                 }
             } else {
                 // We have already seen this transaction, no need to download.
                 state.m_tx_download.m_tx_announced.erase(inv);
                 state.m_tx_download.m_tx_in_flight.erase(inv);
+                LogPrint(BCLog::NET, "%s -- GETDATA already seen inv=(%s), peer=%d\n", __func__, inv.ToString(), pto->GetId());
             }
         }