From d9b4406c09d0e334d72c6e3f5037130cc62e7211 Mon Sep 17 00:00:00 2001
From: jrandom <jrandom>
Date: Sun, 11 Sep 2005 03:22:51 +0000
Subject: [PATCH] 2005-09-10  jrandom     * Test the router's reachability
 earlier and more aggressively     * Use the low level bandwidth limiter's
 rates for the router console, and       if the router has
 net.i2p.router.transport.FIFOBandwidthLimiter=INFO in       the logger
 config, keep track of the 1 second transfer rates as the stat      
 'bw.sendBps1s' and 'bw.recvBps1s', allowing closer monitoring of burst      
 behavior.

---
 .../src/net/i2p/router/web/SummaryHelper.java | 74 +++++-----------
 history.txt                                   | 10 ++-
 router/doc/udp.html                           | 10 +--
 .../src/net/i2p/router/RouterVersion.java     |  4 +-
 .../transport/FIFOBandwidthLimiter.java       | 88 ++++++++++++++-----
 .../router/transport/udp/RemoteHostId.java    | 16 ++--
 .../router/transport/udp/UDPTransport.java    | 14 ++-
 7 files changed, 128 insertions(+), 88 deletions(-)

diff --git a/apps/routerconsole/java/src/net/i2p/router/web/SummaryHelper.java b/apps/routerconsole/java/src/net/i2p/router/web/SummaryHelper.java
index 7e33c51112..13880028fe 100644
--- a/apps/routerconsole/java/src/net/i2p/router/web/SummaryHelper.java
+++ b/apps/routerconsole/java/src/net/i2p/router/web/SummaryHelper.java
@@ -206,14 +206,12 @@ public class SummaryHelper {
         if (_context == null) 
             return "0.0";
         
-        RateStat receiveRate = _context.statManager().getRate("transport.receiveMessageSize");
+        RateStat receiveRate = _context.statManager().getRate("bw.recvRate");
         if (receiveRate == null) return "0.0";
         Rate rate = receiveRate.getRate(60*1000);
-        double bytes = rate.getLastTotalValue();
-        double bps = (bytes*1000.0d)/(rate.getPeriod()*1024.0d); 
-
-	DecimalFormat fmt = new DecimalFormat("##0.00");
-        return fmt.format(bps);
+        double kbps = rate.getAverageValue()/1024;
+        DecimalFormat fmt = new DecimalFormat("##0.00");
+        return fmt.format(kbps);
     }
     /**
      * How fast we have been sending data over the last minute (pretty printed
@@ -224,14 +222,12 @@ public class SummaryHelper {
         if (_context == null) 
             return "0.0";
         
-        RateStat receiveRate = _context.statManager().getRate("transport.sendMessageSize");
+        RateStat receiveRate = _context.statManager().getRate("bw.sendRate");
         if (receiveRate == null) return "0.0";
         Rate rate = receiveRate.getRate(60*1000);
-        double bytes = rate.getLastTotalValue();
-        double bps = (bytes*1000.0d)/(rate.getPeriod()*1024.0d); 
-
-	DecimalFormat fmt = new DecimalFormat("##0.00");
-        return fmt.format(bps);
+        double kbps = rate.getAverageValue()/1024;
+        DecimalFormat fmt = new DecimalFormat("##0.00");
+        return fmt.format(kbps);
     }
     
     /**
@@ -243,14 +239,12 @@ public class SummaryHelper {
         if (_context == null) 
             return "0.0";
         
-        RateStat receiveRate = _context.statManager().getRate("transport.receiveMessageSize");
+        RateStat receiveRate = _context.statManager().getRate("bw.recvBps");
         if (receiveRate == null) return "0.0";
         Rate rate = receiveRate.getRate(5*60*1000);
-        double bytes = rate.getLastTotalValue();
-        double bps = (bytes*1000.0d)/(rate.getPeriod()*1024.0d); 
-
-	DecimalFormat fmt = new DecimalFormat("##0.00");
-        return fmt.format(bps);
+        double kbps = rate.getAverageValue()/1024;
+        DecimalFormat fmt = new DecimalFormat("##0.00");
+        return fmt.format(kbps);
     }
     
     /**
@@ -262,14 +256,12 @@ public class SummaryHelper {
         if (_context == null) 
             return "0.0";
         
-        RateStat receiveRate = _context.statManager().getRate("transport.sendMessageSize");
+        RateStat receiveRate = _context.statManager().getRate("bw.sendBps");
         if (receiveRate == null) return "0.0";
         Rate rate = receiveRate.getRate(5*60*1000);
-        double bytes = rate.getLastTotalValue();
-        double bps = (bytes*1000.0d)/(rate.getPeriod()*1024.0d); 
-
-	DecimalFormat fmt = new DecimalFormat("##0.00");
-        return fmt.format(bps);
+        double kbps = rate.getAverageValue()/1024;
+        DecimalFormat fmt = new DecimalFormat("##0.00");
+        return fmt.format(kbps);
     }
     
     /**
@@ -281,20 +273,11 @@ public class SummaryHelper {
         if (_context == null) 
             return "0.0";
         
-        long received = _context.bandwidthLimiter().getTotalAllocatedInboundBytes();
-
+        RateStat receiveRate = _context.statManager().getRate("bw.recvBps");
+        if (receiveRate == null) return "0.0";
+        double kbps = receiveRate.getLifetimeAverageValue()/1024;
         DecimalFormat fmt = new DecimalFormat("##0.00");
-
-        // we use the unadjusted time, since thats what getWhenStarted is based off
-        long lifetime = _context.clock().now()-_context.clock().getOffset()
-                        - _context.router().getWhenStarted();
-        lifetime /= 1000;
-        if (received > 0) {
-            double receivedKBps = received / (lifetime*1024.0);
-            return fmt.format(receivedKBps);
-        } else {
-            return "0.0";
-        }
+        return fmt.format(kbps);
     }
     
     /**
@@ -306,20 +289,11 @@ public class SummaryHelper {
         if (_context == null) 
             return "0.0";
         
-        long sent = _context.bandwidthLimiter().getTotalAllocatedOutboundBytes();
-
+        RateStat sendRate = _context.statManager().getRate("bw.sendBps");
+        if (sendRate == null) return "0.0";
+        double kbps = sendRate.getLifetimeAverageValue()/1024;
         DecimalFormat fmt = new DecimalFormat("##0.00");
-
-        // we use the unadjusted time, since thats what getWhenStarted is based off
-        long lifetime = _context.clock().now()-_context.clock().getOffset() 
-                        - _context.router().getWhenStarted();
-        lifetime /= 1000;
-        if (sent > 0) {
-            double sendKBps = sent / (lifetime*1024.0);
-            return fmt.format(sendKBps);
-        } else {
-            return "0.0";
-        }
+        return fmt.format(kbps);
     }
     
     /**
diff --git a/history.txt b/history.txt
index ef97851b9e..f48bb43c0f 100644
--- a/history.txt
+++ b/history.txt
@@ -1,4 +1,12 @@
-$Id: history.txt,v 1.242 2005/09/09 20:13:50 cervantes Exp $
+$Id: history.txt,v 1.243 2005/09/09 23:30:37 jrandom Exp $
+
+2005-09-10  jrandom
+    * Test the router's reachability earlier and more aggressively
+    * Use the low level bandwidth limiter's rates for the router console, and
+      if the router has net.i2p.router.transport.FIFOBandwidthLimiter=INFO in
+      the logger config, keep track of the 1 second transfer rates as the stat
+      'bw.sendBps1s' and 'bw.recvBps1s', allowing closer monitoring of burst 
+      behavior.
 
 2005-09-09  jrandom
     * Added preliminary support for NAT hole punching through SSU introducers
diff --git a/router/doc/udp.html b/router/doc/udp.html
index 516b415325..7768c8e890 100644
--- a/router/doc/udp.html
+++ b/router/doc/udp.html
@@ -1,4 +1,4 @@
-<code>$Id: udp.html,v 1.16 2005/08/17 15:05:02 jrandom Exp $</code>
+<code>$Id: udp.html,v 1.17 2005/09/09 23:30:37 jrandom Exp $</code>
 
 <h1>Secure Semireliable UDP (SSU)</h1>
 <b>DRAFT</b>
@@ -743,12 +743,12 @@ with either Bob or Charlie, but it is not required.</p>
 <h2><a name="capabilities">Peer capabilities</a></h2>
 
 <dl>
- <dt>A</dt>
- <dd>If the peer address contains the 'A' capability, that means 
+ <dt>B</dt>
+ <dd>If the peer address contains the 'B' capability, that means 
      they are willing and able to participate in peer tests as
      a 'Bob' or 'Charlie'.</dd>
- <dt>B</dt>
- <dd>If the peer address contains the 'B' capability, that means
+ <dt>C</dt>
+ <dd>If the peer address contains the 'C' capability, that means
      they are willing and able to serve as an introducer - serving
      as a Bob for an otherwise unreachable Alice.</dd>
 </dl>
diff --git a/router/java/src/net/i2p/router/RouterVersion.java b/router/java/src/net/i2p/router/RouterVersion.java
index bcb2539d04..35bddc1092 100644
--- a/router/java/src/net/i2p/router/RouterVersion.java
+++ b/router/java/src/net/i2p/router/RouterVersion.java
@@ -15,9 +15,9 @@ import net.i2p.CoreVersion;
  *
  */
 public class RouterVersion {
-    public final static String ID = "$Revision: 1.229 $ $Date: 2005/09/09 20:13:49 $";
+    public final static String ID = "$Revision: 1.230 $ $Date: 2005/09/09 23:30:36 $";
     public final static String VERSION = "0.6.0.5";
-    public final static long BUILD = 4;
+    public final static long BUILD = 5;
     public static void main(String args[]) {
         System.out.println("I2P Router version: " + VERSION + "-" + BUILD);
         System.out.println("Router ID: " + RouterVersion.ID);
diff --git a/router/java/src/net/i2p/router/transport/FIFOBandwidthLimiter.java b/router/java/src/net/i2p/router/transport/FIFOBandwidthLimiter.java
index c8a52d1952..de81ed2857 100644
--- a/router/java/src/net/i2p/router/transport/FIFOBandwidthLimiter.java
+++ b/router/java/src/net/i2p/router/transport/FIFOBandwidthLimiter.java
@@ -26,6 +26,13 @@ public class FIFOBandwidthLimiter {
     private int _maxOutboundBytes;
     private FIFOBandwidthRefiller _refiller;
     
+    private long _lastTotalSent;
+    private long _lastTotalReceived;
+    private long _lastStatsUpdated;
+    private long _lastRateUpdated;
+    private float _sendBps;
+    private float _recvBps;
+    
     private static int __id = 0;
     
     public FIFOBandwidthLimiter(I2PAppContext context) {
@@ -35,8 +42,16 @@ public class FIFOBandwidthLimiter {
         _context.statManager().createRateStat("bwLimiter.pendingInboundRequests", "How many inbound requests are ahead of the current one (ignoring ones with 0)?", "BandwidthLimiter", new long[] { 60*1000l, 5*60*1000l, 10*60*1000l, 60*60*1000l });
         _context.statManager().createRateStat("bwLimiter.outboundDelayedTime", "How long it takes to honor an outbound request (ignoring ones with that go instantly)?", "BandwidthLimiter", new long[] { 60*1000l, 5*60*1000l, 10*60*1000l, 60*60*1000l });
         _context.statManager().createRateStat("bwLimiter.inboundDelayedTime", "How long it takes to honor an inbound request (ignoring ones with that go instantly)?", "BandwidthLimiter", new long[] { 60*1000l, 5*60*1000l, 10*60*1000l, 60*60*1000l });
+        _context.statManager().createRateStat("bw.sendRate", "Low level bandwidth send rate, averaged every minute", "BandwidthLimiter", new long[] { 60*1000l, 5*60*1000l, 10*60*1000l, 60*60*1000l });
+        _context.statManager().createRateStat("bw.recvRate", "Low level bandwidth receive rate, averaged every minute", "BandwidthLimiter", new long[] { 60*1000l, 5*60*1000l, 10*60*1000l, 60*60*1000l });
         _pendingInboundRequests = new ArrayList(16);
         _pendingOutboundRequests = new ArrayList(16);
+        _lastTotalSent = _totalAllocatedOutboundBytes;
+        _lastTotalReceived = _totalAllocatedInboundBytes;
+        _sendBps = 0;
+        _recvBps = 0;
+        _lastStatsUpdated = _context.clock().now();
+        _lastRateUpdated = _lastStatsUpdated;
         _refiller = new FIFOBandwidthRefiller(_context, this);
         I2PThread t = new I2PThread(_refiller);
         t.setName("BWRefiller" + (++__id));
@@ -133,6 +148,39 @@ public class FIFOBandwidthLimiter {
             _availableOutboundBytes = _maxOutboundBytes;
         }
         satisfyRequests();
+        updateStats();
+    }
+    
+    private void updateStats() {
+        long now = _context.clock().now();
+        long time = now - _lastStatsUpdated;
+        if (time >= 1000) {
+            long totS = _totalAllocatedOutboundBytes;
+            long totR = _totalAllocatedInboundBytes;
+            long sent = totS - _lastTotalSent;
+            long recv = totR - _lastTotalReceived;
+            _lastTotalSent = totS;
+            _lastTotalReceived = totR;
+            _lastStatsUpdated = now;
+            if (_sendBps <= 0)
+                _sendBps = ((float)sent*time)/1000f;
+            else
+                _sendBps = (0.9f)*_sendBps + (0.1f)*((float)sent*time)/1000f;
+            if (_recvBps <= 0)
+                _recvBps = ((float)recv*time)/1000f;
+            else
+                _recvBps = (0.9f)*_recvBps + (0.1f)*((float)recv*time)/1000f;
+            if (_log.shouldLog(Log.INFO)) {
+                _log.info("BW: time = " + time + " sent: " + sent + " recv: " + recv);
+                _context.statManager().getStatLog().addData("bw", "bw.sendBps1s", (long)_sendBps, sent);
+                _context.statManager().getStatLog().addData("bw", "bw.recvBps1s", (long)_recvBps, recv);
+            }
+        }
+        if (60*1000 + _lastRateUpdated <= now) {
+            _lastRateUpdated = now;
+            _context.statManager().addRateData("bw.sendRate", (long)_sendBps, 0);
+            _context.statManager().addRateData("bw.recvRate", (long)_recvBps, 0);
+        }
     }
     
     /**
@@ -154,8 +202,8 @@ public class FIFOBandwidthLimiter {
                     satisfied = locked_satisfyInboundAvailable();
                 } else {
                     // no bandwidth available
-                    if (_log.shouldLog(Log.WARN))
-                        _log.warn("Still denying the " + _pendingInboundRequests.size() 
+                    if (_log.shouldLog(Log.DEBUG))
+                        _log.debug("Still denying the " + _pendingInboundRequests.size() 
                                   + " pending inbound requests (available "
                                   + _availableInboundBytes + "/" + _availableOutboundBytes 
                                   + " in/out, longest waited " + locked_getLongestInboundWait() + " in)");
@@ -213,8 +261,8 @@ public class FIFOBandwidthLimiter {
                 satisfied = new ArrayList(2);
             satisfied.add(req);
             long waited = _context.clock().now() - req.getRequestTime();
-            if (_log.shouldLog(Log.INFO))
-                 _log.info("Granting inbound request " + req.getRequestName() + " fully for " 
+            if (_log.shouldLog(Log.DEBUG))
+                 _log.debug("Granting inbound request " + req.getRequestName() + " fully for " 
                             + req.getTotalInboundRequested() + " bytes (waited " 
                             + waited
                             + "ms) pending " + _pendingInboundRequests.size());
@@ -240,8 +288,8 @@ public class FIFOBandwidthLimiter {
             long waited = _context.clock().now() - req.getRequestTime();
             if (req.getAborted()) {
                 // connection decided they dont want the data anymore
-                if (_log.shouldLog(Log.INFO))
-                     _log.info("Aborting inbound request to " 
+                if (_log.shouldLog(Log.DEBUG))
+                     _log.debug("Aborting inbound request to " 
                                 + req.getRequestName() + " (total " 
                                 + req.getTotalInboundRequested() + " bytes, waited " 
                                 + waited
@@ -270,16 +318,16 @@ public class FIFOBandwidthLimiter {
                 satisfied = new ArrayList(2);
             satisfied.add(req);
             if (req.getPendingInboundRequested() > 0) {
-                if (_log.shouldLog(Log.INFO))
-                     _log.info("Allocating " + allocated + " bytes inbound as a partial grant to " 
+                if (_log.shouldLog(Log.DEBUG))
+                     _log.debug("Allocating " + allocated + " bytes inbound as a partial grant to " 
                                 + req.getRequestName() + " (wanted " 
                                 + req.getTotalInboundRequested() + " bytes, waited " 
                                 + waited
                                 + "ms) pending " + _pendingInboundRequests.size()
                                 + ", longest waited " + locked_getLongestInboundWait() + " in");
             } else {
-                if (_log.shouldLog(Log.INFO))
-                     _log.info("Allocating " + allocated + " bytes inbound to finish the partial grant to " 
+                if (_log.shouldLog(Log.DEBUG))
+                     _log.debug("Allocating " + allocated + " bytes inbound to finish the partial grant to " 
                                 + req.getRequestName() + " (total " 
                                 + req.getTotalInboundRequested() + " bytes, waited " 
                                 + waited
@@ -304,8 +352,8 @@ public class FIFOBandwidthLimiter {
                     satisfied = locked_satisfyOutboundAvailable();
                 } else {
                     // no bandwidth available
-                    if (_log.shouldLog(Log.WARN))
-                        _log.warn("Still denying the " + _pendingOutboundRequests.size() 
+                    if (_log.shouldLog(Log.DEBUG))
+                        _log.debug("Still denying the " + _pendingOutboundRequests.size() 
                                   + " pending outbound requests (available "
                                   + _availableInboundBytes + "/" + _availableOutboundBytes + " in/out, "
                                   + "longest waited " + locked_getLongestOutboundWait() + " out)");
@@ -337,8 +385,8 @@ public class FIFOBandwidthLimiter {
                 satisfied = new ArrayList(2);
             satisfied.add(req);
             long waited = _context.clock().now() - req.getRequestTime();
-            if (_log.shouldLog(Log.INFO))
-                 _log.info("Granting outbound request " + req.getRequestName() + " fully for " 
+            if (_log.shouldLog(Log.DEBUG))
+                 _log.debug("Granting outbound request " + req.getRequestName() + " fully for " 
                             + req.getTotalOutboundRequested() + " bytes (waited " 
                             + waited
                             + "ms) pending " + _pendingOutboundRequests.size()
@@ -365,8 +413,8 @@ public class FIFOBandwidthLimiter {
             long waited = _context.clock().now() - req.getRequestTime();
             if (req.getAborted()) {
                 // connection decided they dont want the data anymore
-                if (_log.shouldLog(Log.INFO))
-                     _log.info("Aborting outbound request to " 
+                if (_log.shouldLog(Log.DEBUG))
+                     _log.debug("Aborting outbound request to " 
                                 + req.getRequestName() + " (total " 
                                 + req.getTotalOutboundRequested() + " bytes, waited " 
                                 + waited
@@ -395,16 +443,16 @@ public class FIFOBandwidthLimiter {
                 satisfied = new ArrayList(2);
             satisfied.add(req);
             if (req.getPendingOutboundRequested() > 0) {
-                if (_log.shouldLog(Log.INFO))
-                     _log.info("Allocating " + allocated + " bytes outbound as a partial grant to " 
+                if (_log.shouldLog(Log.DEBUG))
+                     _log.debug("Allocating " + allocated + " bytes outbound as a partial grant to " 
                                 + req.getRequestName() + " (wanted " 
                                 + req.getTotalOutboundRequested() + " bytes, waited " 
                                 + waited
                                 + "ms) pending " + _pendingOutboundRequests.size()
                                 + ", longest waited " + locked_getLongestOutboundWait() + " out");
             } else {
-                if (_log.shouldLog(Log.INFO))
-                     _log.info("Allocating " + allocated + " bytes outbound to finish the partial grant to " 
+                if (_log.shouldLog(Log.DEBUG))
+                     _log.debug("Allocating " + allocated + " bytes outbound to finish the partial grant to " 
                                 + req.getRequestName() + " (total " 
                                 + req.getTotalOutboundRequested() + " bytes, waited " 
                                 + waited
diff --git a/router/java/src/net/i2p/router/transport/udp/RemoteHostId.java b/router/java/src/net/i2p/router/transport/udp/RemoteHostId.java
index 2e7b69dfb2..3f0e8cc2d4 100644
--- a/router/java/src/net/i2p/router/transport/udp/RemoteHostId.java
+++ b/router/java/src/net/i2p/router/transport/udp/RemoteHostId.java
@@ -38,14 +38,18 @@ final class RemoteHostId {
     
     public String toString() { return toString(true); }
     public String toString(boolean includePort) {
-        StringBuffer buf = new StringBuffer(_ip.length + 5);
-        for (int i = 0; i < _ip.length; i++) {
-            buf.append(_ip[i]&0xFF);
-            if (i + 1 < _ip.length)
+        if (includePort)
+            return toString(_ip) + ':' + _port;
+        else
+            return toString(_ip);
+    }
+    public static String toString(byte ip[]) {
+        StringBuffer buf = new StringBuffer(ip.length+5);
+        for (int i = 0; i < ip.length; i++) {
+            buf.append(ip[i]&0xFF);
+            if (i + 1 < ip.length)
                 buf.append('.');
         }
-        if (includePort) 
-            buf.append(':').append(_port);
         return buf.toString();
     }
     public String toHostString() { return toString(false); }
diff --git a/router/java/src/net/i2p/router/transport/udp/UDPTransport.java b/router/java/src/net/i2p/router/transport/udp/UDPTransport.java
index 7496223177..1f0b1374d5 100644
--- a/router/java/src/net/i2p/router/transport/udp/UDPTransport.java
+++ b/router/java/src/net/i2p/router/transport/udp/UDPTransport.java
@@ -282,8 +282,8 @@ public class UDPTransport extends TransportImpl implements TimedWeightedPriority
      *
      */
     void externalAddressReceived(byte ourIP[], int ourPort) {
-        if (_log.shouldLog(Log.DEBUG))
-            _log.debug("External address received: " + Base64.encode(ourIP) + ":" + ourPort);
+        if (_log.shouldLog(Log.INFO))
+            _log.info("External address received: " + RemoteHostId.toString(ourIP) + ":" + ourPort);
         
         if (explicitAddressSpecified()) 
             return;
@@ -294,7 +294,7 @@ public class UDPTransport extends TransportImpl implements TimedWeightedPriority
         synchronized (this) {
             if ( (_externalListenHost == null) ||
                  (!eq(_externalListenHost.getAddress(), _externalListenPort, ourIP, ourPort)) ) {
-                if ( (_reachabilityStatus != CommSystemFacade.STATUS_OK) ||
+                if ( (_reachabilityStatus == CommSystemFacade.STATUS_UNKNOWN) ||
                      (_context.clock().now() - _reachabilityStatusLastUpdated > 2*TEST_FREQUENCY) ) {
                     // they told us something different and our tests are either old or failing
                     try {
@@ -515,6 +515,11 @@ public class UDPTransport extends TransportImpl implements TimedWeightedPriority
         // if we need introducers, try to shift 'em around every 10 minutes
         if (introducersRequired() && (_introducersSelectedOn < _context.clock().now() - 10*60*1000))
             rebuildExternalAddress();
+        
+        if (getReachabilityStatus() != CommSystemFacade.STATUS_OK) {
+            _testEvent.forceRun();
+            SimpleTimer.getInstance().addEvent(_testEvent, 0);
+        }
         return true;
     }
     
@@ -1240,9 +1245,10 @@ public class UDPTransport extends TransportImpl implements TimedWeightedPriority
                     _log.error("Unable to run a periodic test, as there are no peers with the capacity required");
             }
             _lastTested = _context.clock().now();
+            _forceRun = false;
         }
         
-        private void forceRun() { _forceRun = true; }
+        void forceRun() { _forceRun = true; }
         
         public void setIsAlive(boolean isAlive) {
             _alive = isAlive;
-- 
GitLab