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); }
/** * 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"); } }