[freenet-cvs] r9037 - trunk/freenet/src/freenet/node

[zot...@freenetproject.org]

Author: zothar
Date: 2006-06-04 04:17:21 +0000 (Sun, 04 Jun 2006)
New Revision: 9037

Modified:
   trunk/freenet/src/freenet/node/FNPPacketMangler.java
   trunk/freenet/src/freenet/node/PeerNode.java
Log:
Add more timing and 'took too long' complaining to PacketSender's code path.

Modified: trunk/freenet/src/freenet/node/FNPPacketMangler.java
===================================================================
--- trunk/freenet/src/freenet/node/FNPPacketMangler.java        2006-06-04 
03:17:14 UTC (rev 9036)
+++ trunk/freenet/src/freenet/node/FNPPacketMangler.java        2006-06-04 
04:17:21 UTC (rev 9037)
@@ -1313,9 +1313,19 @@
         int sentCount = 0;
         long loopTime1 = System.currentTimeMillis();
         for(int i=0;i<handshakeIPs.length;i++){
+          long innerLoopTime1 = System.currentTimeMillis();
           if(handshakeIPs[i].getAddress(false) == null) continue;
+          long innerLoopTime2 = System.currentTimeMillis();
+          if((innerLoopTime2 - innerLoopTime1) > 500)
+            Logger.normal(this, "innerLoopTime2 is more than half a second 
after innerLoopTime1 ("+(innerLoopTime2 - innerLoopTime1)+") working on 
"+handshakeIPs[i]+" of "+pn.getName());
                sendFirstHalfDHPacket(0, ctx.getOurExponential(), pn, 
handshakeIPs[i]);
+          long innerLoopTime3 = System.currentTimeMillis();
+          if((innerLoopTime3 - innerLoopTime2) > 500)
+            Logger.normal(this, "innerLoopTime3 is more than half a second 
after innerLoopTime2 ("+(innerLoopTime3 - innerLoopTime2)+") working on 
"+handshakeIPs[i]+" of "+pn.getName());
                pn.sentHandshake();
+          long innerLoopTime4 = System.currentTimeMillis();
+          if((innerLoopTime4 - innerLoopTime3) > 500)
+            Logger.normal(this, "innerLoopTime4 is more than half a second 
after innerLoopTime3 ("+(innerLoopTime4 - innerLoopTime3)+") working on 
"+handshakeIPs[i]+" of "+pn.getName());
                sentCount += 1;
         }
         long loopTime2 = System.currentTimeMillis();

Modified: trunk/freenet/src/freenet/node/PeerNode.java
===================================================================
--- trunk/freenet/src/freenet/node/PeerNode.java        2006-06-04 03:17:14 UTC 
(rev 9036)
+++ trunk/freenet/src/freenet/node/PeerNode.java        2006-06-04 04:17:21 UTC 
(rev 9037)
@@ -847,7 +847,11 @@
         // Don't fetch ARKs for peers we have verified (through handshake) to 
be incompatible with us
         if(handshakeCount == MAX_HANDSHAKE_COUNT && 
!(verifiedIncompatibleOlderVersion || verifiedIncompatibleNewerVersion)) {
                Logger.normal( this, "Starting ARK Fetcher after 
"+handshakeCount+" failed handshakes for "+getPeer()+" with identity 
'"+getIdentityString()+"'");
+               long arkFetcherStartTime1 = System.currentTimeMillis();
                arkFetcher.start();
+               long arkFetcherStartTime2 = System.currentTimeMillis();
+               if((arkFetcherStartTime2 - arkFetcherStartTime1) > 500)
+                       Logger.normal(this, "arkFetcherStartTime2 is more than 
half a second after arkFetcherStartTime1 ("+(arkFetcherStartTime2 - 
arkFetcherStartTime1)+") working on "+myName);
         }
     }