From 43b71a263c29bc0ebd7e74f76e0aac934cd9042c Mon Sep 17 00:00:00 2001 From: zzz Date: Thu, 17 Dec 2009 23:45:20 +0000 Subject: [PATCH] * Tunnel building: - Increase timeout to 13s (was 10s) - Fix tunnel.buildReplyTooSlow stat - Tweak logging - Prioritize expl. builds over client builds - Code cleanups --- history.txt | 24 ++++++- .../src/net/i2p/router/RouterVersion.java | 2 +- .../i2p/router/tunnel/pool/BuildExecutor.java | 65 ++++++++++++++----- .../i2p/router/tunnel/pool/BuildHandler.java | 60 ++++++++++------- .../router/tunnel/pool/BuildRequestor.java | 23 +++++-- .../router/tunnel/pool/TunnelPoolManager.java | 4 ++ 6 files changed, 132 insertions(+), 46 deletions(-) diff --git a/history.txt b/history.txt index edb571f71..53b2645b1 100644 --- a/history.txt +++ b/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 diff --git a/router/java/src/net/i2p/router/RouterVersion.java b/router/java/src/net/i2p/router/RouterVersion.java index 0116da736..f47a425fd 100644 --- a/router/java/src/net/i2p/router/RouterVersion.java +++ b/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; diff --git a/router/java/src/net/i2p/router/tunnel/pool/BuildExecutor.java b/router/java/src/net/i2p/router/tunnel/pool/BuildExecutor.java index 24a41c6f8..e1cec3607 100644 --- a/router/java/src/net/i2p/router/tunnel/pool/BuildExecutor.java +++ b/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 _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 _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 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 pools = new ArrayList(8); + List wanted = new ArrayList(MAX_CONCURRENT_BUILDS); + List 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 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) - _recentBuildIds.remove(0); + // every so often, shrink the list semi-efficiently + if (_recentBuildIds.size() > 98) { + for (int i = 0; i < 32; i++) + _recentBuildIds.remove(0); + } _recentBuildIds.add(new Long(id)); } } diff --git a/router/java/src/net/i2p/router/tunnel/pool/BuildHandler.java b/router/java/src/net/i2p/router/tunnel/pool/BuildHandler.java index 465f21e33..8a48b5186 100644 --- a/router/java/src/net/i2p/router/tunnel/pool/BuildHandler.java +++ b/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; - /** list of BuildReplyMessageState, oldest first */ - private final List _inboundBuildReplyMessages; - /** list of BuildEndMessageState, oldest first */ - private final List _inboundBuildEndMessages; + private final List _inboundBuildMessages; + /** list of BuildReplyMessageState, oldest first - unused unless HANDLE_REPLIES_INLINE == false */ + private final List _inboundBuildReplyMessages; + /** list of BuildEndMessageState, oldest first - unused unless HANDLE_REPLIES_INLINE == false */ + private final List _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); - _inboundBuildEndMessages = new ArrayList(16); + if (HANDLE_REPLIES_INLINE) { + _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) { - int toHandle = _inboundBuildEndMessages.size(); - if (toHandle > 0) { - if (handled == null) - handled = new ArrayList(_inboundBuildEndMessages); - else - handled.addAll(_inboundBuildEndMessages); - _inboundBuildEndMessages.clear(); + if (!HANDLE_REPLIES_INLINE) { + synchronized (_inboundBuildEndMessages) { + int toHandle = _inboundBuildEndMessages.size(); + if (toHandle > 0) { + if (handled == null) + handled = new ArrayList(_inboundBuildEndMessages); + else + 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)) - _log.debug(msg.getUniqueId() + ": Handling the reply after " + rtt + ", delayed " + delay + " waiting for " + cfg); + if (_log.shouldLog(Log.INFO)) + _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; - private static final boolean HANDLE_REPLIES_INLINE = true; - + /** + * Handle incoming Tunnel Build Messages, which are generally requests to us, + * 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; diff --git a/router/java/src/net/i2p/router/tunnel/pool/BuildRequestor.java b/router/java/src/net/i2p/router/tunnel/pool/BuildRequestor.java index 3f5a2ea23..5340dfa1a 100644 --- a/router/java/src/net/i2p/router/tunnel/pool/BuildRequestor.java +++ b/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)) - log.debug("Sending the tunnel build request " + msg.getUniqueId() + " out the tunnel " + pairedTunnel + " to " + if (log.shouldLog(Log.INFO)) + 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)) - log.debug("Sending the tunnel build request directly to " + cfg.getPeer(1).toBase64() + if (log.shouldLog(Log.INFO)) + 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); diff --git a/router/java/src/net/i2p/router/tunnel/pool/TunnelPoolManager.java b/router/java/src/net/i2p/router/tunnel/pool/TunnelPoolManager.java index dab276069..1eae1de45 100644 --- a/router/java/src/net/i2p/router/tunnel/pool/TunnelPoolManager.java +++ b/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);