@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;
}