[FIXED] LeafNode: set first ping timer after receiving CONNECT

We were setting the ping timer in the accepting server as soon
as the leafnode connection is created, just after sending
the INFO and setting the auth timer.

Sending a PING too soon may cause the solicit side to process
this PING and send a PONG in response, possibly before sending
the CONNECT, which the accepting side would fail as an authentication
error, since first protocol is expected to be a CONNECT.

Since LeafNode always expect a CONNECT, we always set the auth
timer. So now on accept, instead of starting the ping timer just
after sending the INFO, we will delay setting this timer only
after receiving the CONNECT.

The auth timer will take care of a stale connection in the time
it takes to receives the CONNECT.

Signed-off-by: Ivan Kozlovic <ivan@synadia.com>

server/leafnode.go

@@ -795,9 +795,6 @@ func (s *Server) createLeafNode(conn net.Conn, rURL *url.URL, remote *leafNodeCf
 		// Leaf nodes will always require a CONNECT to let us know
 		// when we are properly bound to an account.
 		c.setAuthTimer(secondsToDuration(opts.LeafNode.AuthTimeout))
-
-		// Set the Ping timer
-		s.setFirstPingTimer(c)
 	}
 
 	// Keep track in case server is shutdown before we can successfully register.
@@ -1145,6 +1142,10 @@ func (c *client) processLeafNodeConnect(s *Server, arg []byte, lang string) erro
 	if proto.Cluster != "" {
 		c.leaf.remoteCluster = proto.Cluster
 	}
+
+	// Set the Ping timer
+	s.setFirstPingTimer(c)
+
 	c.mu.Unlock()
 
 	// Add in the leafnode here since we passed through auth at this point.

server/leafnode_test.go

@@ -3280,3 +3280,84 @@ func TestLeafNodeUnsubOnRouteDisconnect(t *testing.T) {
 		return nil
 	})
 }
+
+func TestLeafNodeNoPingBeforeConnect(t *testing.T) {
+	o := DefaultOptions()
+	o.LeafNode.Port = -1
+	o.LeafNode.AuthTimeout = 0.5
+	s := RunServer(o)
+	defer s.Shutdown()
+
+	addr := fmt.Sprintf("127.0.0.1:%d", o.LeafNode.Port)
+	c, err := net.Dial("tcp", addr)
+	if err != nil {
+		t.Fatalf("Error on dial: %v", err)
+	}
+	defer c.Close()
+
+	// Read the info
+	br := bufio.NewReader(c)
+	c.SetReadDeadline(time.Now().Add(time.Second))
+	l, _, err := br.ReadLine()
+	if err != nil {
+		t.Fatalf("Error on read: %v", err)
+	}
+	if !strings.HasPrefix(string(l), "INFO") {
+		t.Fatalf("Wrong proto: %q", l)
+	}
+
+	var leaf *client
+	s.grMu.Lock()
+	for _, l := range s.grTmpClients {
+		leaf = l
+		break
+	}
+	s.grMu.Unlock()
+
+	if leaf == nil {
+		t.Fatal("No leaf connection found")
+	}
+
+	// Make sure that ping timer is not set
+	leaf.mu.Lock()
+	ptmrSet := leaf.ping.tmr != nil
+	leaf.mu.Unlock()
+
+	if ptmrSet {
+		t.Fatal("Ping timer was set before CONNECT was processed")
+	}
+
+	// Send CONNECT
+	if _, err := c.Write([]byte("CONNECT {}\r\n")); err != nil {
+		t.Fatalf("Error writing connect: %v", err)
+	}
+
+	// Check that we correctly set the timer now
+	checkFor(t, time.Second, 15*time.Millisecond, func() error {
+		leaf.mu.Lock()
+		ptmrSet := leaf.ping.tmr != nil
+		leaf.mu.Unlock()
+		if !ptmrSet {
+			return fmt.Errorf("Timer still not set")
+		}
+		return nil
+	})
+
+	// Reduce the first ping..
+	leaf.mu.Lock()
+	leaf.ping.tmr.Reset(15 * time.Millisecond)
+	leaf.mu.Unlock()
+
+	// Now consume that PING (we may get LS+, etc..)
+	for {
+		c.SetReadDeadline(time.Now().Add(time.Second))
+		l, _, err = br.ReadLine()
+		if err != nil {
+			t.Fatalf("Error on read: %v", err)
+		}
+		if strings.HasPrefix(string(l), "PING") {
+			checkLeafNodeConnected(t, s)
+			return
+		}
+	}
+}