Add more logging, don't throw exception at timers

This commit is contained in:
Manfred Karrer 2016-02-19 22:21:56 +01:00
parent d506a1acfc
commit 8b1c0e5e6f
9 changed files with 97 additions and 87 deletions

View file

@ -7,9 +7,6 @@ import java.time.Duration;
import java.util.Random; import java.util.Random;
import java.util.TimerTask; import java.util.TimerTask;
import static com.google.common.base.Preconditions.checkArgument;
import static com.google.common.base.Preconditions.checkNotNull;
public class DefaultJavaTimer implements Timer { public class DefaultJavaTimer implements Timer {
private final Logger log = LoggerFactory.getLogger(DefaultJavaTimer.class); private final Logger log = LoggerFactory.getLogger(DefaultJavaTimer.class);
private java.util.Timer timer; private java.util.Timer timer;
@ -20,46 +17,53 @@ public class DefaultJavaTimer implements Timer {
@Override @Override
public Timer runLater(Duration delay, Runnable runnable) { public Timer runLater(Duration delay, Runnable runnable) {
checkArgument(timer == null, "runLater or runPeriodically already called on that timer"); if (timer != null) {
timer = new java.util.Timer(); timer = new java.util.Timer();
timer.schedule(new TimerTask() { timer.schedule(new TimerTask() {
@Override @Override
public void run() { public void run() {
Thread.currentThread().setName("TimerTask-" + new Random().nextInt(10000)); Thread.currentThread().setName("TimerTask-" + new Random().nextInt(10000));
try { try {
UserThread.execute(runnable::run); UserThread.execute(runnable::run);
} catch (Throwable t) { } catch (Throwable t) {
t.printStackTrace(); t.printStackTrace();
log.error("Executing timerTask failed. " + t.getMessage()); log.error("Executing timerTask failed. " + t.getMessage());
}
} }
} }, delay.toMillis());
}, delay.toMillis()); } else {
log.warn("runLater called on an already running timer.");
}
return this; return this;
} }
@Override @Override
public Timer runPeriodically(java.time.Duration interval, Runnable runnable) { public Timer runPeriodically(java.time.Duration interval, Runnable runnable) {
checkArgument(timer == null, "runLater or runPeriodically already called on that timer"); if (timer != null) {
timer = new java.util.Timer(); timer = new java.util.Timer();
timer.scheduleAtFixedRate(new TimerTask() { timer.scheduleAtFixedRate(new TimerTask() {
@Override @Override
public void run() { public void run() {
Thread.currentThread().setName("TimerTask-" + new Random().nextInt(10000)); Thread.currentThread().setName("TimerTask-" + new Random().nextInt(10000));
try { try {
UserThread.execute(runnable::run); UserThread.execute(runnable::run);
} catch (Throwable t) { } catch (Throwable t) {
t.printStackTrace(); t.printStackTrace();
log.error("Executing timerTask failed. " + t.getMessage()); log.error("Executing timerTask failed. " + t.getMessage());
}
} }
} }, interval.toMillis(), interval.toMillis());
}, interval.toMillis(), interval.toMillis()); } else {
log.warn("runLater called on an already running timer.");
}
return this; return this;
} }
@Override @Override
public void stop() { public void stop() {
checkNotNull(timer, "Timer must not be null"); if (timer != null) {
timer.cancel(); timer.cancel();
timer = null; timer = null;
}
} }
} }

View file

@ -61,8 +61,6 @@ import static io.bitsquare.util.Validator.nonEmptyStringOf;
public class OpenOfferManager { public class OpenOfferManager {
private static final Logger log = LoggerFactory.getLogger(OpenOfferManager.class); private static final Logger log = LoggerFactory.getLogger(OpenOfferManager.class);
private static final int MAX_MSG_SIZE = 100 * 1024;
private final KeyRing keyRing; private final KeyRing keyRing;
private final User user; private final User user;
private final P2PService p2PService; private final P2PService p2PService;
@ -205,6 +203,7 @@ public class OpenOfferManager {
//republishOffers(); //republishOffers();
// run again after 5 sec as it might be that the app needs a bit for getting all re-animated again // run again after 5 sec as it might be that the app needs a bit for getting all re-animated again
log.error("We got re-connected again after loss of all connection. We re-publish our offers now.");
republishOffersTimer = UserThread.runAfter(OpenOfferManager.this::republishOffers, 5); republishOffersTimer = UserThread.runAfter(OpenOfferManager.this::republishOffers, 5);
} }
} }
@ -212,8 +211,10 @@ public class OpenOfferManager {
@Override @Override
public void onDisconnect(CloseConnectionReason closeConnectionReason, Connection connection) { public void onDisconnect(CloseConnectionReason closeConnectionReason, Connection connection) {
lostAllConnections = networkNode.getAllConnections().isEmpty(); lostAllConnections = networkNode.getAllConnections().isEmpty();
if (lostAllConnections) if (lostAllConnections) {
allowRefreshOffers = false; allowRefreshOffers = false;
log.error("We got disconnected from all peers");
}
} }
@Override @Override

View file

@ -7,9 +7,6 @@ import org.slf4j.LoggerFactory;
import java.time.Duration; import java.time.Duration;
import static com.google.common.base.Preconditions.checkArgument;
import static com.google.common.base.Preconditions.checkNotNull;
public class UITimer implements Timer { public class UITimer implements Timer {
private final Logger log = LoggerFactory.getLogger(UITimer.class); private final Logger log = LoggerFactory.getLogger(UITimer.class);
private org.reactfx.util.Timer timer; private org.reactfx.util.Timer timer;
@ -19,24 +16,31 @@ public class UITimer implements Timer {
@Override @Override
public Timer runLater(Duration delay, Runnable runnable) { public Timer runLater(Duration delay, Runnable runnable) {
checkArgument(timer == null, "runLater or runPeriodically already called on that timer"); if (timer != null) {
timer = FxTimer.create(delay, runnable); timer = FxTimer.create(delay, runnable);
timer.restart(); timer.restart();
} else {
log.warn("runLater called on an already running timer.");
}
return this; return this;
} }
@Override @Override
public Timer runPeriodically(Duration interval, Runnable runnable) { public Timer runPeriodically(Duration interval, Runnable runnable) {
checkArgument(timer == null, "runLater or runPeriodically already called on that timer"); if (timer != null) {
timer = FxTimer.createPeriodic(interval, runnable); timer = FxTimer.createPeriodic(interval, runnable);
timer.restart(); timer.restart();
} else {
log.warn("runPeriodically called on an already running timer.");
}
return this; return this;
} }
@Override @Override
public void stop() { public void stop() {
checkNotNull(timer, "Timer must not be null"); if (timer != null) {
timer.stop(); timer.stop();
timer = null; timer = null;
}
} }
} }

View file

@ -54,7 +54,6 @@ public class OfferBook {
offerBookService.addOfferBookChangedListener(new OfferBookService.OfferBookChangedListener() { offerBookService.addOfferBookChangedListener(new OfferBookService.OfferBookChangedListener() {
@Override @Override
public void onAdded(Offer offer) { public void onAdded(Offer offer) {
log.debug("onAdded " + offer);
OfferBookListItem offerBookListItem = new OfferBookListItem(offer); OfferBookListItem offerBookListItem = new OfferBookListItem(offer);
if (!offerBookListItems.contains(offerBookListItem)) if (!offerBookListItems.contains(offerBookListItem))
offerBookListItems.add(offerBookListItem); offerBookListItems.add(offerBookListItem);
@ -62,7 +61,6 @@ public class OfferBook {
@Override @Override
public void onRemoved(Offer offer) { public void onRemoved(Offer offer) {
log.debug("onRemoved " + offer);
// Update state in case that that offer is used in the take offer screen, so it gets updated correctly // Update state in case that that offer is used in the take offer screen, so it gets updated correctly
offer.setState(Offer.State.REMOVED); offer.setState(Offer.State.REMOVED);

View file

@ -61,7 +61,7 @@ public class Connection implements MessageListener {
private static final int MSG_THROTTLE_PER_10SEC = 50; // With MAX_MSG_SIZE of 100kb results in bandwidth of 5 mbit/sec for 10 sec private static final int MSG_THROTTLE_PER_10SEC = 50; // With MAX_MSG_SIZE of 100kb results in bandwidth of 5 mbit/sec for 10 sec
// private static final int SOCKET_TIMEOUT = (int) TimeUnit.SECONDS.toMillis(60); // private static final int SOCKET_TIMEOUT = (int) TimeUnit.SECONDS.toMillis(60);
//TODO //TODO
private static final int SOCKET_TIMEOUT = (int) TimeUnit.SECONDS.toMillis(10); private static final int SOCKET_TIMEOUT = (int) TimeUnit.SECONDS.toMillis(30);
public static int getMaxMsgSize() { public static int getMaxMsgSize() {
return MAX_MSG_SIZE; return MAX_MSG_SIZE;

View file

@ -46,7 +46,7 @@ public class PeerManager implements ConnectionListener, MessageListener {
} }
static { static {
setMaxConnections(12); setMaxConnections(1);
} }
private static final int MAX_REPORTED_PEERS = 1000; private static final int MAX_REPORTED_PEERS = 1000;

View file

@ -120,7 +120,7 @@ public class RequestDataHandshake implements MessageListener {
shutDown(); shutDown();
listener.onFault(errorMessage, null); listener.onFault(errorMessage, null);
}, },
10, TimeUnit.SECONDS); 10);
} }
public void onDataRequest(Message message, final Connection connection) { public void onDataRequest(Message message, final Connection connection) {

View file

@ -24,7 +24,6 @@ import java.util.Random;
import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeUnit;
import static com.google.common.base.Preconditions.checkArgument; import static com.google.common.base.Preconditions.checkArgument;
import static com.google.common.base.Preconditions.checkNotNull;
class PeerExchangeHandler implements MessageListener { class PeerExchangeHandler implements MessageListener {
private static final Logger log = LoggerFactory.getLogger(PeerExchangeHandler.class); private static final Logger log = LoggerFactory.getLogger(PeerExchangeHandler.class);
@ -82,42 +81,44 @@ class PeerExchangeHandler implements MessageListener {
public void sendGetPeersRequest(NodeAddress nodeAddress) { public void sendGetPeersRequest(NodeAddress nodeAddress) {
Log.traceCall("nodeAddress=" + nodeAddress + " / this=" + this); Log.traceCall("nodeAddress=" + nodeAddress + " / this=" + this);
checkNotNull(networkNode.getNodeAddress(), "PeerExchangeHandler.requestReportedPeers: My node address must " + if (networkNode.getNodeAddress() != null) {
"not be null at requestReportedPeers"); GetPeersRequest getPeersRequest = new GetPeersRequest(networkNode.getNodeAddress(), nonce, peerManager.getConnectedPeersNonSeedNodes(nodeAddress));
GetPeersRequest getPeersRequest = new GetPeersRequest(networkNode.getNodeAddress(), nonce, peerManager.getConnectedPeersNonSeedNodes(nodeAddress)); SettableFuture<Connection> future = networkNode.sendMessage(nodeAddress, getPeersRequest);
SettableFuture<Connection> future = networkNode.sendMessage(nodeAddress, getPeersRequest); Futures.addCallback(future, new FutureCallback<Connection>() {
Futures.addCallback(future, new FutureCallback<Connection>() { @Override
@Override public void onSuccess(Connection connection) {
public void onSuccess(Connection connection) { if (!connection.getPeersNodeAddressOptional().isPresent()) {
if (!connection.getPeersNodeAddressOptional().isPresent()) { connection.setPeersNodeAddress(nodeAddress);
connection.setPeersNodeAddress(nodeAddress); //TODO remove setPeersNodeAddress if never needed
//TODO remove setPeersNodeAddress if never needed log.warn("sendGetPeersRequest: !connection.getPeersNodeAddressOptional().isPresent()");
log.warn("sendGetPeersRequest: !connection.getPeersNodeAddressOptional().isPresent()"); }
PeerExchangeHandler.this.connection = connection;
connection.addMessageListener(PeerExchangeHandler.this);
log.trace("Send " + getPeersRequest + " to " + nodeAddress + " succeeded.");
} }
PeerExchangeHandler.this.connection = connection;
connection.addMessageListener(PeerExchangeHandler.this);
log.trace("Send " + getPeersRequest + " to " + nodeAddress + " succeeded.");
}
@Override @Override
public void onFailure(@NotNull Throwable throwable) { public void onFailure(@NotNull Throwable throwable) {
String errorMessage = "Sending getPeersRequest to " + nodeAddress + String errorMessage = "Sending getPeersRequest to " + nodeAddress +
" failed. That is expected if the peer is offline.\n\tgetPeersRequest=" + getPeersRequest + " failed. That is expected if the peer is offline.\n\tgetPeersRequest=" + getPeersRequest +
".\n\tException=" + throwable.getMessage(); ".\n\tException=" + throwable.getMessage();
log.info(errorMessage); log.info(errorMessage);
handleFault(errorMessage, CloseConnectionReason.SEND_MSG_FAILURE, nodeAddress); handleFault(errorMessage, CloseConnectionReason.SEND_MSG_FAILURE, nodeAddress);
} }
}); });
checkArgument(timeoutTimer == null, "requestReportedPeers must not be called twice."); checkArgument(timeoutTimer == null, "requestReportedPeers must not be called twice.");
timeoutTimer = UserThread.runAfter(() -> { timeoutTimer = UserThread.runAfter(() -> {
String errorMessage = "A timeout occurred at sending getPeersRequest:" + getPeersRequest + " for nodeAddress:" + nodeAddress; String errorMessage = "A timeout occurred at sending getPeersRequest:" + getPeersRequest + " for nodeAddress:" + nodeAddress;
log.info(errorMessage + " / PeerExchangeHandler=" + log.info(errorMessage + " / PeerExchangeHandler=" +
PeerExchangeHandler.this); PeerExchangeHandler.this);
log.info("timeoutTimer called on " + this); log.info("timeoutTimer called on " + this);
handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, nodeAddress); handleFault(errorMessage, CloseConnectionReason.SEND_MSG_TIMEOUT, nodeAddress);
}, },
TIME_OUT_SEC, TimeUnit.SECONDS); TIME_OUT_SEC, TimeUnit.SECONDS);
} else {
log.trace("My node address is still null at sendGetPeersRequest. We ignore that call.");
}
} }
/////////////////////////////////////////////////////////////////////////////////////////// ///////////////////////////////////////////////////////////////////////////////////////////

View file

@ -82,7 +82,9 @@ public class P2PDataStorage implements MessageListener, ConnectionListener {
.filter(entry -> entry.getValue().isExpired()) .filter(entry -> entry.getValue().isExpired())
.forEach(entry -> { .forEach(entry -> {
ByteArray hashOfPayload = entry.getKey(); ByteArray hashOfPayload = entry.getKey();
toRemoveSet.add(map.get(hashOfPayload)); ProtectedData protectedData = map.get(hashOfPayload);
toRemoveSet.add(protectedData);
log.trace("remove protectedData:\n\t" + protectedData);
map.remove(hashOfPayload); map.remove(hashOfPayload);
}); });