Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Move tls handshake errors to debug #5766

Open
wants to merge 1 commit into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions server/client.go
Original file line number Diff line number Diff line change
Expand Up @@ -5910,9 +5910,9 @@ func (c *client) doTLSHandshake(typ string, solicit bool, url *url.URL, tlsConfi

if err != nil {
if kind == CLIENT {
c.Errorf("TLS handshake error: %v", err)
c.Debugf("TLS handshake error: %v", err)
} else {
c.Errorf("TLS %s handshake error: %v", typ, err)
c.Debugf("TLS %s handshake error: %v", typ, err)
}
c.closeConnection(TLSHandshakeError)

Expand Down
79 changes: 48 additions & 31 deletions server/leafnode_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -34,7 +34,7 @@ import (
"github.com/nats-io/nkeys"

"github.com/klauspost/compress/s2"
jwt "github.com/nats-io/jwt/v2"
"github.com/nats-io/jwt/v2"
"github.com/nats-io/nats.go"

"github.com/nats-io/nats-server/v2/internal/testhelper"
Expand Down Expand Up @@ -337,12 +337,32 @@ func TestLeafNodeTLSRemoteWithNoCerts(t *testing.T) {

type captureErrorLogger struct {
DummyLogger
errCh chan string
filter func(string) bool
Copy link
Member

@kozlovic kozlovic Aug 9, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's not what I meant. We can create a specific logger for the TLS handshake error and modify only the tests that were checking for the handshake error (when using the generic error capture logger). I would say that in most cases we really only care that we got an error (now a debug trace, but still an handshake error), so a channel of struct{} would suffice, but since in one of the test TestLeafNodeTLSConfigReloadForRemote, we check that we get bad certificate, we could still have string.
So, I would add a dedicated logger, and modify the tests. Here is a diff on the addition of the logger and modification of only 2 of the tests (the others would be similar):

+type captureTLSHandshakeError struct {
+       DummyLogger
+       ch chan string
+}
+
+func (c *captureTLSHandshakeError) Debugf(format string, v ...any) {
+       msg := fmt.Sprintf(format, v...)
+       if strings.Contains(msg, "handshake error") {
+               select {
+               case c.ch <- msg:
+               default:
+               }
+       }
+}
+
 func TestLeafNodeTLSConfigReload(t *testing.T) {
        template := `
                listen: 127.0.0.1:-1
@@ -2623,8 +2638,8 @@ func TestLeafNodeTLSConfigReload(t *testing.T) {
        srvA, optsA := RunServerWithConfig(confA)
        defer srvA.Shutdown()
 
-       lg := &captureErrorLogger{errCh: make(chan string, 10)}
-       srvA.SetLogger(lg, false, false)
+       lg := &captureTLSHandshakeError{ch: make(chan string, 10)}
+       srvA.SetLogger(lg, true, false)
 
        confB := createConfFile(t, []byte(fmt.Sprintf(`
                listen: -1
@@ -2654,14 +2669,7 @@ func TestLeafNodeTLSConfigReload(t *testing.T) {
 
        // Wait for the error
        select {
-       case err := <-lg.errCh:
-               // Since Go 1.18, we had to regenerate certs to not have to use GODEBUG="x509sha1=1"
-               // But on macOS, with our test CA certs, no SCTs included, it will fail
-               // for the reason "x509: “localhost” certificate is not standards compliant"
-               // instead of "unknown authority".
-               if !strings.Contains(err, "unknown") && !strings.Contains(err, "compliant") {
-                       t.Fatalf("Unexpected error: %v", err)
-               }
+       case <-lg.ch:
        case <-time.After(2 * time.Second):
                t.Fatalf("Did not get TLS error")
        }
@@ -2696,8 +2704,8 @@ func TestLeafNodeTLSConfigReloadForRemote(t *testing.T) {
        srvA, optsA := RunServerWithConfig(confA)
        defer srvA.Shutdown()
 
-       lg := &captureErrorLogger{errCh: make(chan string, 10)}
-       srvA.SetLogger(lg, false, false)
+       lg := &captureTLSHandshakeError{ch: make(chan string, 10)}
+       srvA.SetLogger(lg, true, false)
 
        template := `
                listen: -1
@@ -2721,7 +2729,7 @@ func TestLeafNodeTLSConfigReloadForRemote(t *testing.T) {
 
        // Wait for the error
        select {
-       case err := <-lg.errCh:
+       case err := <-lg.ch:
                if !strings.Contains(err, "bad certificate") {
                        t.Fatalf("Unexpected error: %v", err)
                }

errCh chan string
}

func (l *captureErrorLogger) Errorf(format string, v ...any) {
msg := fmt.Sprintf(format, v...)

if l.filter != nil && !l.filter(msg) {
return
}

select {
case l.errCh <- fmt.Sprintf(format, v...):
case l.errCh <- msg:
default:
}
}

func (l *captureErrorLogger) Debugf(format string, v ...any) {
msg := fmt.Sprintf(format, v...)

if l.filter != nil && !l.filter(msg) {
return
}

select {
case l.errCh <- msg:
default:
}
}
Expand Down Expand Up @@ -2623,8 +2643,15 @@ func TestLeafNodeTLSConfigReload(t *testing.T) {
srvA, optsA := RunServerWithConfig(confA)
defer srvA.Shutdown()

lg := &captureErrorLogger{errCh: make(chan string, 10)}
srvA.SetLogger(lg, false, false)
lg := &captureErrorLogger{errCh: make(chan string, 10), filter: func(m string) bool {
// Since Go 1.18, we had to regenerate certs to not have to use GODEBUG="x509sha1=1"
// But on macOS, with our test CA certs, no SCTs included, it will fail
// for the reason "x509: “localhost” certificate is not standards compliant"
// instead of "unknown authority".
return strings.Contains(m, "unknown") || strings.Contains(m, "compliant")
}}

srvA.SetLogger(lg, true, false)

confB := createConfFile(t, []byte(fmt.Sprintf(`
listen: -1
Expand Down Expand Up @@ -2654,14 +2681,7 @@ func TestLeafNodeTLSConfigReload(t *testing.T) {

// Wait for the error
select {
case err := <-lg.errCh:
// Since Go 1.18, we had to regenerate certs to not have to use GODEBUG="x509sha1=1"
// But on macOS, with our test CA certs, no SCTs included, it will fail
// for the reason "x509: “localhost” certificate is not standards compliant"
// instead of "unknown authority".
if !strings.Contains(err, "unknown") && !strings.Contains(err, "compliant") {
t.Fatalf("Unexpected error: %v", err)
}
case <-lg.errCh:
case <-time.After(2 * time.Second):
t.Fatalf("Did not get TLS error")
}
Expand Down Expand Up @@ -2696,8 +2716,10 @@ func TestLeafNodeTLSConfigReloadForRemote(t *testing.T) {
srvA, optsA := RunServerWithConfig(confA)
defer srvA.Shutdown()

lg := &captureErrorLogger{errCh: make(chan string, 10)}
srvA.SetLogger(lg, false, false)
lg := &captureErrorLogger{errCh: make(chan string, 10), filter: func(m string) bool {
return strings.Contains(m, "bad certificate")
}}
srvA.SetLogger(lg, true, false)

template := `
listen: -1
Expand All @@ -2721,10 +2743,7 @@ func TestLeafNodeTLSConfigReloadForRemote(t *testing.T) {

// Wait for the error
select {
case err := <-lg.errCh:
if !strings.Contains(err, "bad certificate") {
t.Fatalf("Unexpected error: %v", err)
}
case <-lg.errCh:
case <-time.After(2 * time.Second):
t.Fatalf("Did not get TLS error")
}
Expand Down Expand Up @@ -3075,14 +3094,13 @@ func TestLeafNodeWSFailedConnection(t *testing.T) {
ln := RunServer(lo)
defer ln.Shutdown()

el := &captureErrorLogger{errCh: make(chan string, 100)}
ln.SetLogger(el, false, false)
el := &captureErrorLogger{errCh: make(chan string, 100), filter: func(m string) bool {
return strings.Contains(m, "handshake error")
}}
ln.SetLogger(el, true, false)

select {
case err := <-el.errCh:
if !strings.Contains(err, "handshake error") {
t.Fatalf("Unexpected error: %v", err)
}
case <-el.errCh:
case <-time.After(time.Second):
t.Fatal("No error reported!")
}
Expand Down Expand Up @@ -5001,18 +5019,17 @@ func TestLeafNodeTLSHandshakeFirst(t *testing.T) {
// Now check that there will be a failure if the remote does not ask for
// handshake first since the hub is configured that way.
// Set a logger on s1 to capture errors
l := &captureErrorLogger{errCh: make(chan string, 10)}
s1.SetLogger(l, false, false)
l := &captureErrorLogger{errCh: make(chan string, 10), filter: func(m string) bool {
return strings.Contains(m, "handshake error")
}}
s1.SetLogger(l, true, false)

confSpoke = createConfFile(t, []byte(fmt.Sprintf(tmpl2, o1.LeafNode.Port, "false")))
s2, _ = RunServerWithConfig(confSpoke)
defer s2.Shutdown()

select {
case err := <-l.errCh:
if !strings.Contains(err, "handshake error") {
t.Fatalf("Unexpected error: %v", err)
}
case <-l.errCh:
case <-time.After(2 * time.Second):
t.Fatal("Did not get TLS handshake failure")
}
Expand Down
6 changes: 4 additions & 2 deletions server/routes_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -1806,8 +1806,10 @@ func TestRouteSaveTLSName(t *testing.T) {

// Set a logger to capture errors trying to connect after clearing
// the routeTLSName and causing a disconnect
l := &captureErrorLogger{errCh: make(chan string, 1)}
s2.SetLogger(l, false, false)
l := &captureErrorLogger{errCh: make(chan string, 1), filter: func(s string) bool {
return strings.Contains(s, "TLS route handshake error")
}}
s2.SetLogger(l, true, false)

var gotIt bool
for i := 0; !gotIt && i < 5; i++ {
Expand Down
4 changes: 2 additions & 2 deletions test/cluster_tls_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -72,7 +72,7 @@ type captureTLSError struct {
ch chan struct{}
}

func (c *captureTLSError) Errorf(format string, v ...any) {
func (c *captureTLSError) Debugf(format string, v ...any) {
msg := fmt.Sprintf(format, v...)
if strings.Contains(msg, "handshake error") {
select {
Expand Down Expand Up @@ -117,7 +117,7 @@ func TestClusterTLSInsecure(t *testing.T) {
defer srvA.Shutdown()

l := &captureTLSError{ch: make(chan struct{}, 1)}
srvA.SetLogger(l, false, false)
srvA.SetLogger(l, true, false)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You need to modify the test in the /test package that uses this logger: TestClusterTLSInsecure.


bConfigTemplate := `
port: -1
Expand Down