Repository: pion/dtls
Pull request #448 (2022-04-14 15:35:12)

Implement retransmit backoff according to 4.2.4.1
#### Description

As per [RFC4347](https://www.rfc-editor.org/rfc/rfc4347.txt)  4.2.4.1 (excluding reset after long period of idleness)

>  Though timer values are the choice of the implementation, mishandling
>    of the timer can lead to serious congestion problems; for example, if
>    many instances of a DTLS time out early and retransmit too quickly on
>    a congested link.  Implementations SHOULD use an initial timer value
> of 1 second (the minimum defined in RFC 2988 [RFC2988]) and double
>    the value at each retransmission, up to no less than the RFC 2988
>    maximum of 60 seconds.  Note that we recommend a 1-second timer
>    rather than the 3-second RFC 2988 default in order to improve latency
>    for time-sensitive applications.  Because DTLS only uses
>    retransmission for handshake and not dataflow, the effect on
>    congestion should be minimal.
> 
>    Implementations SHOULD retain the current timer value until a
>    transmission without loss occurs, at which time the value may be
>    reset to the initial value.  After a long period of idleness, no less
>    than 10 times the current timer value, implementations may reset the
>    timer to the initial value.  One situation where this might occur is
>    when a rehandshake is used after substantial data transfer.

codecov[bot]: # [Codecov](https://codecov.io/gh/pion/dtls/pull/448?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion) Report
> Merging [#448](https://codecov.io/gh/pion/dtls/pull/448?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion) (44c5cbe) into [master](https://codecov.io/gh/pion/dtls/commit/a1db6390bc1420d06e6c9b0dad9cf2c98b635c71?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion) (a1db639) will **decrease** coverage by `0.04%`.
> The diff coverage is `72.72%`.

```diff
@@            Coverage Diff             @@
##           master     #448      +/-   ##
==========================================
- Coverage   75.92%   75.88%   -0.05%     
==========================================
  Files          96       95       -1     
  Lines        5571     5582      +11     
==========================================
+ Hits         4230     4236       +6     
- Misses       1016     1019       +3     
- Partials      325      327       +2     
```

| Flag | Coverage Δ | |
|---|---|---|
| go | `75.88% <72.72%> (-0.07%)` | :arrow_down: |
| wasm | `?` | |

Flags with carried forward coverage won't be shown. [Click here](https://docs.codecov.io/docs/carryforward-flags?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion#carryforward-flags-in-the-pull-request-comment) to find out more.

| [Impacted Files](https://codecov.io/gh/pion/dtls/pull/448?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion) | Coverage Δ | |
|---|---|---|
| [handshaker.go](https://codecov.io/gh/pion/dtls/pull/448/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion#diff-aGFuZHNoYWtlci5nbw==) | `74.48% <71.42%> (-1.47%)` | :arrow_down: |
| [conn.go](https://codecov.io/gh/pion/dtls/pull/448/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion#diff-Y29ubi5nbw==) | `81.56% <100.00%> (+0.13%)` | :arrow_up: |
| [internal/net/dpipe/dpipe.go](https://codecov.io/gh/pion/dtls/pull/448/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion#diff-aW50ZXJuYWwvbmV0L2RwaXBlL2RwaXBlLmdv) | `94.44% <0.00%> (-2.23%)` | :arrow_down: |
| [errors\_noerrno.go](https://codecov.io/gh/pion/dtls/pull/448/diff?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion#diff-ZXJyb3JzX25vZXJybm8uZ28=) | | |

------

[Continue to review full report at Codecov](https://codecov.io/gh/pion/dtls/pull/448?src=pr&el=continue&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion).
> **Legend** - [Click here to learn more](https://docs.codecov.io/docs/codecov-delta?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion)
> `Δ = absolute <relative> (impact)`, `ø = not affected`, `? = missing data`
> Powered by [Codecov](https://codecov.io/gh/pion/dtls/pull/448?src=pr&el=footer&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion). Last update [a1db639...44c5cbe](https://codecov.io/gh/pion/dtls/pull/448?src=pr&el=lastupdated&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion). Read the [comment docs](https://docs.codecov.io/docs/pull-request-comments?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=pion).

eh-steve: I can’t really tell from the logs whether the CI is failing due to my changes…
Sean-Der: Thank you so much @eh-steve 

Sorry it took such a long time to get to these. I am slowly making my way through the backlog

Patch:
diff --git a/config.go b/config.go
index 3cb9ab0..5763ce5 100644
--- a/config.go
+++ b/config.go
@@ -57,6 +57,10 @@ type Config struct {
 	// defaults to time.Second
 	FlightInterval time.Duration
 
+	// DisableRetransmitBackoff can be used to the disable the backoff feature
+	// when sending outbound messages as specified in RFC 4347 4.2.4.1
+	DisableRetransmitBackoff bool
+
 	// PSK sets the pre-shared key used by this DTLS connection
 	// If PSK is non-nil only PSK CipherSuites will be used
 	PSK             PSKCallback
diff --git a/conn.go b/conn.go
index 1c670cc..5d0d86f 100644
--- a/conn.go
+++ b/conn.go
@@ -202,7 +202,8 @@ func handshakeConn(ctx context.Context, conn *Conn, config *Config, isClient boo
 		rootCAs:                       config.RootCAs,
 		clientCAs:                     config.ClientCAs,
 		customCipherSuites:            config.CustomCipherSuites,
-		retransmitInterval:            workerInterval,
+		initialRetransmitInterval:     workerInterval,
+		disableRetransmitBackoff:      config.DisableRetransmitBackoff,
 		log:                           conn.log,
 		initialEpoch:                  0,
 		keyLogWriter:                  config.KeyLogWriter,
diff --git a/handshaker.go b/handshaker.go
index 09c6b4e..4e0f1ad 100644
--- a/handshaker.go
+++ b/handshaker.go
@@ -82,13 +82,14 @@ func (s handshakeState) String() string {
 }
 
 type handshakeFSM struct {
-	currentFlight flightVal
-	flights       []*packet
-	retransmit    bool
-	state         *State
-	cache         *handshakeCache
-	cfg           *handshakeConfig
-	closed        chan struct{}
+	currentFlight      flightVal
+	flights            []*packet
+	retransmit         bool
+	retransmitInterval time.Duration
+	state              *State
+	cache              *handshakeCache
+	cfg                *handshakeConfig
+	closed             chan struct{}
 }
 
 type handshakeConfig struct {
@@ -109,7 +110,8 @@ type handshakeConfig struct {
 	sessionStore                SessionStore
 	rootCAs                     *x509.CertPool
 	clientCAs                   *x509.CertPool
-	retransmitInterval          time.Duration
+	initialRetransmitInterval   time.Duration
+	disableRetransmitBackoff    bool
 	customCipherSuites          func() []CipherSuite
 	ellipticCurves              []elliptic.Curve
 	insecureSkipHelloVerify     bool
@@ -165,11 +167,12 @@ func newHandshakeFSM(
 	initialFlight flightVal,
 ) *handshakeFSM {
 	return &handshakeFSM{
-		currentFlight: initialFlight,
-		state:         s,
-		cache:         cache,
-		cfg:           cfg,
-		closed:        make(chan struct{}),
+		currentFlight:      initialFlight,
+		state:              s,
+		cache:              cache,
+		cfg:                cfg,
+		retransmitInterval: cfg.initialRetransmitInterval,
+		closed:             make(chan struct{}),
 	}
 }
 
@@ -274,11 +277,12 @@ func (s *handshakeFSM) wait(ctx context.Context, c flightConn) (handshakeState,
 		return handshakeErrored, errFlight
 	}
 
-	retransmitTimer := time.NewTimer(s.cfg.retransmitInterval)
+	retransmitTimer := time.NewTimer(s.retransmitInterval)
 	for {
 		select {
 		case done := <-c.recvHandshake():
 			nextFlight, alert, err := parse(ctx, c, s.state, s.cache, s.cfg)
+			s.retransmitInterval = s.cfg.initialRetransmitInterval
 			close(done)
 			if alert != nil {
 				if alertErr := c.notify(ctx, alert.Level, alert.Description); alertErr != nil {
@@ -304,8 +308,19 @@ func (s *handshakeFSM) wait(ctx context.Context, c flightConn) (handshakeState,
 			if !s.retransmit {
 				return handshakeWaiting, nil
 			}
+
+			// RFC 4347 4.2.4.1:
+			// Implementations SHOULD use an initial timer value of 1 second (the minimum defined in RFC 2988 [RFC2988])
+			// and double the value at each retransmission, up to no less than the RFC 2988 maximum of 60 seconds.
+			if !s.cfg.disableRetransmitBackoff {
+				s.retransmitInterval *= 2
+			}
+			if s.retransmitInterval > time.Second*60 {
+				s.retransmitInterval = time.Second * 60
+			}
 			return handshakeSending, nil
 		case <-ctx.Done():
+			s.retransmitInterval = s.cfg.initialRetransmitInterval
 			return handshakeErrored, ctx.Err()
 		}
 	}
@@ -320,11 +335,12 @@ func (s *handshakeFSM) finish(ctx context.Context, c flightConn) (handshakeState
 		return handshakeErrored, errFlight
 	}
 
-	retransmitTimer := time.NewTimer(s.cfg.retransmitInterval)
+	retransmitTimer := time.NewTimer(s.retransmitInterval)
 	select {
 	case done := <-c.recvHandshake():
 		nextFlight, alert, err := parse(ctx, c, s.state, s.cache, s.cfg)
 		close(done)
+		s.retransmitInterval = s.cfg.initialRetransmitInterval
 		if alert != nil {
 			if alertErr := c.notify(ctx, alert.Level, alert.Description); alertErr != nil {
 				if err != nil {
@@ -342,10 +358,16 @@ func (s *handshakeFSM) finish(ctx context.Context, c flightConn) (handshakeState
 			return handshakeFinished, nil
 		}
 		<-retransmitTimer.C
+		// RFC 4347 4.2.4.1
+		s.retransmitInterval *= 2
+		if s.retransmitInterval > time.Second*60 {
+			s.retransmitInterval = time.Second * 60
+		}
 		// Retransmit last flight
 		return handshakeSending, nil
 
 	case <-ctx.Done():
+		s.retransmitInterval = s.cfg.initialRetransmitInterval
 		return handshakeErrored, ctx.Err()
 	}
 	return handshakeFinished, nil


Test patch:
diff --git a/conn_test.go b/conn_test.go
index 9601183..3b30b23 100644
--- a/conn_test.go
+++ b/conn_test.go
@@ -3319,7 +3319,6 @@ func TestApplicationDataQueueLimited(t *testing.T) {
 				if qlen > maxAppDataPacketQueueSize {
 					t.Error("too many encrypted packets enqueued", len(dconn.encryptedPackets))
 				}
-				t.Log(qlen)
 				time.Sleep(1 * time.Second)
 			}
 		}()
diff --git a/e2e/e2e_lossy_test.go b/e2e/e2e_lossy_test.go
index f646557..3e03037 100644
--- a/e2e/e2e_lossy_test.go
+++ b/e2e/e2e_lossy_test.go
@@ -135,10 +135,11 @@ func TestPionE2ELossy(t *testing.T) {
 
 			go func() {
 				cfg := &dtls.Config{
-					FlightInterval:     flightInterval,
-					CipherSuites:       test.CipherSuites,
-					InsecureSkipVerify: true,
-					MTU:                test.MTU,
+					FlightInterval:           flightInterval,
+					CipherSuites:             test.CipherSuites,
+					InsecureSkipVerify:       true,
+					MTU:                      test.MTU,
+					DisableRetransmitBackoff: true,
 				}
 
 				if test.DoClientAuth {
@@ -151,9 +152,10 @@ func TestPionE2ELossy(t *testing.T) {
 
 			go func() {
 				cfg := &dtls.Config{
-					Certificates:   []tls.Certificate{serverCert},
-					FlightInterval: flightInterval,
-					MTU:            test.MTU,
+					Certificates:             []tls.Certificate{serverCert},
+					FlightInterval:           flightInterval,
+					MTU:                      test.MTU,
+					DisableRetransmitBackoff: true,
 				}
 
 				if test.DoClientAuth {
diff --git a/handshaker_test.go b/handshaker_test.go
index 9bbca6f..b2bd444 100644
--- a/handshaker_test.go
+++ b/handshaker_test.go
@@ -216,10 +216,10 @@ func TestHandshaker(t *testing.T) {
 			}
 
 			report := func(t *testing.T) {
-				// with one second server delay and 100 ms retransmit, there should be close to 10 `Finished` from client
-				// using a range of 9 - 11 for checking
-				if cntClientFinished < 8 || cntClientFinished > 11 {
-					t.Errorf("Number of client finished is wrong, expected: %d - %d times, got: %d times", 9, 11, cntClientFinished)
+				// with one second server delay and 100 ms retransmit (+ exponential backoff), there should be close to 4 `Finished` from client
+				// using a range of 3 - 5 for checking
+				if cntClientFinished < 3 || cntClientFinished > 5 {
+					t.Errorf("Number of client finished is wrong, expected: %d - %d times, got: %d times", 3, 5, cntClientFinished)
 				}
 				if !isClientFinished {
 					t.Errorf("Client is not finished")
@@ -281,7 +281,7 @@ func TestHandshaker(t *testing.T) {
 							})
 						}
 					},
-					retransmitInterval: nonZeroRetransmitInterval,
+					initialRetransmitInterval: nonZeroRetransmitInterval,
 				}
 
 				fsm := newHandshakeFSM(&ca.state, ca.handshakeCache, cfg, flight1)
@@ -314,7 +314,7 @@ func TestHandshaker(t *testing.T) {
 							})
 						}
 					},
-					retransmitInterval: nonZeroRetransmitInterval,
+					initialRetransmitInterval: nonZeroRetransmitInterval,
 				}
 
 				fsm := newHandshakeFSM(&cb.state, cb.handshakeCache, cfg, flight0)