@Override public SendableRequestItem chooseKey( KeysFetchingLocally fetching, ObjectContainer container, ClientContext context) { if (persistent) container.activate(key, 5); Key k = key.getNodeKey(false); if (fetching.hasKey(k, this, persistent, container)) return null; long l = fetching.checkRecentlyFailed(k, realTimeFlag); long now = System.currentTimeMillis(); if (l > 0 && l > now) { if (maxRetries == -1 || (maxRetries >= RequestScheduler.COOLDOWN_RETRIES)) { // FIXME synchronization!!! if (logMINOR) Logger.minor( this, "RecentlyFailed -> cooldown until " + TimeUtil.formatTime(l - now) + " on " + this); MyCooldownTrackerItem tracker = makeCooldownTrackerItem(container, context); tracker.cooldownWakeupTime = Math.max(tracker.cooldownWakeupTime, l); return null; } else { this.onFailure( new LowLevelGetException(LowLevelGetException.RECENTLY_FAILED), null, container, context); return null; } } return keys[0]; }
private static FreenetURI insertData(File dataFile) throws IOException { long startInsertTime = System.currentTimeMillis(); InetAddress localhost = InetAddress.getByName("127.0.0.1"); Socket sock = new Socket(localhost, 9481); OutputStream sockOS = sock.getOutputStream(); InputStream sockIS = sock.getInputStream(); System.out.println("Connected to node."); LineReadingInputStream lis = new LineReadingInputStream(sockIS); OutputStreamWriter osw = new OutputStreamWriter(sockOS, "UTF-8"); osw.write( "ClientHello\nExpectedVersion=0.7\nName=BootstrapPullTest-" + System.currentTimeMillis() + "\nEnd\n"); osw.flush(); String name = lis.readLine(65536, 128, true); SimpleFieldSet fs = new SimpleFieldSet(lis, 65536, 128, true, true, false, true); if (!name.equals("NodeHello")) { System.err.println("No NodeHello from insertor node!"); System.exit(EXIT_INSERTER_PROBLEM); } System.out.println("Connected to " + sock); osw.write( "ClientPut\nIdentifier=test-insert\nURI=CHK@\nVerbosity=1023\nUploadFrom=direct\nMaxRetries=-1\nDataLength=" + TEST_SIZE + "\nData\n"); osw.flush(); InputStream is = new FileInputStream(dataFile); FileUtil.copy(is, sockOS, TEST_SIZE); System.out.println("Sent data"); while (true) { name = lis.readLine(65536, 128, true); fs = new SimpleFieldSet(lis, 65536, 128, true, true, false, true); System.out.println("Got FCP message: \n" + name); System.out.print(fs.toOrderedString()); if (name.equals("ProtocolError")) { System.err.println("Protocol error when inserting data."); System.exit(EXIT_INSERTER_PROBLEM); } if (name.equals("PutFailed")) { System.err.println("Insert failed"); System.exit(EXIT_INSERT_FAILED); } if (name.equals("PutSuccessful")) { long endInsertTime = System.currentTimeMillis(); FreenetURI uri = new FreenetURI(fs.get("URI")); System.out.println( "RESULT: Insert took " + (endInsertTime - startInsertTime) + "ms (" + TimeUtil.formatTime(endInsertTime - startInsertTime) + ") to " + uri + " ."); sockOS.close(); sockIS.close(); sock.close(); return uri; } } }
public String statsPageLine(boolean isSSK, boolean isInsert, boolean realTime) { StringBuilder sb = new StringBuilder(100); sb.append(isSSK ? "SSK" : "CHK"); sb.append(' '); sb.append(isInsert ? "Insert" : "Request"); sb.append(' '); sb.append(realTime ? "RealTime" : "Bulk"); sb.append(" RTT="); MyRequestThrottle throttle = getThrottle(isSSK, isInsert, realTime); sb.append(TimeUtil.formatTime((long) throttle.getRTT(), 2, true)); sb.append(" delay="); sb.append(TimeUtil.formatTime(throttle.getDelay(), 2, true)); sb.append(" bw="); sb.append(throttle.getRate()); sb.append("B/sec"); return sb.toString(); }
@Override public List<PersistentChosenBlock> makeBlocks( PersistentChosenRequest request, RequestScheduler sched, KeysFetchingLocally keysFetching, ObjectContainer container, ClientContext context) { if (persistent) container.activate(key, 5); ClientKey ckey = key.cloneKey(); Key k = ckey.getNodeKey(true); if (keysFetching.hasKey(k, this, persistent, container)) return null; long l = keysFetching.checkRecentlyFailed(k, realTimeFlag); long now = System.currentTimeMillis(); if (l > 0 && l > now) { if (maxRetries == -1 || (maxRetries >= RequestScheduler.COOLDOWN_RETRIES)) { // FIXME synchronization!!! if (logMINOR) Logger.minor( this, "RecentlyFailed -> cooldown until " + TimeUtil.formatTime(l - now) + " on " + this); MyCooldownTrackerItem tracker = makeCooldownTrackerItem(container, context); tracker.cooldownWakeupTime = Math.max(tracker.cooldownWakeupTime, l); return null; } else { this.onFailure( new LowLevelGetException(LowLevelGetException.RECENTLY_FAILED), null, container, context); return null; } } PersistentChosenBlock block = new PersistentChosenBlock(false, request, keys[0], k, ckey, sched); return Collections.singletonList(block); }
static void sendReplyHeaders( OutputStream sockOutputStream, int replyCode, String replyDescription, MultiValueTable<String, String> mvt, String mimeType, long contentLength, Date mTime, boolean disconnect) throws IOException { // Construct headers if (mvt == null) mvt = new MultiValueTable<String, String>(); if (mimeType != null) if (mimeType.equalsIgnoreCase("text/html")) { mvt.put("content-type", mimeType + "; charset=UTF-8"); } else { mvt.put("content-type", mimeType); } if (contentLength >= 0) mvt.put("content-length", Long.toString(contentLength)); String expiresTime; if (mTime == null) { expiresTime = "Thu, 01 Jan 1970 00:00:00 GMT"; } else { // use an expiry time of 1 day, somewhat arbitrarily expiresTime = TimeUtil.makeHTTPDate(mTime.getTime() + (24 * 60 * 60 * 1000)); } mvt.put("expires", expiresTime); String nowString = TimeUtil.makeHTTPDate(System.currentTimeMillis()); String lastModString; if (mTime == null) { lastModString = nowString; } else { lastModString = TimeUtil.makeHTTPDate(mTime.getTime()); } mvt.put("last-modified", lastModString); mvt.put("date", nowString); if (mTime == null) { mvt.put("pragma", "no-cache"); mvt.put( "cache-control", "max-age=0, must-revalidate, no-cache, no-store, post-check=0, pre-check=0"); } if (disconnect) mvt.put("connection", "close"); else mvt.put("connection", "keep-alive"); StringBuilder buf = new StringBuilder(1024); buf.append("HTTP/1.1 "); buf.append(replyCode); buf.append(' '); buf.append(replyDescription); buf.append("\r\n"); for (Enumeration<String> e = mvt.keys(); e.hasMoreElements(); ) { String key = e.nextElement(); Object[] list = mvt.getArray(key); key = fixKey(key); for (int i = 0; i < list.length; i++) { String val = (String) list[i]; buf.append(key); buf.append(": "); buf.append(val); buf.append("\r\n"); } } buf.append("\r\n"); sockOutputStream.write(buf.toString().getBytes("US-ASCII")); }
/** * @param args * @throws InvalidThresholdException * @throws IOException * @throws NodeInitException * @throws InterruptedException */ public static void main(String[] args) throws InvalidThresholdException, IOException, NodeInitException, InterruptedException { Node secondNode = null; try { String ipOverride = null; if (args.length > 0) ipOverride = args[0]; File dir = new File("bootstrap-pull-test"); FileUtil.removeAll(dir); RandomSource random = NodeStarter.globalTestInit(dir.getPath(), false, Logger.ERROR, "", false); byte[] seed = new byte[64]; random.nextBytes(seed); MersenneTwister fastRandom = new MersenneTwister(seed); File seednodes = new File("seednodes.fref"); if (!seednodes.exists() || seednodes.length() == 0 || !seednodes.canRead()) { System.err.println("Unable to read seednodes.fref, it doesn't exist, or is empty"); System.exit(EXIT_NO_SEEDNODES); } File secondInnerDir = new File(dir, Integer.toString(DARKNET_PORT)); secondInnerDir.mkdir(); FileInputStream fis = new FileInputStream(seednodes); FileUtil.writeTo(fis, new File(secondInnerDir, "seednodes.fref")); fis.close(); // Create the test data System.out.println("Creating test data."); File dataFile = File.createTempFile("testdata", ".tmp", dir); OutputStream os = new FileOutputStream(dataFile); byte[] buf = new byte[4096]; for (long written = 0; written < TEST_SIZE; ) { fastRandom.nextBytes(buf); int toWrite = (int) Math.min(TEST_SIZE - written, buf.length); os.write(buf, 0, toWrite); written += toWrite; } os.close(); // Insert it to the established node. System.out.println("Inserting test data to an established node."); FreenetURI uri = insertData(dataFile); // Bootstrap a second node. secondInnerDir.mkdir(); fis = new FileInputStream(seednodes); FileUtil.writeTo(fis, new File(secondInnerDir, "seednodes.fref")); fis.close(); PooledExecutor executor = new PooledExecutor(); secondNode = NodeStarter.createTestNode( DARKNET_PORT, OPENNET_PORT, dir.getPath(), false, Node.DEFAULT_MAX_HTL, 0, random, executor, 1000, 5 * 1024 * 1024, true, true, true, true, true, true, true, 12 * 1024, false, true, ipOverride); secondNode.start(true); if (!TestUtil.waitForNodes(secondNode, TARGET_PEERS)) { secondNode.park(); System.exit(EXIT_FAILED_TARGET); } // Fetch the data long startFetchTime = System.currentTimeMillis(); HighLevelSimpleClient client = secondNode.clientCore.makeClient((short) 0); try { client.fetch(uri); } catch (FetchException e) { System.err.println("FETCH FAILED: " + e); e.printStackTrace(); System.exit(EXIT_FETCH_FAILED); return; } long endFetchTime = System.currentTimeMillis(); System.out.println( "RESULT: Fetch took " + (endFetchTime - startFetchTime) + "ms (" + TimeUtil.formatTime(endFetchTime - startFetchTime) + ") of " + uri + " ."); secondNode.park(); System.exit(0); } catch (Throwable t) { System.err.println("CAUGHT: " + t); t.printStackTrace(); try { if (secondNode != null) secondNode.park(); } catch (Throwable t1) { } ; System.exit(EXIT_THREW_SOMETHING); } }
private UpdateThingy createUpdateThingy() { StringBuilder sb = new StringBuilder(); sb.append(l10n("notLatest")); sb.append(' '); if (updater.isArmed() && updater.inFinalCheck()) { sb.append( l10n( "finalCheck", new String[] {"count", "max", "time"}, new String[] { Integer.toString(updater.getRevocationDNFCounter()), Integer.toString(RevocationChecker.REVOCATION_DNF_MIN), TimeUtil.formatTime(updater.timeRemainingOnCheck()) })); sb.append(' '); } else if (updater.isArmed()) { sb.append(l10n("armed")); } else { String formText; if (updater.canUpdateNow()) { boolean b = false; if (updater.hasNewMainJar()) { sb.append( l10n("downloadedNewJar", "version", Integer.toString(updater.newMainJarVersion()))); sb.append(' '); b = true; } if (updater.hasNewExtJar()) { sb.append( l10n( b ? "alsoDownloadedNewExtJar" : "downloadedNewExtJar", "version", Integer.toString(updater.newExtJarVersion()))); sb.append(' '); } if (updater.canUpdateImmediately()) { sb.append(l10n("clickToUpdateNow")); formText = l10n("updateNowButton"); } else { sb.append(l10n("clickToUpdateASAP")); formText = l10n("updateASAPButton"); } } else { boolean fetchingNew = updater.fetchingNewMainJar(); boolean fetchingNewExt = updater.fetchingNewExtJar(); if (fetchingNew) { if (fetchingNewExt) sb.append( l10n( "fetchingNewBoth", new String[] {"nodeVersion", "extVersion"}, new String[] { Integer.toString(updater.fetchingNewMainJarVersion()), Integer.toString(updater.fetchingNewExtJarVersion()) })); else sb.append( l10n( "fetchingNewNode", "nodeVersion", Integer.toString(updater.fetchingNewMainJarVersion()))); } else { if (fetchingNewExt) sb.append( l10n( "fetchingNewExt", "extVersion", Integer.toString(updater.fetchingNewExtJarVersion()))); } sb.append(l10n("updateASAPQuestion")); formText = l10n("updateASAPButton"); } return new UpdateThingy(sb.toString(), formText); } return new UpdateThingy(sb.toString(), null); }
private void fillRequestStarterQueue(ObjectContainer container, ClientContext context) { synchronized (this) { if (fillingRequestStarterQueue) return; fillingRequestStarterQueue = true; } long now = System.currentTimeMillis(); try { if (logMINOR) Logger.minor( this, "Filling request queue... (SSK=" + isSSKScheduler + " insert=" + isInsertScheduler); long noLaterThan = Long.MAX_VALUE; boolean checkCooldownQueue = now > nextQueueFillRequestStarterQueue; if ((!isInsertScheduler) && checkCooldownQueue) { if (persistentCooldownQueue != null) noLaterThan = moveKeysFromCooldownQueue(persistentCooldownQueue, true, container); noLaterThan = Math.min( noLaterThan, moveKeysFromCooldownQueue(transientCooldownQueue, false, container)); } // If anything has been re-added, the request starter will have been woken up. short fuzz = -1; if (PRIORITY_SOFT.equals(choosenPriorityScheduler)) fuzz = -1; else if (PRIORITY_HARD.equals(choosenPriorityScheduler)) fuzz = 0; boolean added = false; synchronized (starterQueue) { if (logMINOR && (!isSSKScheduler) && (!isInsertScheduler)) { Logger.minor(this, "Scheduling CHK fetches..."); for (SendableRequest req : runningPersistentRequests) { boolean wasActive = container.ext().isActive(req); if (!wasActive) container.activate(req, 1); Logger.minor(this, "Running persistent request: " + req); if (!wasActive) container.deactivate(req, 1); } } // Recompute starterQueueLength int length = 0; PersistentChosenRequest old = null; for (PersistentChosenRequest req : starterQueue) { if (old == req) Logger.error(this, "DUPLICATE CHOSEN REQUESTS ON QUEUE: " + req); if (old != null && old.request == req.request) Logger.error( this, "DUPLICATE REQUEST ON QUEUE: " + old + " vs " + req + " both " + req.request); boolean ignoreActive = false; if (!ignoreActive) { if (container.ext().isActive(req.request)) Logger.warning( this, "REQUEST ALREADY ACTIVATED: " + req.request + " for " + req + " while checking request queue in filling request queue"); else if (logMINOR) Logger.minor( this, "Not already activated for " + req + " in while checking request queue in filling request queue"); } else if (logMINOR) Logger.minor(this, "Ignoring active because just registered: " + req.request); req.pruneDuplicates(ClientRequestScheduler.this); old = req; length += req.sizeNotStarted(); } if (logMINOR) Logger.minor( this, "Queue size: " + length + " SSK=" + isSSKScheduler + " insert=" + isInsertScheduler); if (length > MAX_STARTER_QUEUE_SIZE * 3 / 4) { if (length >= WARNING_STARTER_QUEUE_SIZE) Logger.error(this, "Queue already full: " + length); return; } } if ((!isSSKScheduler) && (!isInsertScheduler)) { Logger.minor(this, "Scheduling CHK fetches..."); } boolean addedMore = false; while (true) { SelectorReturn r; // Must synchronize on scheduler to avoid problems with cooldown queue. See notes on // CooldownTracker.clearCachedWakeup, which also applies to other cooldown operations. synchronized (this) { r = selector.removeFirstInner( fuzz, random, offeredKeys, starter, schedCore, schedTransient, false, true, Short.MAX_VALUE, isRTScheduler, context, container, now); } SendableRequest request = null; if (r != null && r.req != null) request = r.req; else { if (r != null && r.wakeupTime > 0 && noLaterThan > r.wakeupTime) { noLaterThan = r.wakeupTime; if (logMINOR) Logger.minor( this, "Waking up in " + TimeUtil.formatTime(noLaterThan - now) + " for cooldowns"); } } if (request == null) { synchronized (ClientRequestScheduler.this) { // Don't wake up for a while, but no later than the time we expect the next item to come // off the cooldown queue if (checkCooldownQueue && !added) { nextQueueFillRequestStarterQueue = System.currentTimeMillis() + WAIT_AFTER_NOTHING_TO_START; if (nextQueueFillRequestStarterQueue > noLaterThan) nextQueueFillRequestStarterQueue = noLaterThan + 1; } } if (addedMore) starter.wakeUp(); return; } boolean full = addToStarterQueue(request, container); container.deactivate(request, 1); if (!added) starter.wakeUp(); else addedMore = true; added = true; if (full) { if (addedMore) starter.wakeUp(); return; } } } finally { synchronized (this) { fillingRequestStarterQueue = false; } } }
/** * 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"); } }
public static void main(String[] args) throws InvalidThresholdException, IOException, NodeInitException, InterruptedException { Node node = null; Node secondNode = null; try { String ipOverride = null; if (args.length > 0) ipOverride = args[0]; File dir = new File("bootstrap-push-pull-test"); FileUtil.removeAll(dir); RandomSource random = NodeStarter.globalTestInit(dir.getPath(), false, LogLevel.ERROR, "", false); File seednodes = new File("seednodes.fref"); if (!seednodes.exists() || seednodes.length() == 0 || !seednodes.canRead()) { System.err.println("Unable to read seednodes.fref, it doesn't exist, or is empty"); System.exit(EXIT_NO_SEEDNODES); } File innerDir = new File(dir, Integer.toString(DARKNET_PORT1)); innerDir.mkdir(); FileInputStream fis = new FileInputStream(seednodes); FileUtil.writeTo(fis, new File(innerDir, "seednodes.fref")); fis.close(); // Create one node Executor executor = new PooledExecutor(); node = NodeStarter.createTestNode( DARKNET_PORT1, OPENNET_PORT1, dir.getPath(), false, Node.DEFAULT_MAX_HTL, 0, random, executor, 1000, 5 * 1024 * 1024, true, true, true, true, true, true, true, 12 * 1024, false, true, false, false, ipOverride); // NodeCrypto.DISABLE_GROUP_STRIP = true; // Logger.setupStdoutLogging(LogLevel.MINOR, // "freenet:NORMAL,freenet.node.NodeDispatcher:MINOR,freenet.node.FNPPacketMangler:MINOR"); Logger.getChain().setThreshold(LogLevel.ERROR); // kill logging // Start it node.start(true); if (!TestUtil.waitForNodes(node)) { node.park(); System.exit(EXIT_FAILED_TARGET); } System.err.println("Creating test data: " + TEST_SIZE + " bytes."); Bucket data = node.clientCore.tempBucketFactory.makeBucket(TEST_SIZE); OutputStream os = data.getOutputStream(); byte[] buf = new byte[4096]; for (long written = 0; written < TEST_SIZE; ) { node.fastWeakRandom.nextBytes(buf); int toWrite = (int) Math.min(TEST_SIZE - written, buf.length); os.write(buf, 0, toWrite); written += toWrite; } os.close(); System.err.println("Inserting test data."); HighLevelSimpleClient client = node.clientCore.makeClient((short) 0); InsertBlock block = new InsertBlock(data, new ClientMetadata(), FreenetURI.EMPTY_CHK_URI); long startInsertTime = System.currentTimeMillis(); FreenetURI uri; try { uri = client.insert(block, false, null); } catch (InsertException e) { System.err.println("INSERT FAILED: " + e); e.printStackTrace(); System.exit(EXIT_INSERT_FAILED); return; } long endInsertTime = System.currentTimeMillis(); System.err.println( "RESULT: Insert took " + (endInsertTime - startInsertTime) + "ms (" + TimeUtil.formatTime(endInsertTime - startInsertTime) + ") to " + uri + " ."); node.park(); // Bootstrap a second node. File secondInnerDir = new File(dir, Integer.toString(DARKNET_PORT2)); secondInnerDir.mkdir(); fis = new FileInputStream(seednodes); FileUtil.writeTo(fis, new File(secondInnerDir, "seednodes.fref")); fis.close(); executor = new PooledExecutor(); secondNode = NodeStarter.createTestNode( DARKNET_PORT2, OPENNET_PORT2, dir.getPath(), false, Node.DEFAULT_MAX_HTL, 0, random, executor, 1000, 5 * 1024 * 1024, true, true, true, true, true, true, true, 12 * 1024, false, true, false, false, ipOverride); secondNode.start(true); if (!TestUtil.waitForNodes(secondNode)) { secondNode.park(); System.exit(EXIT_FAILED_TARGET); } // Fetch the data long startFetchTime = System.currentTimeMillis(); client = secondNode.clientCore.makeClient((short) 0); try { client.fetch(uri); } catch (FetchException e) { System.err.println("FETCH FAILED: " + e); e.printStackTrace(); System.exit(EXIT_FETCH_FAILED); return; } long endFetchTime = System.currentTimeMillis(); System.err.println( "RESULT: Fetch took " + (endFetchTime - startFetchTime) + "ms (" + TimeUtil.formatTime(endFetchTime - startFetchTime) + ") of " + uri + " ."); secondNode.park(); System.exit(0); } catch (Throwable t) { System.err.println("CAUGHT: " + t); t.printStackTrace(); try { if (node != null) node.park(); } catch (Throwable t1) { } ; try { if (secondNode != null) secondNode.park(); } catch (Throwable t1) { } ; System.exit(EXIT_THREW_SOMETHING); } }
/** Try again - returns true if we can retry */ protected boolean retry(ObjectContainer container, ClientContext context) { if (isEmpty(container)) { if (logMINOR) Logger.minor(this, "Not retrying because empty"); return false; // Cannot retry e.g. because we got the block and it failed to decode - that's a // fatal error. } // We want 0, 1, ... maxRetries i.e. maxRetries+1 attempts (maxRetries=0 => try once, no // retries, maxRetries=1 = original try + 1 retry) MyCooldownTrackerItem tracker = makeCooldownTrackerItem(container, context); int r; if (maxRetries == -1) r = ++tracker.retryCount; else r = ++retryCount; if (logMINOR) Logger.minor( this, "Attempting to retry... (max " + maxRetries + ", current " + r + ") on " + this + " finished=" + finished + " cancelled=" + cancelled); if ((r <= maxRetries) || (maxRetries == -1)) { if (persistent && maxRetries != -1) container.store(this); checkCachedCooldownData(container); if (cachedCooldownTries == 0 || r % cachedCooldownTries == 0) { // Add to cooldown queue. Don't reschedule yet. long now = System.currentTimeMillis(); if (tracker.cooldownWakeupTime > now) { Logger.error( this, "Already on the cooldown queue for " + this + " until " + freenet.support.TimeUtil.formatTime(tracker.cooldownWakeupTime - now), new Exception("error")); } else { if (logMINOR) Logger.minor(this, "Adding to cooldown queue " + this); if (persistent) container.activate(key, 5); tracker.cooldownWakeupTime = now + cachedCooldownTime; context.cooldownTracker.setCachedWakeup( tracker.cooldownWakeupTime, this, getParentGrabArray(), persistent, container, context, true); if (logMINOR) Logger.minor( this, "Added single file fetcher into cooldown until " + TimeUtil.formatTime(tracker.cooldownWakeupTime - now)); if (persistent) container.deactivate(key, 5); } onEnterFiniteCooldown(context); } else { // Wake the CRS after clearing cache. this.clearCooldown(container, context, true); } return true; // We will retry in any case, maybe not just not yet. See // requeueAfterCooldown(Key). } unregister(container, context, getPriorityClass(container)); return false; }