Log correct delay when performing TCP retransmit.

whitequark · whitequark · commit c0629f769ba0 · 2017-07-23T05:09:38.000Z
Before, the delay was erroneously multiplied by 2 and also did not
take processing delay into account.
diff --git a/src/socket/tcp.rs b/src/socket/tcp.rs
@@ -201,17 +201,18 @@ impl Retransmit {
         }
     }
 
-    fn commit(&mut self, timestamp: u64) -> bool {
+    fn commit(&mut self, timestamp: u64) -> Option<u64> {
         if self.delay == 0 {
             self.delay      = 100; // ms
             self.resend_at  = timestamp + self.delay;
-            false
+            None
         } else if timestamp >= self.resend_at {
+            let actual_delay = (timestamp - self.resend_at) + self.delay;
             self.resend_at  = timestamp + self.delay;
             self.delay     *= 2;
-            true
+            Some(actual_delay)
         } else {
-            false
+            None
         }
     }
 }
@@ -1109,10 +1110,10 @@ impl<'a> TcpSocket<'a> {
         }
 
         if should_send {
-            if self.retransmit.commit(timestamp) {
-                net_trace!("[{}]{}:{}: retransmit after {}ms",
+            if let Some(actual_delay) = self.retransmit.commit(timestamp) {
+                net_trace!("[{}]{}:{}: retransmitting at t+{}ms ",
                            self.debug_id, self.local_endpoint, self.remote_endpoint,
-                           self.retransmit.delay);
+                           actual_delay);
             }
 
             if self.state != State::SynSent {

Original file line number	Diff line number	Diff line change
`@@ -201,17 +201,18 @@ impl Retransmit {`
`201`	`201`	`}`
`202`	`202`	`}`
`203`	`203`
`204`		`- fn commit(&mut self, timestamp: u64) -> bool {`
	`204`	`+ fn commit(&mut self, timestamp: u64) -> Option<u64> {`
`205`	`205`	`if self.delay == 0 {`
`206`	`206`	`self.delay = 100; // ms`
`207`	`207`	`self.resend_at = timestamp + self.delay;`
`208`		`- false`
	`208`	`+ None`
`209`	`209`	`} else if timestamp >= self.resend_at {`
	`210`	`+ let actual_delay = (timestamp - self.resend_at) + self.delay;`
`210`	`211`	`self.resend_at = timestamp + self.delay;`
`211`	`212`	`self.delay *= 2;`
`212`		`- true`
	`213`	`+ Some(actual_delay)`
`213`	`214`	`} else {`
`214`		`- false`
	`215`	`+ None`
`215`	`216`	`}`
`216`	`217`	`}`
`217`	`218`	`}`
`@@ -1109,10 +1110,10 @@ impl<'a> TcpSocket<'a> {`
`1109`	`1110`	`}`
`1110`	`1111`
`1111`	`1112`	`if should_send {`
`1112`		`- if self.retransmit.commit(timestamp) {`
`1113`		`- net_trace!("[{}]{}:{}: retransmit after {}ms",`
	`1113`	`+ if let Some(actual_delay) = self.retransmit.commit(timestamp) {`
	`1114`	`+ net_trace!("[{}]{}:{}: retransmitting at t+{}ms ",`
`1114`	`1115`	`self.debug_id, self.local_endpoint, self.remote_endpoint,`
`1115`		`- self.retransmit.delay);`
	`1116`	`+ actual_delay);`
`1116`	`1117`	`}`
`1117`	`1118`
`1118`	`1119`	`if self.state != State::SynSent {`