2004-11-27 jrandom

* Fix for a fast loop caused by a race in the new streaming library (thanks
      DrWoo, frontier, pwk_, and thetower!)
    * Minor updates to the SimpleTimer and Connection to help track down a
      high CPU usage problem (dumping debug info to stdout/wrapper.log if too
      many events/tasks fire in a second)
    * Minor fixes for races on client disconnects (causing NPEs)

apps/streaming/java/src/net/i2p/client/streaming/Connection.java

@@ -313,8 +313,26 @@ public class Connection {
         return acked;
     }
 
+    private long _occurredTime;
+    private long _occurredEventCount;
     void eventOccurred() {
-        _chooser.getScheduler(this).eventOccurred(this);
+        long now = System.currentTimeMillis();
+        
+        TaskScheduler sched = _chooser.getScheduler(this);
+        
+        now = now - now % 1000;
+        if (_occurredTime == now) {
+            _occurredEventCount++;
+        } else {
+            _occurredTime = now;
+            if (_occurredEventCount > 5) {
+                _log.log(Log.CRIT, "More than 5 events (" + _occurredEventCount + ") in a second on " 
+                                   + toString() + ": scheduler = " + sched);
+            }
+            _occurredEventCount = 0;
+        }
+            
+        sched.eventOccurred(this);
     }
     
     void resetReceived() {
@@ -376,10 +394,8 @@ public class Connection {
             _outputStream.destroy();
         _outputStream = null;
         _outboundQueue = null;
-        _handler = null;
         if (_receiver != null)
             _receiver.destroy();
-        _receiver = null;
         if (_activityTimer != null)
             SimpleTimer.getInstance().addEvent(_activityTimer, 1);
         _activityTimer = null;

apps/streaming/java/src/net/i2p/client/streaming/MessageOutputStream.java

@@ -79,6 +79,10 @@ public class MessageOutputStream extends OutputStream {
                     remaining -= toWrite;
                     cur += toWrite;
                     _valid = _buf.length;
+                    if (_dataReceiver == null) {
+                        throwAnyError();
+                        return;
+                    }
                     ws = _dataReceiver.writeData(_buf, 0, _valid);
                     _written += _valid;
                     _valid = 0;                       
@@ -117,6 +121,10 @@ public class MessageOutputStream extends OutputStream {
         WriteStatus ws = null;
         synchronized (_dataLock) {
             if (_buf == null) throw new IOException("closed (buffer went away)");
+            if (_dataReceiver == null) {
+                throwAnyError();
+                return;
+            }
             ws = _dataReceiver.writeData(_buf, 0, _valid);
             _written += _valid;
             _valid = 0;
@@ -164,7 +172,8 @@ public class MessageOutputStream extends OutputStream {
         ByteArray ba = null;
         synchronized (_dataLock) {
             // flush any data, but don't wait for it
-            _dataReceiver.writeData(_buf, 0, _valid);
+            if (_dataReceiver != null)
+                _dataReceiver.writeData(_buf, 0, _valid);
             _written += _valid;
             _valid = 0;
             

apps/streaming/java/src/net/i2p/client/streaming/SchedulerClosed.java

@@ -47,7 +47,8 @@ class SchedulerClosed extends SchedulerImpl {
     }
     
     public void eventOccurred(Connection con) {
-        long timeLeft = con.getCloseSentOn() + Connection.DISCONNECT_TIMEOUT - _context.clock().now();
-        reschedule(timeLeft, con);
+        // noop.  we do the timeout through the simpleTimer anyway
+        //long timeLeft = con.getCloseSentOn() + Connection.DISCONNECT_TIMEOUT - _context.clock().now();
+        //reschedule(timeLeft, con);
     }
 }

core/java/src/net/i2p/util/SimpleTimer.java

@@ -72,6 +72,10 @@ public class SimpleTimer {
         _log.log(Log.CRIT, msg, t);
     }
     
+    private long _occurredTime;
+    private long _occurredEventCount;
+    private TimedEvent _recentEvents[] = new TimedEvent[5];
+    
     private class SimpleTimerRunner implements Runnable {
         public void run() {
             List eventsToFire = new ArrayList(1);
@@ -121,6 +125,9 @@ public class SimpleTimer {
                     }
                 }
                 
+                long now = System.currentTimeMillis();
+                now = now - (now % 1000);
+
                 for (int i = 0; i < eventsToFire.size(); i++) {
                     TimedEvent evt = (TimedEvent)eventsToFire.get(i);
                     try {
@@ -128,7 +135,30 @@ public class SimpleTimer {
                     } catch (Throwable t) {
                         log("wtf, event borked: " + evt, t);
                     }
+                    _recentEvents[4] = _recentEvents[3];
+                    _recentEvents[3] = _recentEvents[2];
+                    _recentEvents[2] = _recentEvents[1];
+                    _recentEvents[1] = _recentEvents[0];
+                    _recentEvents[0] = evt;
                 }
+
+                if (_occurredTime == now) {
+                    _occurredEventCount += eventsToFire.size();
+                } else {
+                    _occurredTime = now;
+                    if (_occurredEventCount > 100) {
+                        StringBuffer buf = new StringBuffer(256);
+                        buf.append("Too many simpleTimerJobs (").append(_occurredEventCount);
+                        buf.append(") in a second!  Last 5: \n");
+                        for (int i = 0; i < _recentEvents.length; i++) {
+                            if (_recentEvents[i] != null)
+                                buf.append(_recentEvents[i]).append('\n');
+                        }
+                        _log.log(Log.CRIT, buf.toString());
+                    }
+                    _occurredEventCount = 0;
+                }
+
                 eventsToFire.clear();
             }
         }

history.txt

@@ -1,4 +1,12 @@
-$Id: history.txt,v 1.82 2004/11/25 16:57:19 jrandom Exp $
+$Id: history.txt,v 1.83 2004/11/26 10:20:14 jrandom Exp $
+
+2004-11-27  jrandom
+    * Fix for a fast loop caused by a race in the new streaming library (thanks
+      DrWoo, frontier, pwk_, and thetower!)
+    * Minor updates to the SimpleTimer and Connection to help track down a
+      high CPU usage problem (dumping debug info to stdout/wrapper.log if too
+      many events/tasks fire in a second)
+    * Minor fixes for races on client disconnects (causing NPEs)
 
 * 2004-11-26  0.4.2 released
 

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.87 $ $Date: 2004/11/25 16:57:20 $";
+    public final static String ID = "$Revision: 1.88 $ $Date: 2004/11/26 10:15:17 $";
     public final static String VERSION = "0.4.2";
-    public final static long BUILD = 0;
+    public final static long BUILD = 1;
     public static void main(String args[]) {
         System.out.println("I2P Router version: " + VERSION);
         System.out.println("Router ID: " + RouterVersion.ID);

router/java/src/net/i2p/router/client/ClientManager.java

@@ -159,6 +159,10 @@ public class ClientManager {
             if (_log.shouldLog(Log.DEBUG))
                 _log.debug("Message " + msgId + " is targeting a REMOTE destination!  Added to the client message pool");
             runner = getRunner(fromDest);
+            if (runner == null) {
+                // sender went away
+                return;
+            }
             ClientMessage msg = new ClientMessage();
             msg.setDestination(toDest);
             msg.setPayload(payload);