From ebd4deb8b9d2c79a00431872d07da3b286ba021a Mon Sep 17 00:00:00 2001 From: Derek Collison Date: Sat, 29 Jun 2019 15:43:15 -0700 Subject: [PATCH 1/4] Stager first ping from server and suppress pings if a ping was received. Signed-off-by: Derek Collison --- server/client.go | 36 ++++++++++++++++++++++++++++++------ server/server.go | 4 ++-- test/ping_test.go | 39 +++++++++++++++++++++++++++++++++++++++ test/test.go | 6 +++++- 4 files changed, 76 insertions(+), 9 deletions(-) diff --git a/server/client.go b/server/client.go index b99864f8..cfa0103b 100644 --- a/server/client.go +++ b/server/client.go @@ -202,8 +202,9 @@ type client struct { // Struct for PING initiation from the server. type pinfo struct { - tmr *time.Timer - out int + tmr *time.Timer + last time.Time + out int } // outbound holds pending data for a socket. @@ -1461,6 +1462,10 @@ func (c *client) processPing() { } c.sendPong() + // Record this to suppress us sending one if this + // is withing a given time interval for activity. + c.ping.last = time.Now() + // If not a CLIENT, we are done if c.kind != CLIENT { c.mu.Unlock() @@ -2635,10 +2640,15 @@ func (c *client) processPingTimer() { c.Debugf("%s Ping Timer", c.typeString()) - // If we have had activity within the PingInterval no - // need to send a ping. - if delta := time.Since(c.last); delta < c.srv.getOpts().PingInterval { - c.Debugf("Delaying PING due to activity %v ago", delta.Round(time.Second)) + // If we have had activity within the PingInterval then + // there is no need to send a ping. This can be client data + // or if we received a ping from the other side. + pingInterval := c.srv.getOpts().PingInterval + + if delta := time.Since(c.last); delta < pingInterval { + c.Debugf("Delaying PING due to client activity %v ago", delta.Round(time.Second)) + } else if delta := time.Since(c.ping.last); delta < pingInterval { + c.Debugf("Delaying PING due to remote ping %v ago", delta.Round(time.Second)) } else { // Check for violation if c.ping.out+1 > c.srv.getOpts().MaxPingsOut { @@ -2655,6 +2665,20 @@ func (c *client) processPingTimer() { c.setPingTimer() } +// Lock should be held +// We Randomize the first one by an offset up to 20%, e.g. 2m ~= max 24s. +// This is because the clients by default are usually setting same interval +// and we have alot of cross ping/pongs between clients and servers. +// We will now suppress the server ping/pong if we have received a client ping. +func (c *client) setFirstPingTimer(pingInterval time.Duration) { + if c.srv == nil { + return + } + addDelay := rand.Int63n(int64(pingInterval / 5)) + d := pingInterval + time.Duration(addDelay) + c.ping.tmr = time.AfterFunc(d, c.processPingTimer) +} + // Lock should be held func (c *client) setPingTimer() { if c.srv == nil { diff --git a/server/server.go b/server/server.go index 681fdccf..9811383f 100644 --- a/server/server.go +++ b/server/server.go @@ -1609,8 +1609,8 @@ func (s *Server) createClient(conn net.Conn) *client { // Do final client initialization - // Set the Ping timer - c.setPingTimer() + // Set the First Ping timer. + c.setFirstPingTimer(opts.PingInterval) // Spin up the read loop. s.startGoRoutine(func() { c.readLoop() }) diff --git a/test/ping_test.go b/test/ping_test.go index fa58c903..8807450c 100644 --- a/test/ping_test.go +++ b/test/ping_test.go @@ -187,3 +187,42 @@ func TestUnpromptedPong(t *testing.T) { t.Fatal("timeout: Expected to have connection closed") } } + +func TestPingSuppresion(t *testing.T) { + pingInterval := 100 * time.Millisecond + + opts := DefaultTestOptions + opts.Port = PING_TEST_PORT + opts.PingInterval = pingInterval + + s := RunServer(&opts) + defer s.Shutdown() + + c := createClientConn(t, "127.0.0.1", PING_TEST_PORT) + defer c.Close() + + connectTime := time.Now() + + send, expect := setupConn(t, c) + + expect(pingRe) + pingTime := time.Since(connectTime) + + // Should be > 100 but less then 120(ish) + if pingTime < pingInterval { + t.Fatalf("pingTime too low: %v", pingTime) + } + // +5 is just for fudging in case things are slow in the testing system. + if pingTime > pingInterval+(pingInterval/5)+5 { + t.Fatalf("pingTime too high: %v", pingTime) + } + + time.Sleep(pingInterval / 2) + + // Sending a PING should suppress. + send("PING\r\n") + expect(pongRe) + + // This will wait for + expectNothingTimeout(t, c, time.Now().Add(100*time.Millisecond)) +} diff --git a/test/test.go b/test/test.go index 0518a299..1455f5a8 100644 --- a/test/test.go +++ b/test/test.go @@ -350,8 +350,12 @@ func expectDisconnect(t *testing.T, c net.Conn) { } func expectNothing(t tLogger, c net.Conn) { + expectNothingTimeout(t, c, time.Now().Add(100*time.Millisecond)) +} + +func expectNothingTimeout(t tLogger, c net.Conn, dl time.Time) { expBuf := make([]byte, 32) - c.SetReadDeadline(time.Now().Add(100 * time.Millisecond)) + c.SetReadDeadline(dl) n, err := c.Read(expBuf) c.SetReadDeadline(time.Time{}) if err == nil && n > 0 { From 8a3db71ad50045605e22546907c8d9586a202320 Mon Sep 17 00:00:00 2001 From: Derek Collison Date: Mon, 1 Jul 2019 08:47:13 -0700 Subject: [PATCH 2/4] Updates from comments Signed-off-by: Derek Collison --- server/client.go | 4 ++-- test/ping_test.go | 3 ++- 2 files changed, 4 insertions(+), 3 deletions(-) diff --git a/server/client.go b/server/client.go index cfa0103b..75347295 100644 --- a/server/client.go +++ b/server/client.go @@ -1463,7 +1463,7 @@ func (c *client) processPing() { c.sendPong() // Record this to suppress us sending one if this - // is withing a given time interval for activity. + // is within a given time interval for activity. c.ping.last = time.Now() // If not a CLIENT, we are done @@ -2666,7 +2666,7 @@ func (c *client) processPingTimer() { } // Lock should be held -// We Randomize the first one by an offset up to 20%, e.g. 2m ~= max 24s. +// We randomize the first one by an offset up to 20%, e.g. 2m ~= max 24s. // This is because the clients by default are usually setting same interval // and we have alot of cross ping/pongs between clients and servers. // We will now suppress the server ping/pong if we have received a client ping. diff --git a/test/ping_test.go b/test/ping_test.go index 8807450c..e43a7cc6 100644 --- a/test/ping_test.go +++ b/test/ping_test.go @@ -223,6 +223,7 @@ func TestPingSuppresion(t *testing.T) { send("PING\r\n") expect(pongRe) - // This will wait for + // This will wait for the time period where a PING should have fired + // and been delivered. We expect nothing here since it should be suppressed. expectNothingTimeout(t, c, time.Now().Add(100*time.Millisecond)) } From e11a959584f77c8d4ec5e3e78e7dc4fea420d908 Mon Sep 17 00:00:00 2001 From: Derek Collison Date: Mon, 1 Jul 2019 11:58:06 -0700 Subject: [PATCH 3/4] Send ping when RTT update needed Signed-off-by: Derek Collison --- server/client.go | 6 ++++-- server/const.go | 4 ++++ test/ping_test.go | 1 + 3 files changed, 9 insertions(+), 2 deletions(-) diff --git a/server/client.go b/server/client.go index 75347295..f96a0a1d 100644 --- a/server/client.go +++ b/server/client.go @@ -2644,10 +2644,12 @@ func (c *client) processPingTimer() { // there is no need to send a ping. This can be client data // or if we received a ping from the other side. pingInterval := c.srv.getOpts().PingInterval + now := time.Now() + needRTT := c.rtt == 0 || now.Sub(c.rttStart) > DEFAULT_RTT_MEASUREMENT_INTERVAL - if delta := time.Since(c.last); delta < pingInterval { + if delta := now.Sub(c.last); delta < pingInterval && !needRTT { c.Debugf("Delaying PING due to client activity %v ago", delta.Round(time.Second)) - } else if delta := time.Since(c.ping.last); delta < pingInterval { + } else if delta := now.Sub(c.ping.last); delta < pingInterval && !needRTT { c.Debugf("Delaying PING due to remote ping %v ago", delta.Round(time.Second)) } else { // Check for violation diff --git a/server/const.go b/server/const.go index 48edbca2..6d7813eb 100644 --- a/server/const.go +++ b/server/const.go @@ -156,4 +156,8 @@ const ( // attempt to reconnect a route, gateway or leaf node connection. // The default is to report every attempt. DEFAULT_RECONNECT_ERROR_REPORTS = 1 + + // DEFAULT_RTT_MEASUREMENT_INTERVAL is how often we want to measure RTT from + // this server to clients, routes, gateways or leafnode connections. + DEFAULT_RTT_MEASUREMENT_INTERVAL = time.Hour ) diff --git a/test/ping_test.go b/test/ping_test.go index e43a7cc6..63093dcc 100644 --- a/test/ping_test.go +++ b/test/ping_test.go @@ -207,6 +207,7 @@ func TestPingSuppresion(t *testing.T) { expect(pingRe) pingTime := time.Since(connectTime) + send("PONG\r\n") // Should be > 100 but less then 120(ish) if pingTime < pingInterval { From a6cef5b584649e20c96845a1023b44c8338d9155 Mon Sep 17 00:00:00 2001 From: Derek Collison Date: Mon, 1 Jul 2019 12:03:45 -0700 Subject: [PATCH 4/4] spaces fix Signed-off-by: Derek Collison --- server/const.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/server/const.go b/server/const.go index 6d7813eb..ea325377 100644 --- a/server/const.go +++ b/server/const.go @@ -157,7 +157,7 @@ const ( // The default is to report every attempt. DEFAULT_RECONNECT_ERROR_REPORTS = 1 - // DEFAULT_RTT_MEASUREMENT_INTERVAL is how often we want to measure RTT from + // DEFAULT_RTT_MEASUREMENT_INTERVAL is how often we want to measure RTT from // this server to clients, routes, gateways or leafnode connections. DEFAULT_RTT_MEASUREMENT_INTERVAL = time.Hour )