From 0b5a64089600792570e01777b8398623535f2261 Mon Sep 17 00:00:00 2001 From: jrandom Date: Sat, 27 Nov 2004 03:54:17 +0000 Subject: [PATCH] 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) --- .../net/i2p/client/streaming/Connection.java | 22 ++++++++++++-- .../client/streaming/MessageOutputStream.java | 11 ++++++- .../i2p/client/streaming/SchedulerClosed.java | 5 ++-- core/java/src/net/i2p/util/SimpleTimer.java | 30 +++++++++++++++++++ history.txt | 10 ++++++- .../src/net/i2p/router/RouterVersion.java | 4 +-- .../net/i2p/router/client/ClientManager.java | 4 +++ 7 files changed, 77 insertions(+), 9 deletions(-) diff --git a/apps/streaming/java/src/net/i2p/client/streaming/Connection.java b/apps/streaming/java/src/net/i2p/client/streaming/Connection.java index 45b5624f3..f2521d533 100644 --- a/apps/streaming/java/src/net/i2p/client/streaming/Connection.java +++ b/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; diff --git a/apps/streaming/java/src/net/i2p/client/streaming/MessageOutputStream.java b/apps/streaming/java/src/net/i2p/client/streaming/MessageOutputStream.java index b1a9ab113..32fd5c1cb 100644 --- a/apps/streaming/java/src/net/i2p/client/streaming/MessageOutputStream.java +++ b/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; diff --git a/apps/streaming/java/src/net/i2p/client/streaming/SchedulerClosed.java b/apps/streaming/java/src/net/i2p/client/streaming/SchedulerClosed.java index 3b665291d..08e79c3c0 100644 --- a/apps/streaming/java/src/net/i2p/client/streaming/SchedulerClosed.java +++ b/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); } } diff --git a/core/java/src/net/i2p/util/SimpleTimer.java b/core/java/src/net/i2p/util/SimpleTimer.java index 01f546809..0ce17b02e 100644 --- a/core/java/src/net/i2p/util/SimpleTimer.java +++ b/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(); } } diff --git a/history.txt b/history.txt index 6b29c704c..b26b22550 100644 --- a/history.txt +++ b/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 diff --git a/router/java/src/net/i2p/router/RouterVersion.java b/router/java/src/net/i2p/router/RouterVersion.java index f016d833b..0bd42245f 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.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); diff --git a/router/java/src/net/i2p/router/client/ClientManager.java b/router/java/src/net/i2p/router/client/ClientManager.java index f7be51faf..54bef14b6 100644 --- a/router/java/src/net/i2p/router/client/ClientManager.java +++ b/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);