Opened 2 months ago

Closed 7 weeks ago

Last modified 6 weeks ago

#2710 closed defect (fixed)

Streaming: Retransmit timer needs to be reset after an ACK (rfc 6298 section 5.3)

Reported by: Zlatin Balevsky Owned by: zzz
Priority: minor Milestone: 0.9.46
Component: streaming Version: 0.9.45
Keywords: Cc:
Parent Tickets: Sensitive: no

Description

Right now every packet that gets sent has an associated retransmit event which triggers exactly at 1*RTO. However, rfc 6298 section 5.3 states:

   (5.3) When an ACK is received that acknowledges new data, restart the
         retransmission timer so that it will expire after RTO seconds
         (for the current value of RTO).

I don't see where we do that. So I put together the following patch:

--- a/apps/streaming/java/src/net/i2p/client/streaming/impl/Connection.java
+++ b/apps/streaming/java/src/net/i2p/client/streaming/impl/Connection.java
@@ -71,6 +71,7 @@ class Connection {
     private int _lastCongestionSeenAt;
     private long _lastCongestionTime;
     private volatile long _lastCongestionHighestUnacked;
+    private volatile long _nextRetransmitTime;
     /** has the other side choked us? */
     private volatile boolean _isChoked;
     /** are we choking the other side? */
@@ -559,8 +560,10 @@ class Connection {
             }
             _outboundPackets.notifyAll();
         }
-        if ((acked != null) && (!acked.isEmpty()) )
+        if ((acked != null) && (!acked.isEmpty()) ) {
             _ackSinceCongestion.set(true);
+            _nextRetransmitTime = _context.clock().now() + getOptions().getRTO();
+        }
         return acked;
     }
 
@@ -1454,6 +1457,16 @@ class Connection {
                 _packet.cancelled();
                 return false;
             }
+
+            long now = _context.clock().now();
+            long nextRetransmitTime = _nextRetransmitTime;
+            if (nextRetransmitTime > now) {
+                long delay = nextRetransmitTime - now;
+                if (_log.shouldLog(Log.DEBUG))
+                    _log.debug("Resend time reached but will be delayed " + delay + " for packet " + _packet);
+                forceReschedule(delay);
+                return false;
+            }
             
             //if (_log.shouldLog(Log.DEBUG))
             //    _log.debug("Resend period reached for " + _packet);

A side effect, or maybe intended effect of this is that congestions are considered to be happening much less frequently, leading to higher window sizes and higher throughput. I will attach some data once I have it.

Subtickets

Attachments (1)

2710.ods (142.1 KB) - added by Zlatin Balevsky 2 months ago.
Raw data and charts of window metrics - vanilla vs. patched

Download all attachments as: .zip

Change History (11)

Changed 2 months ago by Zlatin Balevsky

Attachment: 2710.ods added

Raw data and charts of window metrics - vanilla vs. patched

comment:1 Changed 2 months ago by Zlatin Balevsky

The attachment above is from the live net, eepget download of a 16MB file. The patched version died after downloading 12MB, vanilla after 2MB, that's why there is much less data for it.

I extract the data the following way:

grep "New window size" log-router-0.txt | cut -d' ' -f 24,26,28,30 | sed "s/ /,/g" > window.csv

comment:2 Changed 2 months ago by Zlatin Balevsky

Noticed the patch in OP breaks fast retransmit. The following update fixes that:

--- a/apps/streaming/java/src/net/i2p/client/streaming/impl/Connection.java
+++ b/apps/streaming/java/src/net/i2p/client/streaming/impl/Connection.java
@@ -71,6 +71,7 @@ class Connection {
     private int _lastCongestionSeenAt;
     private long _lastCongestionTime;
     private volatile long _lastCongestionHighestUnacked;
+    private volatile long _nextRetransmitTime;
     /** has the other side choked us? */
     private volatile boolean _isChoked;
     /** are we choking the other side? */
@@ -559,8 +560,10 @@ class Connection {
             }
             _outboundPackets.notifyAll();
         }
-        if ((acked != null) && (!acked.isEmpty()) )
+        if ((acked != null) && (!acked.isEmpty()) ) {
             _ackSinceCongestion.set(true);
+            _nextRetransmitTime = _context.clock().now() + getOptions().getRTO();
+        }
         return acked;
     }
 
@@ -1422,6 +1425,7 @@ class Connection {
     class ResendPacketEvent extends SimpleTimer2.TimedEvent {
         private final PacketLocal _packet;
         private long _nextSend;
+        private boolean _fastRetransmit;
 
         public ResendPacketEvent(PacketLocal packet, long delay) {
             super(_timer);
@@ -1435,6 +1439,11 @@ class Connection {
 
         public void timeReached() { retransmit(); }
 
+        void fastRetransmit() {
+            _fastRetransmit = true;
+            reschedule(0);
+        }
+
         /**
          * Retransmit the packet if we need to.  
          *
@@ -1454,6 +1463,16 @@ class Connection {
                 _packet.cancelled();
                 return false;
             }
+
+            long now = _context.clock().now();
+            long nextRetransmitTime = _nextRetransmitTime;
+            if (nextRetransmitTime > now  && !_fastRetransmit) {
+                long delay = nextRetransmitTime - now;
+                if (_log.shouldLog(Log.DEBUG))
+                    _log.debug("Resend time reached but will be delayed " + delay + " for packet " + _packet);
+                forceReschedule(delay);
+                return false;
+            }
             
             //if (_log.shouldLog(Log.DEBUG))
             //    _log.debug("Resend period reached for " + _packet);
@@ -1471,8 +1490,7 @@ class Connection {
                     resend = true;
             }
             if ( (resend) && (_packet.getAckTime() <= 0) ) {
-                boolean fastRetransmit = ( (_packet.getNACKs() >= FAST_RETRANSMIT_THRESHOLD) && (_packet.getNumSends() == 1));
-                if ( (!isLowest) && (!fastRetransmit) ) {
+                if ( (!isLowest) && (!_fastRetransmit) ) {
                     // we want to resend this packet, but there are already active
                     // resends in the air and we dont want to make a bad situation 
                     // worse.  wait another second
@@ -1489,7 +1507,7 @@ class Connection {
                 
                 // It's the lowest, or it's fast retransmit time. Resend the packet.
 
-                if (fastRetransmit)
+                if (_fastRetransmit)
                     _context.statManager().addRateData("stream.fastRetransmit", _packet.getLifetime(), _packet.getLifetime());
                 
                 // revamp various fields, in case we need to ack more, etc
@@ -1593,7 +1611,7 @@ class Connection {
                             _activeResends.incrementAndGet();
                         if (_log.shouldLog(Log.INFO))
                             _log.info("Resent packet " +
-                                  (fastRetransmit ? "(fast) " : "(timeout) ") +
+                                  (_fastRetransmit ? "(fast) " : "(timeout) ") +
                                   _packet +
                                   " next resend in " + timeout + "ms" +
                                   " activeResends: " + _activeResends + 
@@ -1602,6 +1620,7 @@ class Connection {
                                   + (_context.clock().now() - _packet.getCreatedOn()) + "ms)");
                         _unackedPacketsReceived.set(0);
                         _lastSendTime = _context.clock().now();
+                        _fastRetransmit = false;
                         // timer reset added 0.9.1
                         resetActivityTimer();
                     }
diff --git a/apps/streaming/java/src/net/i2p/client/streaming/impl/PacketLocal.java b/apps/streaming/java/src/net/i2p/client/streaming/impl/PacketLocal.java
index 4a2ada514..027996cb2 100644
--- a/apps/streaming/java/src/net/i2p/client/streaming/impl/PacketLocal.java
+++ b/apps/streaming/java/src/net/i2p/client/streaming/impl/PacketLocal.java
@@ -189,11 +189,11 @@ class PacketLocal extends Packet implements MessageOutputStream.WriteStatus {
      */
     public void incrementNACKs() { 
         final int cnt = _nackCount.incrementAndGet();
-        SimpleTimer2.TimedEvent evt = _resendEvent;
+        Connection.ResendPacketEvent evt = (Connection.ResendPacketEvent) _resendEvent;
         if (cnt >= Connection.FAST_RETRANSMIT_THRESHOLD && evt != null && (!_retransmitted) &&
             (_numSends.get() == 1 || _lastSend < _context.clock().now() - 4*1000)) {  // Don't fast retx if we recently resent it
             _retransmitted = true;
-            evt.reschedule(0);
+            evt.fastRetransmit();
             // the predicate used to be '+', changing to '-' --zab
             
             if (_log.shouldLog(Log.DEBUG)) {

comment:3 Changed 2 months ago by zzz

Version: 0.9.460.9.45

We already have a _nextSendTime, getNextSendTime(), setNextSendTime(), I think that is the 6298 "retransmission timer". Why do we need another variable? Let's step back and look at that variable and try to understand better what's happening here.

comment:4 Changed 2 months ago by Zlatin Balevsky

That variable is used for delaying/scheduling ACKs only. The only place it's read is in SchedulerConnectedBulk.eventOccurred() which in turn calls Connection.sendAvailable(). That in turn calls MessageOutputStream.flushAvailable(). If there is no data pending on the connection, an ACK-only packet is built and sent.

comment:5 Changed 2 months ago by Zlatin Balevsky

The only place it's read is in SchedulerConnectedBulk?.eventOccurred()

After the connection has been established that is. I didn't check the other usages of the variable, but it's clear that it is not related to resends.

comment:6 Changed 8 weeks ago by zzz

Add a subticket #2715 (Streaming: single retransmit timer per connection).

comment:7 Changed 7 weeks ago by zzz

Milestone: undecided0.9.46
Owner: set to zzz
Status: newaccepted

Agreed with the assessment of 6298 sec. 5.3. The patch will extend the timer of each ResendPacketEvent? as it gets there. In the (unlikely?) case that the ack would set the retransmit time earlier, the patch doesn't address that. We would need to iterate through all the pending packets and reschedule each timer. That's probably not worth the effort as #2715 addresses this much more elegantly.

The window size chart in the attachment is impressive.

Reviewed only, not tested by me yet, but looks good. Decision whether #2715 goes after this ticket or in place of it TBD but at least one of them should be in 46.

comment:8 Changed 7 weeks ago by zzz

Remove a subticket #2715 (Streaming: single retransmit timer per connection).

comment:9 Changed 7 weeks ago by zzz

Resolution: fixed
Status: acceptedclosed

Combined patch with #2708 in 50c3a79c761dfbb1eb24e4af01c6e2fdef6df736 0.9.45-9

comment:10 Changed 6 weeks ago by Zlatin Balevsky

Remove a subticket #2711 (Streaming: allow more than one fast retransmit per packet).

Note: See TracTickets for help on using tickets.