Author: zothar
Date: 2006-05-29 04:31:30 +0000 (Mon, 29 May 2006)
New Revision: 8912
Modified:
trunk/freenet/src/freenet/node/FNPPacketMangler.java
trunk/freenet/src/freenet/node/Node.java
trunk/freenet/src/freenet/node/PacketSender.java
Log:
More timing and logging in PacketSender's code path
Modified: trunk/freenet/src/freenet/node/FNPPacketMangler.java
===================================================================
--- trunk/freenet/src/freenet/node/FNPPacketMangler.java 2006-05-29
03:22:08 UTC (rev 8911)
+++ trunk/freenet/src/freenet/node/FNPPacketMangler.java 2006-05-29
04:31:30 UTC (rev 8912)
@@ -1288,9 +1288,16 @@
DiffieHellmanContext ctx;
Peer[] handshakeIPs;
if(!pn.shouldSendHandshake()) return;
+ long firstTime = System.currentTimeMillis();
handshakeIPs = pn.getHandshakeIPs();
+ long secondTime = System.currentTimeMillis();
+ if((secondTime - firstTime) > 1000)
+ Logger.normal(this, "getHandshakeIPs() took more than a second to
execute ("+(secondTime - firstTime)+")");
if(handshakeIPs.length == 0) {
pn.couldNotSendHandshake();
+ long thirdTime = System.currentTimeMillis();
+ if((thirdTime - secondTime) > 1000)
+ Logger.normal(this, "couldNotSendHandshake() (after
getHandshakeIPs()) took more than a second to execute ("+(thirdTime -
secondTime)+")");
return;
} else {
ctx = DiffieHellman.generateContext();
Modified: trunk/freenet/src/freenet/node/Node.java
===================================================================
--- trunk/freenet/src/freenet/node/Node.java 2006-05-29 03:22:08 UTC (rev
8911)
+++ trunk/freenet/src/freenet/node/Node.java 2006-05-29 04:31:30 UTC (rev
8912)
@@ -2882,7 +2882,7 @@
public void maybeLogPeerNodeStatusSummary(long now) {
if(now > nextPeerNodeStatusLogTime) {
if((now - nextPeerNodeStatusLogTime) > (3*1000))
- Logger.error(this,"maybeLogPeerNodeStatusSummary() not called for
more than 3 seconds. PacketSender getting bogged down or something?");
+ Logger.error(this,"maybeLogPeerNodeStatusSummary() not called for
more than 3 seconds ("+(now - nextPeerNodeStatusLogTime)+"). PacketSender
getting bogged down or something?");
int numberOfConnected = getNumStatusConnectedPeerNodes();
int numberOfRoutingBackedOff = getNumStatusRoutingBackedOffPeerNodes();
int numberOfTooNew = getNumStatusTooNewPeerNodes();
Modified: trunk/freenet/src/freenet/node/PacketSender.java
===================================================================
--- trunk/freenet/src/freenet/node/PacketSender.java 2006-05-29 03:22:08 UTC
(rev 8911)
+++ trunk/freenet/src/freenet/node/PacketSender.java 2006-05-29 04:31:30 UTC
(rev 8912)
@@ -75,6 +75,7 @@
}
node.maybeLogPeerNodeStatusSummary(now);
long nextActionTime = Long.MAX_VALUE;
+ long oldTempNow = now;
for(int i=0;i<nodes.length;i++) {
PeerNode pn = nodes[i];
lastReceivedPacketFromAnyNode =
@@ -176,9 +177,17 @@
} else {
// Not connected
// Send handshake if necessary
+ long beforeHandshakeTime = System.currentTimeMillis();
if(pn.shouldSendHandshake())
node.packetMangler.sendHandshake(pn);
+ long afterHandshakeTime = System.currentTimeMillis();
+ if((afterHandshakeTime - beforeHandshakeTime) > (2*1000))
+ Logger.normal(this, "afterHandshakeTime is more than 2
seconds past beforeHandshakeTime ("+(afterHandshakeTime -
beforeHandshakeTime)+") in PacketSender working with "+pn.getPeer()+" named
"+pn.getName());
}
+ long tempNow = System.currentTimeMillis();
+ if((tempNow - oldTempNow) > (5*1000))
+ Logger.normal(this, "tempNow is more than 5 seconds
past oldTempNow ("+(tempNow - oldTempNow)+") in PacketSender working with
"+pn.getPeer()+" named "+pn.getName());
+ oldTempNow = tempNow;
}
if(now - lastClearedOldSwapChains > 10000) {
@@ -191,9 +200,8 @@
// Send may have taken some time
now = System.currentTimeMillis();
- long nowDelta = now - oldNow;
- if(nowDelta > (60*1000))
- Logger.normal(this, "nowDelta("+nowDelta+") is greater than a
minute in PacketSender");
+ if((now - oldNow) > (10*1000))
+ Logger.normal(this, "now is more than 10 seconds past oldNow
("+(now - oldNow)+") in PacketSender");
Vector jobsToRun = null;
