add logging

Author: adamsmo

src/main/scala/io/iohk/ethereum/blockchain/sync/FastSync.scala

@@ -65,14 +65,21 @@ trait FastSync {
         tryStartFastSync(newReceived)
       } else context become waitingForBlockHeaders(newWaitingFor, newReceived, timeout)
 
-    case PeerActor.MessageReceived(BlockHeaders(_)) =>
+    case PeerActor.MessageReceived(BlockHeaders(blockHeaders)) =>
       sender() ! PeerActor.Unsubscribe
+      log.info("Peer ({}) did not respond with 1 header but with {}, blacklisting for {}",
+        sender().path.name,
+        blockHeaders.size,
+        blacklistDuration)
       blacklist(sender(), blacklistDuration)
       context become waitingForBlockHeaders(waitingFor - sender(), received, timeout)
 
     case BlockHeadersTimeout =>
       waitingFor.foreach { peer =>
         peer ! PeerActor.Unsubscribe
+        log.info("Peer ({}) did not respond within required time with block header, blacklisting for {}",
+          peer.path.name,
+          blacklistDuration)
         blacklist(peer, blacklistDuration)
       }
       tryStartFastSync(received)

src/main/scala/io/iohk/ethereum/blockchain/sync/FastSyncNodesRequestHandler.scala

@@ -19,10 +19,12 @@ class FastSyncNodesRequestHandler(
   import FastSyncNodesRequestHandler._
 
   override val requestMsg = GetNodeData(requestedHashes.map(_.v))
-  override val responseMsgCode = NodeData.code
+  override val responseMsgCode: Int = NodeData.code
 
   override def handleResponseMsg(nodeData: NodeData): Unit = {
     if (nodeData.values.isEmpty) {
+      log.info(s"Blacklisting peer (${peer.path.name}), " +
+        s"got empty mpt node response for known hashes: ${requestedHashes.map(h => Hex.toHexString(h.v.toArray[Byte]))}")
       syncController ! BlacklistSupport.BlacklistPeer(peer)
     }
 
@@ -59,6 +61,8 @@ class FastSyncNodesRequestHandler(
   }
 
   override def handleTimeout(): Unit = {
+    log.info(s"Blacklisting peer (${peer.path.name}), " +
+      s"time out on mpt node response for known hashes: ${requestedHashes.map(h => Hex.toHexString(h.v.toArray[Byte]))}")
     syncController ! BlacklistSupport.BlacklistPeer(peer)
     syncController ! FastSync.EnqueueNodes(requestedHashes)
     cleanupAndStop()

src/main/scala/io/iohk/ethereum/blockchain/sync/FastSyncReceiptsRequestHandler.scala

@@ -5,6 +5,7 @@ import akka.util.ByteString
 import io.iohk.ethereum.db.storage.AppStateStorage
 import io.iohk.ethereum.domain.Blockchain
 import io.iohk.ethereum.network.p2p.messages.PV63.{GetReceipts, Receipts}
+import org.spongycastle.util.encoders.Hex
 
 class FastSyncReceiptsRequestHandler(
     peer: ActorRef,
@@ -14,7 +15,7 @@ class FastSyncReceiptsRequestHandler(
   extends SyncRequestHandler[GetReceipts, Receipts](peer) {
 
   override val requestMsg = GetReceipts(requestedHashes)
-  override val responseMsgCode = Receipts.code
+  override val responseMsgCode: Int = Receipts.code
 
   override def handleResponseMsg(receipts: Receipts): Unit = {
     (requestedHashes zip receipts.receiptsForBlocks).foreach { case (hash, receiptsForBlock) =>
@@ -25,6 +26,8 @@ class FastSyncReceiptsRequestHandler(
     updateBestBlockIfNeeded(receivedHashes)
 
     if (receipts.receiptsForBlocks.isEmpty) {
+      log.info(s"Blacklisting peer (${peer.path.name}), " +
+        s"got empty receipts for known hashes: ${requestedHashes.map(h => Hex.toHexString(h.toArray[Byte]))}")
       syncController ! BlacklistSupport.BlacklistPeer(peer)
     }
 
@@ -54,6 +57,8 @@ class FastSyncReceiptsRequestHandler(
   }
 
   override def handleTimeout(): Unit = {
+    log.info(s"Blacklisting peer (${peer.path.name}), " +
+      s"time out on receipts response for known hashes: ${requestedHashes.map(h => Hex.toHexString(h.toArray[Byte]))}")
     syncController ! BlacklistSupport.BlacklistPeer(peer)
     syncController ! FastSync.EnqueueReceipts(requestedHashes)
     cleanupAndStop()

src/main/scala/io/iohk/ethereum/blockchain/sync/RegularSync.scala

@@ -162,6 +162,7 @@ trait RegularSync {
   }
 
   private def resumeWithDifferentPeer(currentPeer: ActorRef) = {
+    log.info(s"Blacklisting peer (${currentPeer.path.name}), because of error in response")
     self ! BlacklistPeer(currentPeer)
     headersQueue = Seq.empty
     context.self ! ResumeRegularSync

src/main/scala/io/iohk/ethereum/blockchain/sync/SyncBlockBodiesRequestHandler.scala

@@ -5,6 +5,7 @@ import akka.util.ByteString
 import io.iohk.ethereum.blockchain.sync.SyncController.BlockBodiesReceived
 import io.iohk.ethereum.db.storage.AppStateStorage
 import io.iohk.ethereum.network.p2p.messages.PV62.{BlockBodies, GetBlockBodies}
+import org.spongycastle.util.encoders.Hex
 
 class SyncBlockBodiesRequestHandler(
     peer: ActorRef,
@@ -17,6 +18,8 @@ class SyncBlockBodiesRequestHandler(
 
   override def handleResponseMsg(blockBodies: BlockBodies): Unit = {
     if (blockBodies.bodies.isEmpty) {
+      log.info(s"Blacklisting peer (${peer.path.name}), " +
+        s"got empty block bodies response for known hashes: ${requestedHashes.map(h => Hex.toHexString(h.toArray[Byte]))}")
       syncController ! BlacklistSupport.BlacklistPeer(peer)
     } else {
       syncController ! BlockBodiesReceived(peer, requestedHashes, blockBodies.bodies)
@@ -27,6 +30,8 @@ class SyncBlockBodiesRequestHandler(
   }
 
   override def handleTimeout(): Unit = {
+    log.info(s"Blacklisting peer (${peer.path.name}), " +
+      s"time out on block bodies response for known hashes: ${requestedHashes.map(h => Hex.toHexString(h.toArray[Byte]))}")
     syncController ! BlacklistSupport.BlacklistPeer(peer)
     syncController ! FastSync.EnqueueBlockBodies(requestedHashes)
     cleanupAndStop()

src/main/scala/io/iohk/ethereum/blockchain/sync/SyncBlockHeadersRequestHandler.scala

@@ -32,13 +32,15 @@ class SyncBlockHeadersRequestHandler(
         log.info("Received {} block headers in {} ms", headers.size, timeTakenSoFar())
       }
     } else {
+      log.info(s"Blacklisting peer (${peer.path.name}), got error in block headers response for request: $requestMsg")
       syncController ! BlacklistSupport.BlacklistPeer(peer)
     }
 
     cleanupAndStop()
   }
 
   override def handleTimeout(): Unit = {
+    log.info(s"Blacklisting peer (${peer.path.name}), got time out waiting for block headers response for request: $requestMsg")
     syncController ! BlacklistSupport.BlacklistPeer(peer)
     cleanupAndStop()
   }