From 4e95b6e6cbd7f09c25dbba5d0f20c669b1b790f6 Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 09:13:34 +0200 Subject: [PATCH 1/9] Avoid race condition on timer creation in ``GetDataRequestHanler.handle()`` If the timer is created after sending the message and establishing callbacks, they may have already run on timer creation so it would be pointless (and issue a warning when triggered). --- .../peers/getdata/GetDataRequestHandler.java | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java index 8f62f2a605..bb9aebdd8a 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java @@ -66,6 +66,16 @@ public class GetDataRequestHandler { Log.traceCall(getDataRequest + "\n\tconnection=" + connection); GetDataResponse getDataResponse = new GetDataResponse(new HashSet<>(dataStorage.getMap().values()), getDataRequest.getNonce()); + + if (timeoutTimer == null) { // setup before sending to avoid race conditions + timeoutTimer = UserThread.runAfter(() -> { + String errorMessage = "A timeout occurred for getDataResponse:" + getDataResponse + + " on connection:" + connection; + handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, connection); + }, + TIME_OUT_SEC, TimeUnit.SECONDS); + } + SettableFuture future = networkNode.sendMessage(connection, getDataResponse); Futures.addCallback(future, new FutureCallback() { @Override @@ -84,15 +94,6 @@ public class GetDataRequestHandler { handleFault(errorMessage, CloseConnectionReason.SEND_MSG_FAILURE, connection); } }); - - if (timeoutTimer == null) { - timeoutTimer = UserThread.runAfter(() -> { - String errorMessage = "A timeout occurred for getDataResponse:" + getDataResponse + - " on connection:" + connection; - handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, connection); - }, - TIME_OUT_SEC, TimeUnit.SECONDS); - } } /////////////////////////////////////////////////////////////////////////////////////////// From 704b985121fd18a66aa35c54751e574d4fcd88fa Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 09:36:49 +0200 Subject: [PATCH 2/9] Avoid race condition on timer creation in ``PeerExchangeHandler.sendGetPeersRequest()`` If the timer is created after sending the message and establishing callbacks, they may have already run on timer creation so it would be pointless (and issue a warning when triggered). --- .../peerexchange/PeerExchangeHandler.java | 31 ++++++++++--------- 1 file changed, 16 insertions(+), 15 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java index 8cf25d0b77..73cc630f8c 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java @@ -84,6 +84,22 @@ class PeerExchangeHandler implements MessageListener { if (!stopped) { if (networkNode.getNodeAddress() != null) { GetPeersRequest getPeersRequest = new GetPeersRequest(networkNode.getNodeAddress(), nonce, peerManager.getConnectedNonSeedNodeReportedPeers(nodeAddress)); + + if (timeoutTimer == null) { // setup before sending to avoid race conditions + timeoutTimer = UserThread.runAfter(() -> { + if (!stopped) { + String errorMessage = "A timeout occurred at sending getPeersRequest:" + getPeersRequest + " for nodeAddress:" + nodeAddress; + log.info(errorMessage + " / PeerExchangeHandler=" + + PeerExchangeHandler.this); + log.info("timeoutTimer called on " + this); + handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, nodeAddress); + } else { + log.trace("We have stopped that handler already. We ignore that timeoutTimer.run call."); + } + }, + TIME_OUT_SEC, TimeUnit.SECONDS); + } + SettableFuture future = networkNode.sendMessage(nodeAddress, getPeersRequest); Futures.addCallback(future, new FutureCallback() { @Override @@ -116,21 +132,6 @@ class PeerExchangeHandler implements MessageListener { } } }); - - if (timeoutTimer == null) { - timeoutTimer = UserThread.runAfter(() -> { - if (!stopped) { - String errorMessage = "A timeout occurred at sending getPeersRequest:" + getPeersRequest + " for nodeAddress:" + nodeAddress; - log.info(errorMessage + " / PeerExchangeHandler=" + - PeerExchangeHandler.this); - log.info("timeoutTimer called on " + this); - handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, nodeAddress); - } else { - log.trace("We have stopped that handler already. We ignore that timeoutTimer.run call."); - } - }, - TIME_OUT_SEC, TimeUnit.SECONDS); - } } else { log.debug("My node address is still null at sendGetPeersRequest. We ignore that call."); } From b59e3ff0f88ba0dc3a6adb1ff2cd6ee754deb794 Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 09:45:28 +0200 Subject: [PATCH 3/9] Avoid race condition on timer creation in ``GetPeersRequestHandler.handle()`` If the timer is created after sending the message and establishing callbacks, they may have already run on timer creation so it would be pointless (and issue a warning when triggered). --- .../peerexchange/GetPeersRequestHandler.java | 29 ++++++++++--------- 1 file changed, 15 insertions(+), 14 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/GetPeersRequestHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/GetPeersRequestHandler.java index 2d4453b161..426cefe673 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/GetPeersRequestHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/GetPeersRequestHandler.java @@ -70,6 +70,21 @@ class GetPeersRequestHandler { "The peers address must have been already set at the moment"); GetPeersResponse getPeersResponse = new GetPeersResponse(getPeersRequest.nonce, peerManager.getConnectedNonSeedNodeReportedPeers(connection.getPeersNodeAddressOptional().get())); + + checkArgument(timeoutTimer == null, "onGetPeersRequest must not be called twice."); + timeoutTimer = UserThread.runAfter(() -> { // setup before sending to avoid race conditions + if (!stopped) { + String errorMessage = "A timeout occurred at sending getPeersResponse:" + getPeersResponse + " on connection:" + connection; + log.info(errorMessage + " / PeerExchangeHandshake=" + + GetPeersRequestHandler.this); + log.info("timeoutTimer called. this=" + this); + handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, connection); + } else { + log.trace("We have stopped already. We ignore that timeoutTimer.run call."); + } + }, + TIME_OUT_SEC, TimeUnit.SECONDS); + SettableFuture future = networkNode.sendMessage(connection, getPeersResponse); Futures.addCallback(future, new FutureCallback() { @@ -98,20 +113,6 @@ class GetPeersRequestHandler { } }); - checkArgument(timeoutTimer == null, "onGetPeersRequest must not be called twice."); - timeoutTimer = UserThread.runAfter(() -> { - if (!stopped) { - String errorMessage = "A timeout occurred at sending getPeersResponse:" + getPeersResponse + " on connection:" + connection; - log.info(errorMessage + " / PeerExchangeHandshake=" + - GetPeersRequestHandler.this); - log.info("timeoutTimer called. this=" + this); - handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, connection); - } else { - log.trace("We have stopped already. We ignore that timeoutTimer.run call."); - } - }, - TIME_OUT_SEC, TimeUnit.SECONDS); - peerManager.addToReportedPeers(getPeersRequest.reportedPeers, connection); } From c3fa4831c5ac6b415346fb47f2619e03b2b400a9 Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 10:05:17 +0200 Subject: [PATCH 4/9] Avoid race condition on timer creation in ``RequestDataHandler.requestData()`` If the timer is created after sending the message and establishing callbacks, they may have already run on timer creation so it would be pointless (and issue a warning when triggered). --- .../p2p/peers/getdata/RequestDataHandler.java | 30 +++++++++---------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java index 7410d2e4b3..95d7ba448e 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java @@ -90,6 +90,21 @@ public class RequestDataHandler implements MessageListener { log.info("We send a {} to peer {}. ", getDataRequest.getClass().getSimpleName(), nodeAddress); + if (timeoutTimer == null) { // setup before sending to avoid race conditions + timeoutTimer = UserThread.runAfter(() -> { + if (!stopped) { + String errorMessage = "A timeout occurred at sending getDataRequest:" + getDataRequest + + " on nodeAddress:" + nodeAddress; + log.info(errorMessage + " / RequestDataHandler=" + RequestDataHandler.this); + handleFault(errorMessage, nodeAddress, CloseConnectionReason.SEND_MSG_TIMEOUT); + } else { + log.trace("We have stopped already. We ignore that timeoutTimer.run call. " + + "Might be caused by an previous networkNode.sendMessage.onFailure."); + } + }, + TIME_OUT_SEC); + } + SettableFuture future = networkNode.sendMessage(nodeAddress, getDataRequest); Futures.addCallback(future, new FutureCallback() { @Override @@ -119,21 +134,6 @@ public class RequestDataHandler implements MessageListener { } } }); - - if (timeoutTimer == null) { - timeoutTimer = UserThread.runAfter(() -> { - if (!stopped) { - String errorMessage = "A timeout occurred at sending getDataRequest:" + getDataRequest + - " on nodeAddress:" + nodeAddress; - log.info(errorMessage + " / RequestDataHandler=" + RequestDataHandler.this); - handleFault(errorMessage, nodeAddress, CloseConnectionReason.SEND_MSG_TIMEOUT); - } else { - log.trace("We have stopped already. We ignore that timeoutTimer.run call. " + - "Might be caused by an previous networkNode.sendMessage.onFailure."); - } - }, - TIME_OUT_SEC); - } } else { log.warn("We have stopped already. We ignore that requestData call."); } From e4ce976babadc2d0a92b7771ac963af6238bd2d9 Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 10:22:47 +0200 Subject: [PATCH 5/9] Avoid potential race condition on timer creation in ``BroadcastHandler.broadcast()`` If the timer is created after sending the message and establishing callbacks, they may have already run on timer creation so it would be pointless (and issue a warning when triggered). Currently there is no race condition because no callbacks are attached to the futures return by sending broadcast messages, but the timer is still created before in case they were added and for consistency with other classes. --- .../bitsquare/p2p/peers/BroadcastHandler.java | 17 +++++++++-------- 1 file changed, 9 insertions(+), 8 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java index b883aa8a68..abf654b097 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java @@ -116,16 +116,9 @@ public class BroadcastHandler implements PeerManager.Listener { numOfPeers = Math.min(5, connectedPeersList.size()); factor = 2; } - log.info("Broadcast message to {} peers out of {} total connected peers.", numOfPeers, connectedPeersSet.size()); - for (int i = 0; i < numOfPeers; i++) { - final long minDelay = i * 30 * factor + 1; - final long maxDelay = minDelay * 2 + 30 * factor; - final Connection connection = connectedPeersList.get(i); - UserThread.runAfterRandomDelay(() -> sendToPeer(connection, message), minDelay, maxDelay, TimeUnit.MILLISECONDS); - } long timeoutDelay = TIMEOUT_PER_PEER_SEC * numOfPeers; - timeoutTimer = UserThread.runAfter(() -> { + timeoutTimer = UserThread.runAfter(() -> { // setup before sending to avoid race conditions String errorMessage = "Timeout: Broadcast did not complete after " + timeoutDelay + " sec."; log.warn(errorMessage + "\n\t" + @@ -137,6 +130,14 @@ public class BroadcastHandler implements PeerManager.Listener { "broadcastQueue=" + broadcastQueue); onFault(errorMessage); }, timeoutDelay); + + log.info("Broadcast message to {} peers out of {} total connected peers.", numOfPeers, connectedPeersSet.size()); + for (int i = 0; i < numOfPeers; i++) { + final long minDelay = i * 30 * factor + 1; + final long maxDelay = minDelay * 2 + 30 * factor; + final Connection connection = connectedPeersList.get(i); + UserThread.runAfterRandomDelay(() -> sendToPeer(connection, message), minDelay, maxDelay, TimeUnit.MILLISECONDS); + } } else { onFault("Message not broadcasted because we have no available peers yet.\n\t" + "message = " + StringUtils.abbreviate(message.toString(), 100), false); From b814eff5f1336a2576e305f92de8959c24506708 Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 10:23:57 +0200 Subject: [PATCH 6/9] Move log message closer to actual sending --- .../io/bitsquare/p2p/peers/getdata/RequestDataHandler.java | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java index 95d7ba448e..773c2cd347 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java @@ -88,8 +88,6 @@ public class RequestDataHandler implements MessageListener { else getDataRequest = new GetUpdatedDataRequest(networkNode.getNodeAddress(), nonce); - log.info("We send a {} to peer {}. ", getDataRequest.getClass().getSimpleName(), nodeAddress); - if (timeoutTimer == null) { // setup before sending to avoid race conditions timeoutTimer = UserThread.runAfter(() -> { if (!stopped) { @@ -105,6 +103,7 @@ public class RequestDataHandler implements MessageListener { TIME_OUT_SEC); } + log.info("We send a {} to peer {}. ", getDataRequest.getClass().getSimpleName(), nodeAddress); SettableFuture future = networkNode.sendMessage(nodeAddress, getDataRequest); Futures.addCallback(future, new FutureCallback() { @Override From 0d32a3b5ceda8d5664afc72f2a2e98b9403ccc06 Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 10:25:42 +0200 Subject: [PATCH 7/9] Move comment closer to timer creation For consistency across classes. --- .../io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java | 4 ++-- .../io/bitsquare/p2p/peers/getdata/RequestDataHandler.java | 4 ++-- .../bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java | 4 ++-- 3 files changed, 6 insertions(+), 6 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java index bb9aebdd8a..fc76ad3e55 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java @@ -67,8 +67,8 @@ public class GetDataRequestHandler { GetDataResponse getDataResponse = new GetDataResponse(new HashSet<>(dataStorage.getMap().values()), getDataRequest.getNonce()); - if (timeoutTimer == null) { // setup before sending to avoid race conditions - timeoutTimer = UserThread.runAfter(() -> { + if (timeoutTimer == null) { + timeoutTimer = UserThread.runAfter(() -> { // setup before sending to avoid race conditions String errorMessage = "A timeout occurred for getDataResponse:" + getDataResponse + " on connection:" + connection; handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, connection); diff --git a/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java index 773c2cd347..01472b207c 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/getdata/RequestDataHandler.java @@ -88,8 +88,8 @@ public class RequestDataHandler implements MessageListener { else getDataRequest = new GetUpdatedDataRequest(networkNode.getNodeAddress(), nonce); - if (timeoutTimer == null) { // setup before sending to avoid race conditions - timeoutTimer = UserThread.runAfter(() -> { + if (timeoutTimer == null) { + timeoutTimer = UserThread.runAfter(() -> { // setup before sending to avoid race conditions if (!stopped) { String errorMessage = "A timeout occurred at sending getDataRequest:" + getDataRequest + " on nodeAddress:" + nodeAddress; diff --git a/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java index 73cc630f8c..8c2db58afe 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/peerexchange/PeerExchangeHandler.java @@ -85,8 +85,8 @@ class PeerExchangeHandler implements MessageListener { if (networkNode.getNodeAddress() != null) { GetPeersRequest getPeersRequest = new GetPeersRequest(networkNode.getNodeAddress(), nonce, peerManager.getConnectedNonSeedNodeReportedPeers(nodeAddress)); - if (timeoutTimer == null) { // setup before sending to avoid race conditions - timeoutTimer = UserThread.runAfter(() -> { + if (timeoutTimer == null) { + timeoutTimer = UserThread.runAfter(() -> { // setup before sending to avoid race conditions if (!stopped) { String errorMessage = "A timeout occurred at sending getPeersRequest:" + getPeersRequest + " for nodeAddress:" + nodeAddress; log.info(errorMessage + " / PeerExchangeHandler=" + From 00df057e097d6d357306f81530be47cb63ca6a0a Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 10:32:52 +0200 Subject: [PATCH 8/9] Stop broadcasting after a timeout or cancellation --- .../src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java | 2 ++ 1 file changed, 2 insertions(+) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java index abf654b097..544665efd1 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/BroadcastHandler.java @@ -133,6 +133,8 @@ public class BroadcastHandler implements PeerManager.Listener { log.info("Broadcast message to {} peers out of {} total connected peers.", numOfPeers, connectedPeersSet.size()); for (int i = 0; i < numOfPeers; i++) { + if (stopped) + break; // do not continue sending after a timeout or a cancellation final long minDelay = i * 30 * factor + 1; final long maxDelay = minDelay * 2 + 30 * factor; final Connection connection = connectedPeersList.get(i); From 846cdb743f47d2001aaae91043d91640796c68ac Mon Sep 17 00:00:00 2001 From: Ivan Vilata-i-Balaguer Date: Thu, 5 May 2016 10:40:59 +0200 Subject: [PATCH 9/9] Ignore data request message success or failure after a timeout --- .../peers/getdata/GetDataRequestHandler.java | 24 ++++++++++++------- 1 file changed, 16 insertions(+), 8 deletions(-) diff --git a/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java b/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java index fc76ad3e55..451a95bdbd 100644 --- a/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java +++ b/network/src/main/java/io/bitsquare/p2p/peers/getdata/GetDataRequestHandler.java @@ -80,18 +80,26 @@ public class GetDataRequestHandler { Futures.addCallback(future, new FutureCallback() { @Override public void onSuccess(Connection connection) { - log.trace("Send DataResponse to {} succeeded. getDataResponse={}", - connection.getPeersNodeAddressOptional(), getDataResponse); - cleanup(); - listener.onComplete(); + if (!stopped) { + log.trace("Send DataResponse to {} succeeded. getDataResponse={}", + connection.getPeersNodeAddressOptional(), getDataResponse); + cleanup(); + listener.onComplete(); + } else { + log.trace("We have stopped already. We ignore that networkNode.sendMessage.onSuccess call."); + } } @Override public void onFailure(@NotNull Throwable throwable) { - String errorMessage = "Sending getDataRequest to " + connection + - " failed. That is expected if the peer is offline. getDataResponse=" + getDataResponse + "." + - "Exception: " + throwable.getMessage(); - handleFault(errorMessage, CloseConnectionReason.SEND_MSG_FAILURE, connection); + if (!stopped) { + String errorMessage = "Sending getDataRequest to " + connection + + " failed. That is expected if the peer is offline. getDataResponse=" + getDataResponse + "." + + "Exception: " + throwable.getMessage(); + handleFault(errorMessage, CloseConnectionReason.SEND_MSG_FAILURE, connection); + } else { + log.trace("We have stopped already. We ignore that networkNode.sendMessage.onFailure call."); + } } }); }