* Tunnel building:

- Increase timeout to 13s (was 10s)
      - Fix tunnel.buildReplyTooSlow stat
      - Tweak logging
      - Prioritize expl. builds over client builds
      - Code cleanups

history.txt

@@ -1,8 +1,30 @@
+2009-12-18 zzz
+    * Console: Fix spacing in update section
+    * I2CP:
+      - Move client-side writes to their own thread
+      - Reenable InternalSockets
+    * i2ptunnel: Fix bundle script
+    * InNetMessagePool: Cleanup
+    * SusiDNS:
+      - Remove untranslatable button images (-15KB)
+      - Tag buttons and messages
+      - Add some button CSS
+    * Tunnel building:
+      - Increase timeout to 13s (was 10s)
+      - Fix tunnel.buildReplyTooSlow stat
+      - Tweak logging
+      - Prioritize expl. builds over client builds
+      - Code cleanups
+    * TunnelSettings: Drop, unused
+
 2009-12-15 zzz
     * HTTP Proxy: Make jump server list configurable
+    * I2CP: Remove unused logs
     * i2psnark: Fix stop/start, cleanups
     * i2ptunnel: Fix bundle location
-    * susidns: UTF-8 fixes
+    * SusiDNS:
+      - Rewrite and correct a lot of the text, tag jsps
+      - UTF-8 fixes
     * TunnelManager: Fix a locking bug
     * Update: Improve error message
 

router/java/src/net/i2p/router/RouterVersion.java

@@ -18,7 +18,7 @@ public class RouterVersion {
     /** deprecated */
     public final static String ID = "Monotone";
     public final static String VERSION = CoreVersion.VERSION;
-    public final static long BUILD = 8;
+    public final static long BUILD = 9;
     /** for example "-test" */
     public final static String EXTRA = "";
     public final static String FULL_VERSION = VERSION + "-" + BUILD + EXTRA;

router/java/src/net/i2p/router/tunnel/pool/BuildExecutor.java

@@ -2,6 +2,7 @@ package net.i2p.router.tunnel.pool;
 
 import java.util.ArrayList;
 import java.util.Collections;
+import java.util.Comparator;
 import java.util.List;
 
 import net.i2p.data.Hash;
@@ -19,23 +20,25 @@ import net.i2p.util.Log;
  * it waits for a short period before looping again (or until it is told that something
  * changed, such as a tunnel failed, new client started up, or tunnel creation was aborted).
  *
+ * Note that 10 minute tunnel expiration is hardcoded in here.
  */
 class BuildExecutor implements Runnable {
-    private final List _recentBuildIds = new ArrayList(100);
+    private final ArrayList<Long> _recentBuildIds = new ArrayList(100);
     private RouterContext _context;
     private Log _log;
     private TunnelPoolManager _manager;
     /** list of TunnelCreatorConfig elements of tunnels currently being built */
-    private final List _currentlyBuilding;
+    private final List<PooledTunnelCreatorConfig> _currentlyBuilding;
     private boolean _isRunning;
     private BuildHandler _handler;
     private boolean _repoll;
+    private static final int MAX_CONCURRENT_BUILDS = 10;
 
     public BuildExecutor(RouterContext ctx, TunnelPoolManager mgr) {
         _context = ctx;
         _log = ctx.logManager().getLog(getClass());
         _manager = mgr;
-        _currentlyBuilding = new ArrayList(10);
+        _currentlyBuilding = new ArrayList(MAX_CONCURRENT_BUILDS);
         _context.statManager().createRateStat("tunnel.concurrentBuilds", "How many builds are going at once", "Tunnels", new long[] { 60*1000, 5*60*1000, 60*60*1000 });
         _context.statManager().createRateStat("tunnel.concurrentBuildsLagged", "How many builds are going at once when we reject further builds, due to job lag (period is lag)", "Tunnels", new long[] { 60*1000, 5*60*1000, 60*60*1000 });
         _context.statManager().createRateStat("tunnel.buildExploratoryExpire", "How often an exploratory tunnel times out during creation", "Tunnels", new long[] { 10*60*1000, 60*60*1000 });
@@ -74,16 +77,17 @@ class BuildExecutor implements Runnable {
         int maxKBps = _context.bandwidthLimiter().getOutboundKBytesPerSecond();
         int allowed = maxKBps / 6; // Max. 1 concurrent build per 6 KB/s outbound
         if (allowed < 2) allowed = 2; // Never choke below 2 builds (but congestion may)
-        if (allowed > 10) allowed = 10; // Never go beyond 10, that is uncharted territory (old limit was 5)
+        if (allowed > MAX_CONCURRENT_BUILDS) allowed = MAX_CONCURRENT_BUILDS; // Never go beyond 10, that is uncharted territory (old limit was 5)
         allowed = _context.getProperty("router.tunnelConcurrentBuilds", allowed);
 
-        List expired = null;
+        List<PooledTunnelCreatorConfig> expired = null;
         int concurrent = 0;
+        // Todo: Make expiration variable
         long expireBefore = _context.clock().now() + 10*60*1000 - BuildRequestor.REQUEST_TIMEOUT;
         synchronized (_currentlyBuilding) {
             // expire any old requests
             for (int i = 0; i < _currentlyBuilding.size(); i++) {
-                TunnelCreatorConfig cfg = (TunnelCreatorConfig)_currentlyBuilding.get(i);
+                PooledTunnelCreatorConfig cfg = _currentlyBuilding.get(i);
                 if (cfg.getExpiration() <= expireBefore) {
                     _currentlyBuilding.remove(i);
                     i--;
@@ -98,7 +102,7 @@ class BuildExecutor implements Runnable {
         
         if (expired != null) {
             for (int i = 0; i < expired.size(); i++) {
-                PooledTunnelCreatorConfig cfg = (PooledTunnelCreatorConfig)expired.get(i);
+                PooledTunnelCreatorConfig cfg = expired.get(i);
                 if (_log.shouldLog(Log.INFO))
                     _log.info("Timed out waiting for reply asking for " + cfg);
 
@@ -220,8 +224,8 @@ class BuildExecutor implements Runnable {
 
     public void run() {
         _isRunning = true;
-        List wanted = new ArrayList(8);
+        List<TunnelPool> wanted = new ArrayList(MAX_CONCURRENT_BUILDS);
-        List pools = new ArrayList(8);
+        List<TunnelPool> pools = new ArrayList(8);
         
         int pendingRemaining = 0;
         
@@ -238,7 +242,7 @@ class BuildExecutor implements Runnable {
                 _repoll = pendingRemaining > 0; // resets repoll to false unless there are inbound requeusts pending
                 _manager.listPools(pools);
                 for (int i = 0; i < pools.size(); i++) {
-                    TunnelPool pool = (TunnelPool)pools.get(i);
+                    TunnelPool pool = pools.get(i);
                     if (!pool.isAlive())
                         continue;
                     int howMany = pool.countHowManyToBuild();
@@ -278,14 +282,15 @@ class BuildExecutor implements Runnable {
                 } else {
                     if ( (allowed > 0) && (wanted.size() > 0) ) {
                         Collections.shuffle(wanted, _context.random());
-                        
+                        Collections.sort(wanted, new TunnelPoolComparator());
+
                         // force the loops to be short, since 3 consecutive tunnel build requests can take
                         // a long, long time
                         if (allowed > 2)
                             allowed = 2;
                         
                         for (int i = 0; (i < allowed) && (wanted.size() > 0); i++) {
-                            TunnelPool pool = (TunnelPool)wanted.remove(0);
+                            TunnelPool pool = wanted.remove(0);
                             //if (pool.countWantedTunnels() <= 0)
                             //    continue;
                             PooledTunnelCreatorConfig cfg = pool.configureNewTunnel();
@@ -360,13 +365,38 @@ class BuildExecutor implements Runnable {
         _isRunning = false;
     }
     
+    /**
+     *  Prioritize the pools for building
+     *  #1: Exploratory
+     *  #2: Pools without tunnels
+     *  #3: Everybody else
+     *
+     *  This prevents a large number of client pools from starving the exploratory pool.
+     *
+     */
+    private static class TunnelPoolComparator implements Comparator {
+        public int compare(Object l, Object r) {
+            TunnelPool tpl = (TunnelPool) l;
+            TunnelPool tpr = (TunnelPool) r;
+            if (tpl.getSettings().isExploratory() && !tpr.getSettings().isExploratory())
+                return -1;
+            if (tpr.getSettings().isExploratory() && !tpl.getSettings().isExploratory())
+                return 1;
+            if (tpl.getTunnelCount() <= 0 && tpr.getTunnelCount() > 0)
+                return -1;
+            if (tpr.getTunnelCount() <= 0 && tpl.getTunnelCount() > 0)
+                return 1;
+            return 0;
+        }
+    }
+
     /**
      * iterate over the 0hop tunnels, running them all inline regardless of how many are allowed
      * @return number of tunnels allowed after processing these zero hop tunnels (almost always the same as before)
      */
-    private int buildZeroHopTunnels(List wanted, int allowed) {
+    private int buildZeroHopTunnels(List<TunnelPool> wanted, int allowed) {
         for (int i = 0; i < wanted.size(); i++) {
-            TunnelPool pool = (TunnelPool)wanted.get(0);
+            TunnelPool pool = wanted.get(0);
             if (pool.getSettings().getLength() == 0) {
                 PooledTunnelCreatorConfig cfg = pool.configureNewTunnel();
                 if (cfg != null) {
@@ -403,8 +433,11 @@ class BuildExecutor implements Runnable {
         long id = cfg.getReplyMessageId();
         if (id > 0) {
             synchronized (_recentBuildIds) { 
-                while (_recentBuildIds.size() > 64)
+                // every so often, shrink the list semi-efficiently
-                    _recentBuildIds.remove(0);
+                if (_recentBuildIds.size() > 98) {
+                    for (int i = 0; i < 32; i++)
+                        _recentBuildIds.remove(0);
+                }
                 _recentBuildIds.add(new Long(id));
             }
         }

router/java/src/net/i2p/router/tunnel/pool/BuildHandler.java

@@ -30,6 +30,8 @@ import net.i2p.stat.RateStat;
 import net.i2p.util.Log;
 
 /**
+ *
+ * Note that 10 minute tunnel expiration is hardcoded in here.
  *
  */
 class BuildHandler {
@@ -39,20 +41,27 @@ class BuildHandler {
     private Job _buildMessageHandlerJob;
     private Job _buildReplyMessageHandlerJob;
     /** list of BuildMessageState, oldest first */
-    private final List _inboundBuildMessages;
+    private final List<BuildMessageState> _inboundBuildMessages;
-    /** list of BuildReplyMessageState, oldest first */
+    /** list of BuildReplyMessageState, oldest first - unused unless HANDLE_REPLIES_INLINE == false */
-    private final List _inboundBuildReplyMessages;
+    private final List<BuildReplyMessageState> _inboundBuildReplyMessages;
-    /** list of BuildEndMessageState, oldest first */
+    /** list of BuildEndMessageState, oldest first - unused unless HANDLE_REPLIES_INLINE == false */
-    private final List _inboundBuildEndMessages;
+    private final List<BuildEndMessageState> _inboundBuildEndMessages;
     private BuildMessageProcessor _processor;
+
+    private static final boolean HANDLE_REPLIES_INLINE = true;
     
     public BuildHandler(RouterContext ctx, BuildExecutor exec) {
         _context = ctx;
         _log = ctx.logManager().getLog(getClass());
         _exec = exec;
         _inboundBuildMessages = new ArrayList(16);
-        _inboundBuildReplyMessages = new ArrayList(16);
+        if (HANDLE_REPLIES_INLINE) {
-        _inboundBuildEndMessages = new ArrayList(16);
+            _inboundBuildEndMessages = null;
+            _inboundBuildReplyMessages = null;
+        } else {
+            _inboundBuildEndMessages = new ArrayList(16);
+            _inboundBuildReplyMessages = new ArrayList(16);
+        }
     
         _context.statManager().createRateStat("tunnel.reject.10", "How often we reject a tunnel probabalistically", "Tunnels", new long[] { 60*1000, 10*60*1000 });
         _context.statManager().createRateStat("tunnel.reject.20", "How often we reject a tunnel because of transient overload", "Tunnels", new long[] { 60*1000, 10*60*1000 });
@@ -148,14 +157,16 @@ class BuildHandler {
             }
             handled.clear();
         }
-        synchronized (_inboundBuildEndMessages) {
+        if (!HANDLE_REPLIES_INLINE) {
-            int toHandle = _inboundBuildEndMessages.size();
+            synchronized (_inboundBuildEndMessages) {
-            if (toHandle > 0) {
+                int toHandle = _inboundBuildEndMessages.size();
-                if (handled == null)
+                if (toHandle > 0) {
-                    handled = new ArrayList(_inboundBuildEndMessages);
+                    if (handled == null)
-                else
+                        handled = new ArrayList(_inboundBuildEndMessages);
-                    handled.addAll(_inboundBuildEndMessages);
+                    else
-                _inboundBuildEndMessages.clear();
+                        handled.addAll(_inboundBuildEndMessages);
+                    _inboundBuildEndMessages.clear();
+                }
             }
         }
         if (handled != null) {
@@ -181,7 +192,10 @@ class BuildHandler {
         return remaining;
     }
     
+    /** Warning - noop if HANDLE_REPLIES_INLINE == true */
     void handleInboundReplies() {
+        if (HANDLE_REPLIES_INLINE)
+            return;
         List handled = null;
         synchronized (_inboundBuildReplyMessages) {
             int toHandle = _inboundBuildReplyMessages.size();
@@ -236,8 +250,8 @@ class BuildHandler {
     private void handleReply(TunnelBuildReplyMessage msg, PooledTunnelCreatorConfig cfg, long delay) {
         long requestedOn = cfg.getExpiration() - 10*60*1000;
         long rtt = _context.clock().now() - requestedOn;
-        if (_log.shouldLog(Log.DEBUG))
+        if (_log.shouldLog(Log.INFO))
-            _log.debug(msg.getUniqueId() + ": Handling the reply after " + rtt + ", delayed " + delay + " waiting for " + cfg);
+            _log.info(msg.getUniqueId() + ": Handling the reply after " + rtt + ", delayed " + delay + " waiting for " + cfg);
         
         BuildReplyHandler handler = new BuildReplyHandler();
         List order = cfg.getReplyOrder();
@@ -663,10 +677,10 @@ class BuildHandler {
         }
     }
     
-    /** um, this is bad.  don't set this. */
+    /**
-    private static final boolean DROP_ALL_REQUESTS = false;
+     *  Handle incoming Tunnel Build Messages, which are generally requests to us,
-    private static final boolean HANDLE_REPLIES_INLINE = true;
+     *  but could also be the reply where we are the IBEP.
-
+     */
     private class TunnelBuildMessageHandlerJobBuilder implements HandlerJobBuilder {
         public Job createJob(I2NPMessage receivedMessage, RouterIdentity from, Hash fromHash) {
             // need to figure out if this is a reply to an inbound tunnel request (where we are the
@@ -704,9 +718,11 @@ class BuildHandler {
                     _exec.repoll();
                 }
             } else {
-                if (DROP_ALL_REQUESTS || _exec.wasRecentlyBuilding(reqId)) {
+                if (_exec.wasRecentlyBuilding(reqId)) {
+                    // we are the IBEP but we already gave up?
                     if (_log.shouldLog(Log.WARN))
                         _log.warn("Dropping the reply " + reqId + ", as we used to be building that");
+                    _context.statManager().addRateData("tunnel.buildReplyTooSlow", 1, 0);
                 } else {
                     synchronized (_inboundBuildMessages) {
                         boolean removed = false;

router/java/src/net/i2p/router/tunnel/pool/BuildRequestor.java

@@ -29,7 +29,17 @@ class BuildRequestor {
             ORDER.add(Integer.valueOf(i));
     }
     private static final int PRIORITY = 500;
-    static final int REQUEST_TIMEOUT = 10*1000;
+    /**
+     *  At 10 seconds, we were receiving about 20% of replies after expiration
+     *  Todo: make this variable on a per-request basis, to account for tunnel length,
+     *  expl. vs. client, uptime, and network conditions.
+     *  Put the expiration in the PTCC.
+     *
+     *  Also, perhaps, save the PTCC even after expiration for an extended time,
+     *  so can we use a successfully built tunnel anyway.
+     *
+     */
+    static final int REQUEST_TIMEOUT = 13*1000;
     
     private static boolean usePairedTunnels(RouterContext ctx) {
         String val = ctx.getProperty("router.usePairedTunnels");
@@ -113,19 +123,20 @@ class BuildRequestor {
         
         long beforeDispatch = System.currentTimeMillis();
         if (cfg.isInbound()) {
-            if (log.shouldLog(Log.DEBUG))
+            if (log.shouldLog(Log.INFO))
-                log.debug("Sending the tunnel build request " + msg.getUniqueId() + " out the tunnel " + pairedTunnel + " to " 
+                log.info("Sending the tunnel build request " + msg.getUniqueId() + " out the tunnel " + pairedTunnel + " to " 
                           + cfg.getPeer(0).toBase64() + " for " + cfg + " waiting for the reply of "
                           + cfg.getReplyMessageId());
             // send it out a tunnel targetting the first hop
             ctx.tunnelDispatcher().dispatchOutbound(msg, pairedTunnel.getSendTunnelId(0), cfg.getPeer(0));
         } else {
-            if (log.shouldLog(Log.DEBUG))
+            if (log.shouldLog(Log.INFO))
-                log.debug("Sending the tunnel build request directly to " + cfg.getPeer(1).toBase64() 
+                log.info("Sending the tunnel build request directly to " + cfg.getPeer(1).toBase64() 
                           + " for " + cfg + " waiting for the reply of " + cfg.getReplyMessageId() 
                           + " with msgId=" + msg.getUniqueId());
             // send it directly to the first hop
             OutNetMessage outMsg = new OutNetMessage(ctx);
+            // Todo: add some fuzz to the expiration to make it harder to guess how many hops?
             outMsg.setExpiration(msg.getMessageExpiration());
             outMsg.setMessage(msg);
             outMsg.setPriority(PRIORITY);
@@ -190,7 +201,7 @@ class BuildRequestor {
                 }
             }
             if (log.shouldLog(Log.DEBUG))
-                log.debug(cfg.getReplyMessageId() + ": record " + i + "/" + hop + " has key " + key + " for " + cfg);
+                log.debug(cfg.getReplyMessageId() + ": record " + i + "/" + hop + " has key " + key);
             gen.createRecord(i, hop, msg, cfg, replyRouter, replyTunnel, ctx, key);
         }
         gen.layeredEncrypt(ctx, msg, cfg, order);

router/java/src/net/i2p/router/tunnel/pool/TunnelPoolManager.java

@@ -250,6 +250,10 @@ public class TunnelPoolManager implements TunnelManagerFacade {
         startup();
     }
         
+    /**
+     *  Used only at session startup.
+     *  Do not use to change settings.
+     */
     public void buildTunnels(Destination client, ClientTunnelSettings settings) {
         if (_log.shouldLog(Log.DEBUG))
             _log.debug("Building tunnels for the client " + client.calculateHash().toBase64() + ": " + settings);