private void finishDisconnect(final Message m, final PeerNode source) {
source.disconnected(true, true);
// If true, remove from active routing table, likely to be down for a while.
// Otherwise just dump all current connection state and keep trying to connect.
boolean remove = m.getBoolean(DMT.REMOVE);
if (remove) node.peers.disconnect(source, false, false, false);
// If true, purge all references to this node. Otherwise, we can keep the node
// around in secondary tables etc in order to more easily reconnect later.
// (Mostly used on opennet)
boolean purge = m.getBoolean(DMT.PURGE);
if (purge) {
OpennetManager om = node.getOpennet();
if (om != null) om.purgeOldOpennetPeer(source);
}
// Process parting message
int type = m.getInt(DMT.NODE_TO_NODE_MESSAGE_TYPE);
ShortBuffer messageData = (ShortBuffer) m.getObject(DMT.NODE_TO_NODE_MESSAGE_DATA);
if (messageData.getLength() == 0) return;
node.receivedNodeToNodeMessage(source, type, messageData, true);
}
void realRun() {
ChosenBlock req = null;
// The last time at which we sent a request or decided not to
long cycleTime = System.currentTimeMillis();
while (true) {
// Allow 5 minutes before we start killing requests due to not connecting.
OpennetManager om;
if (core.node.peers.countConnectedPeers() < 3
&& (om = core.node.getOpennet()) != null
&& System.currentTimeMillis() - om.getCreationTime() < 5 * 60 * 1000) {
try {
synchronized (this) {
wait(1000);
}
} catch (InterruptedException e) {
// TODO Auto-generated catch block
e.printStackTrace();
}
continue;
}
if (req == null) {
req = sched.grabRequest();
}
if (req != null) {
if (logMINOR) Logger.minor(this, "Running " + req + " priority " + req.getPriority());
if (!req.localRequestOnly) {
// Wait
long delay;
delay = throttle.getDelay();
if (logMINOR) Logger.minor(this, "Delay=" + delay + " from " + throttle);
long sleepUntil = cycleTime + delay;
if (!LOCAL_REQUESTS_COMPETE_FAIRLY) {
inputBucket.blockingGrab(
(int) (Math.max(0, averageInputBytesPerRequest.currentValue())));
outputBucket.blockingGrab(
(int) (Math.max(0, averageOutputBytesPerRequest.currentValue())));
}
long now;
do {
now = System.currentTimeMillis();
if (now < sleepUntil)
try {
Thread.sleep(sleepUntil - now);
if (logMINOR) Logger.minor(this, "Slept: " + (sleepUntil - now) + "ms");
} catch (InterruptedException e) {
// Ignore
}
} while (now < sleepUntil);
}
// if(!doAIMD) {
// // Arbitrary limit on number of local requests waiting for slots.
// // Firstly, they use threads. This could be a serious problem for faster nodes.
// // Secondly, it may help to prevent wider problems:
// // If all queues are full, the network will die.
// int[] waiting = core.node.countRequestsWaitingForSlots();
// int localRequestsWaitingForSlots = waiting[0];
// int maxWaitingForSlots = MAX_WAITING_FOR_SLOTS;
// // FIXME calibrate this by the number of local timeouts.
// // FIXME consider an AIMD, or some similar mechanism.
// // Local timeout-waiting-for-slots is largely dependant on
// // the number of requests running, due to strict round-robin,
// // so we can probably do something even simpler than an AIMD.
// // For now we'll just have a fixed number.
// // This should partially address the problem.
// // Note that while waitFor() is blocking, we need such a limit anyway.
// if(localRequestsWaitingForSlots > maxWaitingForSlots) continue;
// }
RejectReason reason;
assert (req.realTimeFlag == realTime);
if (LOCAL_REQUESTS_COMPETE_FAIRLY && !req.localRequestOnly) {
if ((reason =
stats.shouldRejectRequest(
true,
isInsert,
isSSK,
true,
false,
null,
false,
isInsert && Node.PREFER_INSERT_DEFAULT,
req.realTimeFlag,
null))
!= null) {
if (logMINOR) Logger.minor(this, "Not sending local request: " + reason);
// Wait one throttle-delay before trying again
cycleTime = System.currentTimeMillis();
continue; // Let local requests compete with all the others
}
} else {
stats.waitUntilNotOverloaded(isInsert);
}
} else {
if (logMINOR) Logger.minor(this, "Waiting...");
// Always take the lock on RequestStarter first. AFAICS we don't synchronize on
// RequestStarter anywhere else.
// Nested locks here prevent extra latency when there is a race, and therefore allow us to
// sleep indefinitely
synchronized (this) {
req = sched.grabRequest();
if (req == null) {
try {
wait(
1
* 1000); // this can happen when most but not all stuff is already running but
// there is still stuff to fetch, so don't wait *too* long.
// FIXME increase when we can be *sure* there is nothing left in the queue (especially
// for transient requests).
} catch (InterruptedException e) {
// Ignore
}
}
}
}
if (req == null) continue;
if (!startRequest(req, logMINOR)) {
// Don't log if it's a cancelled transient request.
if (!((!req.isPersistent()) && req.isCancelled()))
Logger.normal(this, "No requests to start on " + req);
}
if (!req.localRequestOnly) cycleTime = System.currentTimeMillis();
req = null;
}
}
/**
* Send loop. Strategy: - Each peer can tell us when its data needs to be sent by. This is usually
* 100ms after it is posted. It could vary by message type. Acknowledgements also become valid
* 100ms after being queued. - If any peer's data is overdue, send the data from the most overdue
* peer. - If there are peers with more than a packet's worth of data queued, send the data from
* the peer with the oldest data. - If there are peers with overdue ack's, send to the peer whose
* acks are oldest.
*
* <p>It does not attempt to ensure fairness, it attempts to minimise latency. Fairness is best
* dealt with at a higher level e.g. requests, although some transfers are not part of requests,
* e.g. bulk f2f transfers, so we may need to reconsider this eventually...
*/
private void realRun() {
long now = System.currentTimeMillis();
PeerManager pm;
PeerNode[] nodes;
pm = node.peers;
nodes = pm.myPeers();
long nextActionTime = Long.MAX_VALUE;
long oldTempNow = now;
boolean canSendThrottled = false;
int MAX_PACKET_SIZE = node.darknetCrypto.socket.getMaxPacketSize();
long count = node.outputThrottle.getCount();
if (count > MAX_PACKET_SIZE) canSendThrottled = true;
else {
long canSendAt = node.outputThrottle.getNanosPerTick() * (MAX_PACKET_SIZE - count);
canSendAt = MILLISECONDS.convert(canSendAt + MILLISECONDS.toNanos(1) - 1, NANOSECONDS);
if (logMINOR) Logger.minor(this, "Can send throttled packets in " + canSendAt + "ms");
nextActionTime = Math.min(nextActionTime, now + canSendAt);
}
/**
* The earliest time at which a peer needs to send a packet, which is before now. Throttled if
* canSendThrottled, otherwise not throttled. Note: we only use it to sort the full-packed peers
* by priority, don't rely on it when setting nextActionTime!
*/
long lowestUrgentSendTime = Long.MAX_VALUE;
/** The peer(s) which lowestUrgentSendTime is referring to */
ArrayList<PeerNode> urgentSendPeers = null;
/**
* The earliest time at which a peer needs to send a packet, which is after now, where there is
* a full packet's worth of data to send. Throttled if canSendThrottled, otherwise not
* throttled.
*/
long lowestFullPacketSendTime = Long.MAX_VALUE;
/** The peer(s) which lowestFullPacketSendTime is referring to */
ArrayList<PeerNode> urgentFullPacketPeers = null;
/** The earliest time at which a peer needs to send an ack, before now. */
long lowestAckTime = Long.MAX_VALUE;
/** The peer(s) which lowestAckTime is referring to */
ArrayList<PeerNode> ackPeers = null;
/** The earliest time at which a peer needs to handshake. */
long lowestHandshakeTime = Long.MAX_VALUE;
/** The peer(s) which lowestHandshakeTime is referring to */
ArrayList<PeerNode> handshakePeers = null;
for (PeerNode pn : nodes) {
now = System.currentTimeMillis();
// Basic peer maintenance.
// For purposes of detecting not having received anything, which indicates a
// serious connectivity problem, we want to look for *any* packets received,
// including auth packets.
lastReceivedPacketFromAnyNode =
Math.max(pn.lastReceivedPacketTime(), lastReceivedPacketFromAnyNode);
pn.maybeOnConnect();
if (pn.shouldDisconnectAndRemoveNow() && !pn.isDisconnecting()) {
// Might as well do it properly.
node.peers.disconnectAndRemove(pn, true, true, false);
}
if (pn.isConnected()) {
boolean shouldThrottle = pn.shouldThrottle();
pn.checkForLostPackets();
// Is the node dead?
// It might be disconnected in terms of FNP but trying to reconnect via JFK's, so we need to
// use the time when we last got a *data* packet.
if (now - pn.lastReceivedDataPacketTime() > pn.maxTimeBetweenReceivedPackets()) {
Logger.normal(this, "Disconnecting from " + pn + " - haven't received packets recently");
// Hopefully this is a transient network glitch, but stuff will have already started to
// timeout, so lets dump the pending messages.
pn.disconnected(true, false);
continue;
} else if (now - pn.lastReceivedAckTime() > pn.maxTimeBetweenReceivedAcks()
&& !pn.isDisconnecting()) {
// FIXME better to disconnect immediately??? Or check canSend()???
Logger.normal(this, "Disconnecting from " + pn + " - haven't received acks recently");
// Do it properly.
// There appears to be connectivity from them to us but not from us to them.
// So it is helpful for them to know that we are disconnecting.
node.peers.disconnect(pn, true, true, false, true, false, SECONDS.toMillis(5));
continue;
} else if (pn.isRoutable() && pn.noLongerRoutable()) {
/*
NOTE: Whereas isRoutable() && noLongerRoutable() are generally mutually exclusive, this
code will only execute because of the scheduled-runnable in start() which executes
updateVersionRoutablity() on all our peers. We don't disconnect the peer, but mark it
as being incompatible.
*/
pn.invalidate(now);
Logger.normal(
this,
"shouldDisconnectNow has returned true : marking the peer as incompatible: " + pn);
continue;
}
// The peer is connected.
if (canSendThrottled || !shouldThrottle) {
// We can send to this peer.
long sendTime = pn.getNextUrgentTime(now);
if (sendTime != Long.MAX_VALUE) {
if (sendTime <= now) {
// Message is urgent.
if (sendTime < lowestUrgentSendTime) {
lowestUrgentSendTime = sendTime;
if (urgentSendPeers != null) urgentSendPeers.clear();
else urgentSendPeers = new ArrayList<PeerNode>();
}
if (sendTime <= lowestUrgentSendTime) urgentSendPeers.add(pn);
} else if (pn.fullPacketQueued()) {
if (sendTime < lowestFullPacketSendTime) {
lowestFullPacketSendTime = sendTime;
if (urgentFullPacketPeers != null) urgentFullPacketPeers.clear();
else urgentFullPacketPeers = new ArrayList<PeerNode>();
}
if (sendTime <= lowestFullPacketSendTime) urgentFullPacketPeers.add(pn);
}
}
} else if (shouldThrottle && !canSendThrottled) {
long ackTime = pn.timeSendAcks();
if (ackTime != Long.MAX_VALUE) {
if (ackTime <= now) {
if (ackTime < lowestAckTime) {
lowestAckTime = ackTime;
if (ackPeers != null) ackPeers.clear();
else ackPeers = new ArrayList<PeerNode>();
}
if (ackTime <= lowestAckTime) ackPeers.add(pn);
}
}
}
if (canSendThrottled || !shouldThrottle) {
long urgentTime = pn.getNextUrgentTime(now);
// Should spam the logs, unless there is a deadlock
if (urgentTime < Long.MAX_VALUE && logMINOR)
Logger.minor(
this,
"Next urgent time: " + urgentTime + "(in " + (urgentTime - now) + ") for " + pn);
nextActionTime = Math.min(nextActionTime, urgentTime);
} else {
nextActionTime = Math.min(nextActionTime, pn.timeCheckForLostPackets());
}
} else
// Not connected
if (pn.noContactDetails()) pn.startARKFetcher();
long handshakeTime = pn.timeSendHandshake(now);
if (handshakeTime != Long.MAX_VALUE) {
if (handshakeTime < lowestHandshakeTime) {
lowestHandshakeTime = handshakeTime;
if (handshakePeers != null) handshakePeers.clear();
else handshakePeers = new ArrayList<PeerNode>();
}
if (handshakeTime <= lowestHandshakeTime) handshakePeers.add(pn);
}
long tempNow = System.currentTimeMillis();
if ((tempNow - oldTempNow) > SECONDS.toMillis(5))
Logger.error(
this,
"tempNow is more than 5 seconds past oldTempNow ("
+ (tempNow - oldTempNow)
+ ") in PacketSender working with "
+ pn.userToString());
oldTempNow = tempNow;
}
// We may send a packet, send an ack-only packet, or send a handshake.
PeerNode toSendPacket = null;
PeerNode toSendAckOnly = null;
PeerNode toSendHandshake = null;
long t = Long.MAX_VALUE;
if (lowestUrgentSendTime <= now) {
// We need to send a full packet.
toSendPacket = urgentSendPeers.get(localRandom.nextInt(urgentSendPeers.size()));
t = lowestUrgentSendTime;
} else if (lowestFullPacketSendTime < Long.MAX_VALUE) {
toSendPacket = urgentFullPacketPeers.get(localRandom.nextInt(urgentFullPacketPeers.size()));
t = lowestFullPacketSendTime;
} else if (lowestAckTime <= now) {
// We need to send an ack
toSendAckOnly = ackPeers.get(localRandom.nextInt(ackPeers.size()));
t = lowestAckTime;
}
if (lowestHandshakeTime <= now && t > lowestHandshakeTime) {
toSendHandshake = handshakePeers.get(localRandom.nextInt(handshakePeers.size()));
toSendPacket = null;
toSendAckOnly = null;
}
if (toSendPacket != null) {
try {
if (toSendPacket.maybeSendPacket(now, false)) {
// Round-robin over the loop to update nextActionTime appropriately
nextActionTime = now;
}
} catch (BlockedTooLongException e) {
Logger.error(
this,
"Waited too long: "
+ TimeUtil.formatTime(e.delta)
+ " to allocate a packet number to send to "
+ toSendPacket
+ " : "
+ ("(new packet format)")
+ " (version "
+ toSendPacket.getVersionNumber()
+ ") - DISCONNECTING!");
toSendPacket.forceDisconnect();
}
if (canSendThrottled || !toSendPacket.shouldThrottle()) {
long urgentTime = toSendPacket.getNextUrgentTime(now);
// Should spam the logs, unless there is a deadlock
if (urgentTime < Long.MAX_VALUE && logMINOR)
Logger.minor(
this,
"Next urgent time: "
+ urgentTime
+ "(in "
+ (urgentTime - now)
+ ") for "
+ toSendPacket);
nextActionTime = Math.min(nextActionTime, urgentTime);
} else {
nextActionTime = Math.min(nextActionTime, toSendPacket.timeCheckForLostPackets());
}
} else if (toSendAckOnly != null) {
try {
if (toSendAckOnly.maybeSendPacket(now, true)) {
count = node.outputThrottle.getCount();
if (count > MAX_PACKET_SIZE) canSendThrottled = true;
else {
canSendThrottled = false;
long canSendAt = node.outputThrottle.getNanosPerTick() * (MAX_PACKET_SIZE - count);
canSendAt = MILLISECONDS.convert(canSendAt + MILLISECONDS.toNanos(1) - 1, NANOSECONDS);
if (logMINOR) Logger.minor(this, "Can send throttled packets in " + canSendAt + "ms");
nextActionTime = Math.min(nextActionTime, now + canSendAt);
}
}
} catch (BlockedTooLongException e) {
Logger.error(
this,
"Waited too long: "
+ TimeUtil.formatTime(e.delta)
+ " to allocate a packet number to send to "
+ toSendAckOnly
+ " : "
+ ("(new packet format)")
+ " (version "
+ toSendAckOnly.getVersionNumber()
+ ") - DISCONNECTING!");
toSendAckOnly.forceDisconnect();
}
if (canSendThrottled || !toSendAckOnly.shouldThrottle()) {
long urgentTime = toSendAckOnly.getNextUrgentTime(now);
// Should spam the logs, unless there is a deadlock
if (urgentTime < Long.MAX_VALUE && logMINOR)
Logger.minor(
this,
"Next urgent time: "
+ urgentTime
+ "(in "
+ (urgentTime - now)
+ ") for "
+ toSendAckOnly);
nextActionTime = Math.min(nextActionTime, urgentTime);
} else {
nextActionTime = Math.min(nextActionTime, toSendAckOnly.timeCheckForLostPackets());
}
}
/* Estimating of nextActionTime logic:
* FullPackets:
* - A full packet available, bandwidth available -->> now
* - A full packet available for non-throttled peer -->> now
* - A full packet available, no bandwidth -->> wait till bandwidth available
* - No packet -->> don't care, will wake up anyway when one arrives, goto Nothing
* UrgentMessages: Only applies when there's enough bandwidth to send a full packet, Includes any urgent acks
* - There's an urgent message, deadline(urgentMessage) > now -->> deadline(urgentMessage)
* - There's an urgent message, deadline(urgentMessage) <= now -->> now
* - There's an urgent message, but there's not enough bandwidth for a full packet -->> wait till bandwidth available
* - There's no urgent message -->> don't care, goto Nothing
* Nothing:
* -->> timeCheckForLostPackets
*/
if (toSendHandshake != null) {
// Send handshake if necessary
long beforeHandshakeTime = System.currentTimeMillis();
toSendHandshake.getOutgoingMangler().sendHandshake(toSendHandshake, false);
long afterHandshakeTime = System.currentTimeMillis();
if ((afterHandshakeTime - beforeHandshakeTime) > SECONDS.toMillis(2))
Logger.error(
this,
"afterHandshakeTime is more than 2 seconds past beforeHandshakeTime ("
+ (afterHandshakeTime - beforeHandshakeTime)
+ ") in PacketSender working with "
+ toSendHandshake.userToString());
}
// All of these take into account whether the data can be sent already.
// So we can include them in nextActionTime.
nextActionTime = Math.min(nextActionTime, lowestUrgentSendTime);
nextActionTime = Math.min(nextActionTime, lowestFullPacketSendTime);
nextActionTime = Math.min(nextActionTime, lowestAckTime);
nextActionTime = Math.min(nextActionTime, lowestHandshakeTime);
// FIXME: If we send something we will have to go around the loop again.
// OPTIMISATION: We could track the second best, and check how many are in the array.
/* Attempt to connect to old-opennet-peers.
* Constantly send handshake packets, in order to get through a NAT.
* Most JFK(1)'s are less than 300 bytes. 25*300/15 = avg 500B/sec bandwidth cost.
* Well worth it to allow us to reconnect more quickly. */
OpennetManager om = node.getOpennet();
if (om != null && node.getUptime() > SECONDS.toMillis(30)) {
PeerNode[] peers = om.getOldPeers();
for (PeerNode pn : peers) {
long lastConnected = pn.timeLastConnected(now);
if (lastConnected <= 0)
Logger.error(this, "Last connected is zero or negative for old-opennet-peer " + pn);
// Will be removed by next line.
if (now - lastConnected > OpennetManager.MAX_TIME_ON_OLD_OPENNET_PEERS) {
om.purgeOldOpennetPeer(pn);
if (logMINOR)
Logger.minor(
this,
"Removing old opennet peer (too old): "
+ pn
+ " age is "
+ TimeUtil.formatTime(now - lastConnected));
continue;
}
if (pn.isConnected()) continue; // Race condition??
if (pn.noContactDetails()) {
pn.startARKFetcher();
continue;
}
if (pn.shouldSendHandshake()) {
// Send handshake if necessary
long beforeHandshakeTime = System.currentTimeMillis();
pn.getOutgoingMangler().sendHandshake(pn, true);
long afterHandshakeTime = System.currentTimeMillis();
if ((afterHandshakeTime - beforeHandshakeTime) > SECONDS.toMillis(2))
Logger.error(
this,
"afterHandshakeTime is more than 2 seconds past beforeHandshakeTime ("
+ (afterHandshakeTime - beforeHandshakeTime)
+ ") in PacketSender working with "
+ pn.userToString());
}
}
}
long oldNow = now;
// Send may have taken some time
now = System.currentTimeMillis();
if ((now - oldNow) > SECONDS.toMillis(10))
Logger.error(
this, "now is more than 10 seconds past oldNow (" + (now - oldNow) + ") in PacketSender");
long sleepTime = nextActionTime - now;
// MAX_COALESCING_DELAYms maximum sleep time - same as the maximum coalescing delay
sleepTime = Math.min(sleepTime, MAX_COALESCING_DELAY);
if (now - node.startupTime > MINUTES.toMillis(5))
if (now - lastReceivedPacketFromAnyNode > Node.ALARM_TIME) {
Logger.error(
this,
"Have not received any packets from any node in last "
+ SECONDS.convert(Node.ALARM_TIME, MILLISECONDS)
+ " seconds");
lastReportedNoPackets = now;
}
if (sleepTime > 0) {
// Update logging only when have time to do so
try {
if (logMINOR) Logger.minor(this, "Sleeping for " + sleepTime);
synchronized (this) {
wait(sleepTime);
}
} catch (InterruptedException e) {
// Ignore, just wake up. Probably we got interrupt()ed
// because a new packet came in.
}
} else {
if (logDEBUG)
Logger.debug(this, "Next urgent time is " + (now - nextActionTime) + "ms in the past");
}
}