Author: zothar
Date: 2006-05-19 22:36:32 +0000 (Fri, 19 May 2006)
New Revision: 8792
Modified:
trunk/freenet/src/freenet/client/StandardOnionFECCodec.java
trunk/freenet/src/freenet/node/FNPPacketMangler.java
trunk/freenet/src/freenet/node/KeyTracker.java
trunk/freenet/src/freenet/node/PacketSender.java
trunk/freenet/src/freenet/node/PeerNode.java
trunk/freenet/src/freenet/support/LimitedRangeIntByteArrayMap.java
trunk/freenet/src/test/PaddingSpeedTest.java
Log:
- Log a reason with some "Requeueing x messages" log messages and lower the log
level of some partner log messages from normal to minor
- Throwing a WouldBlockException now passes the details in the exception rather
than logging them directly at normal log level
- Add average ping time to "Removing ack request twice" log messages
- Consistently space the use of "ms" units
Modified: trunk/freenet/src/freenet/client/StandardOnionFECCodec.java
===================================================================
--- trunk/freenet/src/freenet/client/StandardOnionFECCodec.java 2006-05-19
20:13:37 UTC (rev 8791)
+++ trunk/freenet/src/freenet/client/StandardOnionFECCodec.java 2006-05-19
22:36:32 UTC (rev 8792)
@@ -441,7 +441,7 @@
Logger.minor(this, "Memory in use after
stripe: "+memUsedAfterStripe);
long endTime =
System.currentTimeMillis();
Logger.minor(this, "Stripe encode took "
- + (endTime - startTime)
+ " ms for k=" + k + ", n="
+ + (endTime - startTime)
+ "ms for k=" + k + ", n="
+ n + ", stripeSize=" +
STRIPE_SIZE);
// Try to limit CPU usage!!
try {
Modified: trunk/freenet/src/freenet/node/FNPPacketMangler.java
===================================================================
--- trunk/freenet/src/freenet/node/FNPPacketMangler.java 2006-05-19
20:13:37 UTC (rev 8791)
+++ trunk/freenet/src/freenet/node/FNPPacketMangler.java 2006-05-19
22:36:32 UTC (rev 8792)
@@ -790,34 +790,34 @@
KeyTracker kt = pn.getCurrentKeyTracker();
if(kt == null) {
Logger.minor(this, "kt = null");
- pn.requeueMessageItems(messages, i, messages.length-i,
false);
+ pn.requeueMessageItems(messages, i, messages.length-i,
false, "kt = null");
return;
}
int packetNumber =
kt.allocateOutgoingPacketNumberNeverBlock();
this.processOutgoingPreformatted(buf, 0, buf.length,
pn.getCurrentKeyTracker(), packetNumber, mi.cb);
} catch (NotConnectedException e) {
- Logger.normal(this, "Caught "+e+" while sending messages,
requeueing");
+ Logger.minor(this, "Caught "+e+" while sending messages,
requeueing");
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, i, messages.length-i,
false);
+ pn.requeueMessageItems(messages, i, messages.length-i,
false, "NotConnectedException");
return;
} catch (WouldBlockException e) {
- Logger.normal(this, "Caught "+e+" while sending messages,
requeueing");
+ Logger.minor(this, "Caught "+e+" while sending messages,
requeueing", e);
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, i, messages.length-i,
false);
+ pn.requeueMessageItems(messages, i, messages.length-i,
false, "WouldBlockException");
return;
} catch (KeyChangedException e) {
- Logger.normal(this, "Caught "+e+" while sending messages,
requeueing");
+ Logger.minor(this, "Caught "+e+" while sending messages,
requeueing");
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, i, messages.length-i,
false);
+ pn.requeueMessageItems(messages, i, messages.length-i,
false, "KeyChangedException");
return;
} catch (Throwable e) {
Logger.error(this, "Caught "+e+" while sending messages,
requeueing", e);
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, i, messages.length-i,
false);
+ pn.requeueMessageItems(messages, i, messages.length-i,
false, "Throwable");
return;
}
@@ -853,19 +853,19 @@
Logger.normal(this, "Caught "+e+" while sending messages,
requeueing");
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, 0, messages.length,
false);
+ pn.requeueMessageItems(messages, 0, messages.length,
false, "NotConnectedException(2)");
return;
} catch (WouldBlockException e) {
- Logger.normal(this, "Caught "+e+" while sending messages,
requeueing");
+ Logger.minor(this, "Caught "+e+" while sending messages,
requeueing", e);
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, 0, messages.length,
false);
+ pn.requeueMessageItems(messages, 0, messages.length,
false, "WouldBlockException(2)");
return;
} catch (Throwable e) {
Logger.error(this, "Caught "+e+" while sending messages,
requeueing", e);
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, 0, messages.length,
false);
+ pn.requeueMessageItems(messages, 0, messages.length,
false, "Throwable(2)");
return;
}
@@ -893,19 +893,19 @@
Logger.normal(this, "Caught "+e+" while sending
messages, requeueing remaining messages");
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, lastIndex,
messages.length - lastIndex, false);
+ pn.requeueMessageItems(messages, lastIndex,
messages.length - lastIndex, false, "NotConnectedException(3)");
return;
} catch (WouldBlockException e) {
- Logger.normal(this, "Caught "+e+" while sending
messages, requeueing remaining messages");
+ Logger.minor(this, "Caught "+e+" while sending
messages, requeueing remaining messages", e);
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, lastIndex,
messages.length - lastIndex, false);
+ pn.requeueMessageItems(messages, lastIndex,
messages.length - lastIndex, false, "WouldBlockException(3)");
return;
} catch (Throwable e) {
Logger.error(this, "Caught "+e+" while sending
messages, requeueing remaining messages", e);
// Requeue
if(!dontRequeue)
- pn.requeueMessageItems(messages, lastIndex,
messages.length - lastIndex, false);
+ pn.requeueMessageItems(messages, lastIndex,
messages.length - lastIndex, false, "Throwable(3)");
return;
}
}
Modified: trunk/freenet/src/freenet/node/KeyTracker.java
===================================================================
--- trunk/freenet/src/freenet/node/KeyTracker.java 2006-05-19 20:13:37 UTC
(rev 8791)
+++ trunk/freenet/src/freenet/node/KeyTracker.java 2006-05-19 22:36:32 UTC
(rev 8792)
@@ -538,7 +538,7 @@
QueuedAckRequest qr =
(QueuedAckRequest)ackRequestQueue.removeByKey(new Integer(seqNo));
if(qr != null) qr.onAcked();
else
- Logger.normal(this, "Removing ack request twice? Null on
"+seqNo+" from "+pn.getPeer());
+ Logger.normal(this, "Removing ack request twice? Null on
"+seqNo+" from "+pn.getPeer()+" ("+new
Double(pn.pingAverage.currentValue()).intValue()+"ms ping average)");
}
/**
@@ -755,7 +755,7 @@
Logger.minor(this, "Grabbing ack request "+packetNumber+"
("+realLength+") from "+this);
qr.sent();
} else {
- Logger.minor(this, "Ignoring ack request "+packetNumber+"
("+realLength+") - will become active in "+(qr.activeTime-now)+" ms on "+this+"
- "+qr);
+ Logger.minor(this, "Ignoring ack request "+packetNumber+"
("+realLength+") - will become active in "+(qr.activeTime-now)+"ms on "+this+"
- "+qr);
}
}
}
Modified: trunk/freenet/src/freenet/node/PacketSender.java
===================================================================
--- trunk/freenet/src/freenet/node/PacketSender.java 2006-05-19 20:13:37 UTC
(rev 8791)
+++ trunk/freenet/src/freenet/node/PacketSender.java 2006-05-19 22:36:32 UTC
(rev 8792)
@@ -143,7 +143,7 @@
// Don't send immediately
if(nextActionTime > (l+100))
nextActionTime = l+100;
- pn.requeueMessageItems(messages, 0,
messages.length, true);
+ pn.requeueMessageItems(messages, 0,
messages.length, true, "TrafficCoalescing");
} else {
for(int j=0;j<messages.length;j++) {
Logger.minor(this, "PS Sending:
"+(messages[j].msg == null ? "(not a Message)" :
messages[j].msg.getSpec().getName()));
Modified: trunk/freenet/src/freenet/node/PeerNode.java
===================================================================
--- trunk/freenet/src/freenet/node/PeerNode.java 2006-05-19 20:13:37 UTC
(rev 8791)
+++ trunk/freenet/src/freenet/node/PeerNode.java 2006-05-19 22:36:32 UTC
(rev 8792)
@@ -562,9 +562,18 @@
}
public void requeueMessageItems(MessageItem[] messages, int offset, int
length, boolean dontLog) {
+ requeueMessageItems( messages, offset, length, dontLog, "" );
+ }
+
+ public void requeueMessageItems(MessageItem[] messages, int offset, int
length, boolean dontLog, String reason) {
// Will usually indicate serious problems
- if(!dontLog)
- Logger.normal(this, "Requeueing "+messages.length+" messages on
"+this);
+ if(!dontLog) {
+ String reasonWrapper = "";
+ if( 0 < reason.length()) {
+ reasonWrapper = " because of '"+reason+"'";
+ }
+ Logger.normal(this, "Requeueing "+messages.length+"
messages"+reasonWrapper+" on "+this);
+ }
synchronized(messagesToSendNow) {
for(int i=offset;i<offset+length;i++)
if(messages[i] != null)
Modified: trunk/freenet/src/freenet/support/LimitedRangeIntByteArrayMap.java
===================================================================
--- trunk/freenet/src/freenet/support/LimitedRangeIntByteArrayMap.java
2006-05-19 20:13:37 UTC (rev 8791)
+++ trunk/freenet/src/freenet/support/LimitedRangeIntByteArrayMap.java
2006-05-19 22:36:32 UTC (rev 8792)
@@ -131,8 +131,7 @@
public synchronized void lockNeverBlock(int index) throws
WouldBlockException {
if(minValue == -1) return;
if(index - minValue < maxRange) return;
- Logger.normal(this, toString()+ " WOULD BLOCK:
lockNeverBlock("+index+") - minValue = "+minValue+", maxValue = "+maxValue+",
maxRange="+maxRange);
- throw new WouldBlockException();
+ throw new WouldBlockException(toString()+ " WOULD BLOCK:
lockNeverBlock("+index+") - minValue = "+minValue+", maxValue = "+maxValue+",
maxRange="+maxRange);
}
/**
Modified: trunk/freenet/src/test/PaddingSpeedTest.java
===================================================================
--- trunk/freenet/src/test/PaddingSpeedTest.java 2006-05-19 20:13:37 UTC
(rev 8791)
+++ trunk/freenet/src/test/PaddingSpeedTest.java 2006-05-19 22:36:32 UTC
(rev 8792)
@@ -89,6 +89,6 @@
*/
private static void printStats(String name, int bytesTotal, long interval)
{
double rate = bytesTotal / ((double)interval/1000);
- System.out.println(name+": "+bytesTotal+" in "+interval+" ms =
"+ByteFormat.format((long)rate,false)+"/s");
+ System.out.println(name+": "+bytesTotal+" in "+interval+"ms =
"+ByteFormat.format((long)rate,false)+"/s");
}
}
