changeset 23685:110ccd1e93ab

1. add node's IP address to thin block logs that reference a node to make the logs more understandable 2. Clear a CNode's thinblock CBlock structure via SetNull() rather than via copy constructor for clarity and efficiency. 3. Also clear the CNode's thinblock right away to ensure that is is not used after it has been "released" 4. In SendMessages, the deadlock detector is triggered, so reordered cs_main and cs_vSend locks to match other code's locking order (not a thin block issue) 5. Prefer thin block communications by handling them first in ThreadMessageHandler. 6. Add a member function ThinBlockCapable() that returns true if the node supports thin blocks
author Andrew Stone <g.andrew.stone@gmail.com>
date Tue, 16 Feb 2016 16:31:25 -0500
parents 5b387556b1d1
children 87ea81c9c6be 8be78259f37f
files src/main.cpp src/net.cpp src/net.h src/unlimited.cpp src/unlimited.h
diffstat 5 files changed, 77 insertions(+), 28 deletions(-) [+]
line wrap: on
line diff
--- a/src/main.cpp	Mon Feb 15 14:19:35 2016 -0500
+++ b/src/main.cpp	Tue Feb 16 16:31:25 2016 -0500
@@ -4605,7 +4605,7 @@
                                     vToFetch.push_back(inv2);
                                     SendSeededBloomFilter(pfrom);
                                     MarkBlockAsInFlight(pfrom->GetId(), inv.hash, chainparams.GetConsensus());
-                                    LogPrint("thin", "Requesting Thinblock %s peer=%d\n", inv2.hash.ToString(), pfrom->id);
+                                    LogPrint("thin", "Requesting Thinblock %s from peer %s (%d)\n", inv2.hash.ToString(), pfrom->addrName.c_str(),pfrom->id);
                                 }
                             }
                             else {
@@ -4614,10 +4614,10 @@
                                     pfrom->mapThinBlocksInFlight[inv2.hash] = GetTime();
                                     inv2.type = MSG_XTHINBLOCK;
                                     SendSeededBloomFilter(pfrom);
-                                    LogPrint("thin", "Requesting Thinblock %s peer=%d\n", inv2.hash.ToString(), pfrom->id);
+                                    LogPrint("thin", "Requesting Thinblock %s from peer %s (%d)\n", inv2.hash.ToString(), pfrom->addrName.c_str(),pfrom->id);
                                 }
                                 else
-                                    LogPrint("thin", "Requesting Regular Block %s peer=%d\n", inv2.hash.ToString(), pfrom->id);
+                                    LogPrint("thin", "Requesting Regular Block %s from peer %s (%d)\n", inv2.hash.ToString(), pfrom->addrName.c_str(),pfrom->id);
                                 MarkBlockAsInFlight(pfrom->GetId(), inv.hash, chainparams.GetConsensus());
                                 vToFetch.push_back(inv2);
                             }
@@ -4625,7 +4625,7 @@
                         else {
                             vToFetch.push_back(inv2);
                             MarkBlockAsInFlight(pfrom->GetId(), inv.hash, chainparams.GetConsensus());
-                            LogPrint("thin", "Requesting Regular Block %s peer=%d\n", inv2.hash.ToString(), pfrom->id);
+                            LogPrint("thin", "Requesting Regular Block %s from peer %s (%d)\n", inv2.hash.ToString(), pfrom->addrName.c_str(),pfrom->id);
                         }
                         // BUIP010 Xtreme Thinblocks: end section
                     }
@@ -5017,13 +5017,13 @@
 
         CInv inv(MSG_BLOCK, thinBlock.header.GetHash());
         int nSizeThinBlock = ::GetSerializeSize(thinBlock, SER_NETWORK, PROTOCOL_VERSION);
-        LogPrint("thin", "received thinblock %s peer=%d (%d bytes)\n", inv.hash.ToString(), pfrom->id, nSizeThinBlock);
+        LogPrint("thin", "Received thinblock %s from peer %s (%d). Size %d bytes.\n", inv.hash.ToString(), pfrom->addrName.c_str(),pfrom->id, nSizeThinBlock);
         if (!pfrom->mapThinBlocksInFlight.count(inv.hash)) {
-            LogPrint("thin", "Thinblock received but not requested %s  peer=%d\n",inv.hash.ToString(), pfrom->id);
+            LogPrint("thin", "Thinblock received but not requested %s from peer %s (%d)\n",inv.hash.ToString(), pfrom->addrName.c_str(), pfrom->addrName.c_str(), pfrom->id);
             Misbehaving(pfrom->GetId(), 20);
         }
 
-        pfrom->thinBlock = CBlock();
+        pfrom->thinBlock.SetNull();
         pfrom->thinBlock.nVersion = thinBlock.header.nVersion;
         pfrom->thinBlock.nBits = thinBlock.header.nBits;
         pfrom->thinBlock.nNonce = thinBlock.header.nNonce;
@@ -5088,7 +5088,7 @@
             pfrom->AddInventoryKnown(inv); 
             LogPrint("thin", "Reassembled thin block for %s (%d bytes)\n", pfrom->thinBlock.GetHash().ToString(),
                        pfrom->thinBlock.GetSerializeSize(SER_NETWORK, CBlock::CURRENT_VERSION));
-            HandleBlockMessage(pfrom, strCommand, pfrom->thinBlock, inv);
+            HandleBlockMessage(pfrom, strCommand, pfrom->thinBlock, inv);  // clears the thin block
         }
         else if (pfrom->thinBlockWaitingForTxns > 0) {
             // This marks the end of the transactions we've received. If we get this and we have NOT been able to
@@ -5115,14 +5115,14 @@
 
         CInv inv(MSG_BLOCK, thinBlock.header.GetHash());
         int nSizeThinBlock = ::GetSerializeSize(thinBlock, SER_NETWORK, PROTOCOL_VERSION);
-        LogPrint("thin", "received thinblock %s peer=%d (%d bytes)\n", inv.hash.ToString(), pfrom->id, nSizeThinBlock);
+        LogPrint("thin", "received thinblock %s from peer %s (%d) of %d bytes\n", inv.hash.ToString(), pfrom->addrName.c_str(),pfrom->id, nSizeThinBlock);
         if (!pfrom->mapThinBlocksInFlight.count(inv.hash)) {
             LogPrint("thin", "Thinblock received but not requested %s  peer=%d\n",inv.hash.ToString(), pfrom->id);
             LOCK(cs_main);
             Misbehaving(pfrom->GetId(), 20);
         }
 
-        pfrom->thinBlock = CBlock();
+        pfrom->thinBlock.SetNull();
         pfrom->thinBlock.nVersion = thinBlock.header.nVersion;
         pfrom->thinBlock.nBits = thinBlock.header.nBits;
         pfrom->thinBlock.nNonce = thinBlock.header.nNonce;
@@ -5670,6 +5670,9 @@
         TRY_LOCK(cs_main, lockMain); // Acquire cs_main for IsInitialBlockDownload() and CNodeState()
         if (!lockMain)
             return true;
+        TRY_LOCK(pto->cs_vSend, lockSend);
+        if (!lockSend)
+          return true;
 
         // Address refresh broadcast
         int64_t nNow = GetTimeMicros();
@@ -5951,8 +5954,8 @@
                             vGetData.push_back(CInv(MSG_XTHINBLOCK, pindex->GetBlockHash())); 
                             SendSeededBloomFilter(pto);
                             MarkBlockAsInFlight(pto->GetId(), pindex->GetBlockHash(), consensusParams, pindex);
-                            LogPrint("thin", "Requesting Thinblock %s (%d) peer=%d\n", pindex->GetBlockHash().ToString(),
-                                             pindex->nHeight, pto->id);
+                            LogPrint("thin", "Requesting thinblock %s (%d) from peer %s (%d)\n", pindex->GetBlockHash().ToString(),
+                                     pindex->nHeight, pto->addrName.c_str(), pto->id);
                         }
                     }
                     else {
@@ -5961,13 +5964,13 @@
                             pto->mapThinBlocksInFlight[pindex->GetBlockHash()] = GetTime();
                             vGetData.push_back(CInv(MSG_XTHINBLOCK, pindex->GetBlockHash())); 
                             SendSeededBloomFilter(pto);
-                            LogPrint("thin", "Requesting Thinblock %s (%d) peer=%d\n", pindex->GetBlockHash().ToString(),
-                                             pindex->nHeight, pto->id);
+                            LogPrint("thin", "Requesting Thinblock %s (%d) from peer %s (%d)\n", pindex->GetBlockHash().ToString(),
+                                     pindex->nHeight, pto->addrName.c_str(), pto->id);
                         }
                         else {
                             vGetData.push_back(CInv(MSG_BLOCK, pindex->GetBlockHash())); 
-                            LogPrint("net", "Requesting block %s (%d) peer=%d\n", pindex->GetBlockHash().ToString(),
-                                             pindex->nHeight, pto->id);
+                            LogPrint("net", "Requesting block %s (%d) from peer %s (%d)\n", pindex->GetBlockHash().ToString(),
+                                     pindex->nHeight, pto->addrName.c_str(), pto->id);
                         }
                         MarkBlockAsInFlight(pto->GetId(), pindex->GetBlockHash(), consensusParams, pindex);
                     }
--- a/src/net.cpp	Mon Feb 15 14:19:35 2016 -0500
+++ b/src/net.cpp	Tue Feb 16 16:31:25 2016 -0500
@@ -215,7 +215,7 @@
         }
         if (addrLocal.IsRoutable())
         {
-            LogPrintf("AdvertizeLocal: advertizing address %s\n", addrLocal.ToString());
+          // BU logs too often: LogPrintf("AdvertiseLocal: advertising address %s\n", addrLocal.ToString());
             pnode->PushAddress(addrLocal);
         }
     }
@@ -1685,7 +1685,7 @@
             }
         }
 
-        bool fSleep = true;
+        bool fSleep = ThinBlockMessageHandler(vNodesCopy);
 
         BOOST_FOREACH (CNode* pnode, vNodesCopy) {
             if (pnode->fDisconnect)
@@ -1709,9 +1709,9 @@
 
             // Send messages
             {
-                TRY_LOCK(pnode->cs_vSend, lockSend);
-                if (lockSend)
-                    g_signals.SendMessages(pnode);
+              //TRY_LOCK(pnode->cs_vSend, lockSend);
+              //  if (lockSend)
+              g_signals.SendMessages(pnode);
             }
             boost::this_thread::interruption_point();
         }
@@ -1723,7 +1723,7 @@
         }
 
         if (fSleep)
-            messageHandlerCondition.timed_wait(lock, boost::posix_time::microsec_clock::universal_time() + boost::posix_time::milliseconds(100));
+            messageHandlerCondition.timed_wait(lock, boost::posix_time::microsec_clock::universal_time() + boost::posix_time::milliseconds(50));
     }
 }
 
--- a/src/net.h	Mon Feb 15 14:19:35 2016 -0500
+++ b/src/net.h	Tue Feb 16 16:31:25 2016 -0500
@@ -489,6 +489,13 @@
         nRefCount--;
     }
 
+    // BUIP010:
+    bool ThinBlockCapable()
+    {
+        if(nVersion >= THINBLOCKS_VERSION) return true;
+        return false;
+    }
+    
 
     void AddAddressKnown(const CAddress& addr)
     {
--- a/src/unlimited.cpp	Mon Feb 15 14:19:35 2016 -0500
+++ b/src/unlimited.cpp	Tue Feb 16 16:31:25 2016 -0500
@@ -600,23 +600,58 @@
             Misbehaving(pfrom->GetId(), nDoS);
         }
     }
-    LogPrint("thin", "Processed block %s in %.2f seconds\n", inv.hash.ToString(), (double)(GetTimeMicros() - startTime) / 1000000.0);
-
+    LogPrint("thin", "Processed thinblock %s in %.2f seconds\n", inv.hash.ToString(), (double)(GetTimeMicros() - startTime) / 1000000.0);
+    
     // When we request a thinblock we may get back a regular block if it is smaller than a thinblock
-    // Therefore we have to remove thinblock in flight if it exists and we also need to check that 
-    // the block didn't arrive from some other peer.
+    // Therefore we have to remove the thinblock in flight if it exists and we also need to check that 
+    // the block didn't arrive from some other peer.  This code ALSO cleans up the thin block that
+    // was passed to us (&block), so do not use it after this.
     {
         LOCK(cs_vNodes);
         BOOST_FOREACH(CNode* pnode, vNodes) {
             if (pnode->mapThinBlocksInFlight.count(inv.hash)) {
                 pnode->mapThinBlocksInFlight.erase(inv.hash); 
                 pnode->thinBlockWaitingForTxns = -1;
-                LogPrintf("Removing Thinblock in flight %s  peer=%d\n",inv.hash.ToString(), pnode->id);
+                pnode->thinBlock.SetNull();
+                if (pnode != pfrom) LogPrintf("Removing thinblock in flight %s from %s (%d)\n",inv.hash.ToString(), pnode->addrName.c_str(), pnode->id);
             }
         }
     }
 }
 
+bool ThinBlockMessageHandler(vector<CNode*>& vNodesCopy)
+{
+  bool sleep = true;
+  CNodeSignals& signals = GetNodeSignals();
+  BOOST_FOREACH (CNode* pnode, vNodesCopy)
+    {
+      if ((pnode->fDisconnect)||(!pnode->ThinBlockCapable()))
+        continue;
+
+      // Receive messages
+      {
+        TRY_LOCK(pnode->cs_vRecvMsg, lockRecv);
+        if (lockRecv)
+          {
+            if (!signals.ProcessMessages(pnode))
+              pnode->CloseSocketDisconnect();
+
+            if (pnode->nSendSize < SendBufferSize())
+              {
+                if (!pnode->vRecvGetData.empty() || (!pnode->vRecvMsg.empty() && pnode->vRecvMsg[0].complete()))
+                  {
+                    sleep = false;
+                  }
+              }
+          }
+      }
+      boost::this_thread::interruption_point();
+      signals.SendMessages(pnode);
+      boost::this_thread::interruption_point();
+    }
+  return sleep;
+}
+
 void ConnectToThinBlockNodes()
 {
     // Connect to specific addresses
--- a/src/unlimited.h	Mon Feb 15 14:19:35 2016 -0500
+++ b/src/unlimited.h	Tue Feb 16 16:31:25 2016 -0500
@@ -8,6 +8,7 @@
 #include "leakybucket.h"
 #include "net.h"
 #include <univalue.h>
+#include <vector>
 
 enum {
     DEFAULT_MAX_GENERATED_BLOCK_SIZE = 1000000,
@@ -58,7 +59,7 @@
 
 // BUIP010 Xtreme Thinblocks:
 extern bool HaveThinblockNodeConnections();
-extern bool IsThinBlocksEnabled();
+extern bool IsThinBlocksEnabled();  // has the user enabled thin blocks for this node (command line option)
 extern bool IsChainNearlySyncd();
 extern void SendSeededBloomFilter(CNode *pto);
 extern void HandleBlockMessage(CNode *pfrom, const std::string &strCommand, CBlock &block, const CInv &inv);
@@ -66,4 +67,7 @@
 extern void CheckNodeSupportForThinBlocks();
 extern void SendXThinBlock(CBlock &block, CNode* pfrom, const CInv &inv);
 
+// Handle receiving and sending messages from thin block capable nodes only (so that thin block nodes capable nodes are preferred)
+extern bool ThinBlockMessageHandler(std::vector<CNode*>& vNodesCopy);
+
 #endif