Changeset 3fa2fb4

Timestamp:

Nov 11, 2015 1:38:24 PM (5 years ago)

Author:

zzz <zzz@…>

Branches:

master

Children:

e93e76a

Parents:

ffddf41

Message:

Timers: State fix 4th try (tickets #1694, #1705)
log tweaks

Files:

• core/java/src/net/i2p/util/SimpleTimer2.java (modified) (4 diffs)
• history.txt (modified) (1 diff)
• router/java/src/net/i2p/router/RouterVersion.java (modified) (1 diff)

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

@@ -296 +296 @@
                 // streaming timers do call with timeoutMs == 0
                 if (timeoutMs < 0 && _log.shouldLog(Log.WARN))
-                    _log.warn("Timeout <= 0: " + this + " timeout = " + timeoutMs + " state: " + _state);
+                    _log.warn("Sched. timeout <= 0: " + this + " timeout = " + timeoutMs + " state: " + _state);
                 timeoutMs = 1; // otherwise we may execute before _future is updated, which is fine
                                // except it triggers 'early execution' warning logging
@@ -338 +338 @@
          */
         public synchronized void reschedule(long timeoutMs, boolean useEarliestTime) {
+            if (timeoutMs <= 0) {
+                if (timeoutMs < 0 && _log.shouldWarn())
+                    _log.warn("Resched. timeout < 0: " + this + " timeout = " + timeoutMs + " state: " + _state);
+                timeoutMs = 1;
+            }
             final long now = System.currentTimeMillis();
             long oldTimeout;
@@ -350 +355 @@
                 (oldTimeout + _fuzz < timeoutMs && !useEarliestTime)||
                 (!scheduled)) {
+                if (scheduled && oldTimeout <= 5) {
+                    // don't reschedule to avoid race
+                    if (_log.shouldWarn())
+                        _log.warn("not rescheduling to " + timeoutMs + ", about to execute " + this + " in " + oldTimeout);
+                    return;
+                }
                 if (scheduled && (now + timeoutMs) < _nextRun) {
                     if (_log.shouldLog(Log.INFO))
@@ -383 +394 @@
                 return true;
               case SCHEDULED:
+                // There's probably a race here, where it's cancelled after it's running
+                // The result (if rescheduled) is a dup on the queue, see tickets 1694, 1705
+                // Mitigated by close-to-execution check in reschedule()
                 boolean cancelled = _future.cancel(false);
                 if (cancelled)
                     _state = TimedEventState.CANCELLED;
-                else 
-                    _log.warn("could not cancel "+this);
+                else
+                    _log.error("could not cancel " + this + " to run in " + (_nextRun - System.currentTimeMillis()), new Exception());
                 return cancelled;
             }

history.txt

@@ +1 @@
+2015-11-11 zzz
+ * i2psnark:
+   - Change log level to hide socket closed error at tunnel shutdown
+   - Increase max pieces
+ * Timers: State fix 4th try (tickets #1694, #1705)
+
 2015-11-05 zzz
  * I2CP: Fix additional connections getting rejected during tunnel open (ticket #1650)

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

@@ -19 +19 @@
     public final static String ID = "Monotone";
     public final static String VERSION = CoreVersion.VERSION;
-    public final static long BUILD = 24;
+    public final static long BUILD = 25;
 
     /** for example "-test" */