[FIXED] Authorization Timeout and TLS

When TLS and authorization is enabled, the authorization timeout can
fire during the TLS handshake, causing the server to write the
authorization timeout error string into the client socket, injecting
what becomes bad data into the TLS handshake. This creates misleading
errors on the client such as tls: oversized record received with length
21024.

This moves the authorization timeout scheduling to after the TLS
handshake to avoid the race. This should be safe since TLS has its own
handshake timeout. Added a unit test that fails with the old behavior
and passes with the new. LMK if you can think of a better way to test
this.

Fixes #432

server/client_test.go

@@ -592,10 +592,19 @@ func TestAuthorizationTimeout(t *testing.T) {
 	serverOptions := defaultServerOptions
 	serverOptions.Authorization = "my_token"
 	serverOptions.AuthTimeout = 1
-	_, _, cr, _ := rawSetup(serverOptions)
+	s := RunServer(&serverOptions)
+	defer s.Shutdown()
 
-	time.Sleep(secondsToDuration(serverOptions.AuthTimeout))
-	l, err := cr.ReadString('\n')
+	conn, err := net.Dial("tcp", fmt.Sprintf("%s:%d", serverOptions.Host, serverOptions.Port))
+	if err != nil {
+		t.Fatalf("Error dialing server: %v\n", err)
+	}
+	defer conn.Close()
+	client := bufio.NewReaderSize(conn, maxBufSize)
+	if _, err := client.ReadString('\n'); err != nil {
+		t.Fatalf("Error receiving info from server: %v\n", err)
+	}
+	l, err := client.ReadString('\n')
 	if err != nil {
 		t.Fatalf("Error receiving info from server: %v\n", err)
 	}

server/server.go

@@ -548,11 +548,6 @@ func (s *Server) createClient(conn net.Conn) *client {
 
 	c.Debugf("Client connection created")
 
-	// Check for Auth
-	if authRequired {
-		c.setAuthTimer(secondsToDuration(s.opts.AuthTimeout))
-	}
-
 	// Send our information.
 	c.sendInfo(info)
 
@@ -614,6 +609,13 @@ func (s *Server) createClient(conn net.Conn) *client {
 		return c
 	}
 
+	// Check for Auth. We schedule this timer after the TLS handshake to avoid
+	// the race where the timer fires during the handshake and causes the
+	// server to write bad data to the socket. See issue #432.
+	if authRequired {
+		c.setAuthTimer(secondsToDuration(s.opts.AuthTimeout))
+	}
+
 	if tlsRequired {
 		// Rewrap bw
 		c.bw = bufio.NewWriterSize(c.nc, startBufSize)

test/tls_test.go

@@ -160,6 +160,28 @@ func TestTLSConnectionTimeout(t *testing.T) {
 	}
 }
 
+// Ensure there is no race between authorization timeout and TLS handshake.
+func TestTLSAuthorizationShortTimeout(t *testing.T) {
+	opts := LoadConfig("./configs/tls.conf")
+	opts.AuthTimeout = 0.001
+
+	srv := RunServer(opts)
+	defer srv.Shutdown()
+
+	endpoint := fmt.Sprintf("%s:%d", opts.Host, opts.Port)
+	nurl := fmt.Sprintf("tls://%s:%s@%s/", opts.Username, opts.Password, endpoint)
+
+	// Expect an error here (no CA) but not a TLS oversized record error which
+	// indicates the authorization timeout fired too soon.
+	_, err := nats.Connect(nurl)
+	if err == nil {
+		t.Fatal("Expected error trying to connect to secure server")
+	}
+	if strings.Contains(err.Error(), "oversized record") {
+		t.Fatal("Corrupted TLS handshake:", err)
+	}
+}
+
 func stressConnect(t *testing.T, wg *sync.WaitGroup, errCh chan error, url string, index int) {
 	defer wg.Done()