From 0314cd8e22398c9f9e87d7ea8f3055e63e37f611 Mon Sep 17 00:00:00 2001 From: Dzianis Vashchuk Date: Mon, 1 Jun 2026 14:16:02 +0000 Subject: [PATCH 1/6] fix(nodeauth): downgrade context-cancel errors to WARN in node JWT authenticator When IsNodePubKeyTrusted returns context.Canceled or context.DeadlineExceeded, log at WARN instead of ERROR. These are expected transient conditions (caller-initiated cancellation or slow upstream) and should not fire alerts. Adds tests for both Canceled and DeadlineExceeded paths, and a well-behaved captureHandler for slog assertions. Ticket: SHARED-2644 --- pkg/nodeauth/jwt/node_jwt_authenticator.go | 16 ++- .../jwt/node_jwt_authenticator_test.go | 117 ++++++++++++++++++ 2 files changed, 129 insertions(+), 4 deletions(-) diff --git a/pkg/nodeauth/jwt/node_jwt_authenticator.go b/pkg/nodeauth/jwt/node_jwt_authenticator.go index 24bcbd5ac8..5a3fa79ba2 100644 --- a/pkg/nodeauth/jwt/node_jwt_authenticator.go +++ b/pkg/nodeauth/jwt/node_jwt_authenticator.go @@ -78,10 +78,18 @@ func (v *NodeJWTAuthenticator) AuthenticateJWT(ctx context.Context, tokenString // Public Key Validation: Verify node's CSA pubkey against the whitelisted registry via NodeAuthProvider. isValid, err := v.nodeAuthProvider.IsNodePubKeyTrusted(ctx, publicKey) if err != nil { - v.logger.Error("Node validation failed", - "csaPubKey", hex.EncodeToString(publicKey), - "error", err, - ) + if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) { + v.logger.Warn("Node validation skipped: context canceled or deadline exceeded", + "csaPubKey", hex.EncodeToString(publicKey), + "error", err, + "contextErr", ctx.Err(), + ) + } else { + v.logger.Error("Node validation failed", + "csaPubKey", hex.EncodeToString(publicKey), + "error", err, + ) + } return false, claims, fmt.Errorf("node validation failed: %w", err) } diff --git a/pkg/nodeauth/jwt/node_jwt_authenticator_test.go b/pkg/nodeauth/jwt/node_jwt_authenticator_test.go index 9986d268aa..539abc919f 100644 --- a/pkg/nodeauth/jwt/node_jwt_authenticator_test.go +++ b/pkg/nodeauth/jwt/node_jwt_authenticator_test.go @@ -5,8 +5,10 @@ import ( "crypto/ed25519" "crypto/rand" "encoding/hex" + "errors" "io" "log/slog" + "sync" "testing" "time" @@ -450,3 +452,118 @@ func TestNewNodeJWTAuthenticator_WithAndWithoutLeeway(t *testing.T) { assert.NotNil(t, authenticator.parser) }) } + +// captureHandler is a minimal slog.Handler that captures log records for test assertions. +// It satisfies the full slog.Handler contract: WithAttrs and WithGroup return a new +// handler so that logger.With(...) / logger.WithGroup(...) calls don't silently discard +// attributes. +type captureHandler struct { + mu sync.Mutex + records []slog.Record + attrs []slog.Attr + groups []string +} + +func (h *captureHandler) Enabled(_ context.Context, _ slog.Level) bool { return true } +func (h *captureHandler) Handle(_ context.Context, r slog.Record) error { + // Prepend any inherited attrs so they appear in captured records. + if len(h.attrs) > 0 { + r2 := slog.NewRecord(r.Time, r.Level, r.Message, r.PC) + r2.AddAttrs(h.attrs...) + r.Attrs(func(a slog.Attr) bool { r2.AddAttrs(a); return true }) + r = r2 + } + h.mu.Lock() + defer h.mu.Unlock() + h.records = append(h.records, r.Clone()) + return nil +} +func (h *captureHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + h.mu.Lock() + defer h.mu.Unlock() + merged := make([]slog.Attr, len(h.attrs)+len(attrs)) + copy(merged, h.attrs) + copy(merged[len(h.attrs):], attrs) + return &captureHandler{records: h.records, attrs: merged, groups: h.groups} +} +func (h *captureHandler) WithGroup(name string) slog.Handler { + h.mu.Lock() + defer h.mu.Unlock() + groups := append(append([]string{}, h.groups...), name) + return &captureHandler{records: h.records, attrs: h.attrs, groups: groups} +} + +func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderNonContextError(t *testing.T) { + // Non-context provider errors must be logged at ERROR level. + privateKey, csaPubKey := createValidatorTestKeys() + providerErr := errors.New("database unavailable") + mockProvider := &mocks.NodeAuthProvider{} + mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, providerErr) + + h := &captureHandler{} + authenticator := NewNodeJWTAuthenticator(mockProvider, slog.New(h)) + + testRequest := testRequest{Field: "test-request"} + valid, claims, err := authenticator.AuthenticateJWT(context.Background(), createValidJWT(privateKey, csaPubKey), testRequest) + + require.Error(t, err) + assert.False(t, valid) + assert.NotNil(t, claims) + assert.Contains(t, err.Error(), "node validation failed") + + require.Len(t, h.records, 1) + assert.Equal(t, slog.LevelError, h.records[0].Level, "non-context provider errors should log at ERROR") + mockProvider.AssertExpectations(t) +} + +func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderContextCancelledError(t *testing.T) { + // Context-cancellation errors from the provider must be logged at WARN, not ERROR, + // because they are caused by the caller cancelling the request — not a system fault. + privateKey, csaPubKey := createValidatorTestKeys() + mockProvider := &mocks.NodeAuthProvider{} + mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.Canceled) + + h := &captureHandler{} + authenticator := NewNodeJWTAuthenticator(mockProvider, slog.New(h)) + + ctx, cancel := context.WithCancel(context.Background()) + cancel() // already cancelled + + testRequest := testRequest{Field: "test-request"} + valid, claims, err := authenticator.AuthenticateJWT(ctx, createValidJWT(privateKey, csaPubKey), testRequest) + + require.Error(t, err) + assert.False(t, valid) + assert.NotNil(t, claims) + assert.ErrorIs(t, err, context.Canceled) + + require.Len(t, h.records, 1) + assert.Equal(t, slog.LevelWarn, h.records[0].Level, "context cancellation from provider should log at WARN not ERROR") + mockProvider.AssertExpectations(t) +} + +func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderDeadlineExceededError(t *testing.T) { + // context.DeadlineExceeded from the provider must also be logged at WARN, not ERROR, + // because it is an expected transient condition (e.g. slow upstream), not a system fault. + privateKey, csaPubKey := createValidatorTestKeys() + mockProvider := &mocks.NodeAuthProvider{} + mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.DeadlineExceeded) + + h := &captureHandler{} + authenticator := NewNodeJWTAuthenticator(mockProvider, slog.New(h)) + + ctx, cancel := context.WithTimeout(context.Background(), 0) // immediately expired + defer cancel() + + testRequest := testRequest{Field: "test-request"} + valid, claims, err := authenticator.AuthenticateJWT(ctx, createValidJWT(privateKey, csaPubKey), testRequest) + + require.Error(t, err) + assert.False(t, valid) + assert.NotNil(t, claims) + assert.ErrorIs(t, err, context.DeadlineExceeded) + + require.Len(t, h.records, 1) + assert.Equal(t, slog.LevelWarn, h.records[0].Level, "deadline exceeded from provider should log at WARN not ERROR") + mockProvider.AssertExpectations(t) +} From 6da70557ac6007fb91089acf274b0e0d35d045e3 Mon Sep 17 00:00:00 2001 From: Dzianis Vashchuk Date: Tue, 2 Jun 2026 08:59:11 +0000 Subject: [PATCH 2/6] ci: retrigger CI to refresh SonarQube coverage analysis From 712f553f5e0eaf7945a89518075c66ec6c101b56 Mon Sep 17 00:00:00 2001 From: Dzianis Vashchuk Date: Tue, 2 Jun 2026 16:27:50 +0000 Subject: [PATCH 3/6] fix(nodeauth): use real slog handler in tests --- pkg/nodeauth/jwt/node_jwt_authenticator.go | 9 ++- .../jwt/node_jwt_authenticator_test.go | 80 +++++++------------ 2 files changed, 33 insertions(+), 56 deletions(-) diff --git a/pkg/nodeauth/jwt/node_jwt_authenticator.go b/pkg/nodeauth/jwt/node_jwt_authenticator.go index 5a3fa79ba2..bb5c836101 100644 --- a/pkg/nodeauth/jwt/node_jwt_authenticator.go +++ b/pkg/nodeauth/jwt/node_jwt_authenticator.go @@ -79,11 +79,14 @@ func (v *NodeJWTAuthenticator) AuthenticateJWT(ctx context.Context, tokenString isValid, err := v.nodeAuthProvider.IsNodePubKeyTrusted(ctx, publicKey) if err != nil { if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) { - v.logger.Warn("Node validation skipped: context canceled or deadline exceeded", + attrs := []any{ "csaPubKey", hex.EncodeToString(publicKey), "error", err, - "contextErr", ctx.Err(), - ) + } + if ctxErr := ctx.Err(); ctxErr != nil { + attrs = append(attrs, "contextErr", ctxErr) + } + v.logger.Warn("Node validation skipped: context canceled or deadline exceeded", attrs...) } else { v.logger.Error("Node validation failed", "csaPubKey", hex.EncodeToString(publicKey), diff --git a/pkg/nodeauth/jwt/node_jwt_authenticator_test.go b/pkg/nodeauth/jwt/node_jwt_authenticator_test.go index 539abc919f..81c8154902 100644 --- a/pkg/nodeauth/jwt/node_jwt_authenticator_test.go +++ b/pkg/nodeauth/jwt/node_jwt_authenticator_test.go @@ -1,14 +1,15 @@ package jwt import ( + "bytes" "context" "crypto/ed25519" "crypto/rand" "encoding/hex" + "encoding/json" "errors" "io" "log/slog" - "sync" "testing" "time" @@ -453,46 +454,6 @@ func TestNewNodeJWTAuthenticator_WithAndWithoutLeeway(t *testing.T) { }) } -// captureHandler is a minimal slog.Handler that captures log records for test assertions. -// It satisfies the full slog.Handler contract: WithAttrs and WithGroup return a new -// handler so that logger.With(...) / logger.WithGroup(...) calls don't silently discard -// attributes. -type captureHandler struct { - mu sync.Mutex - records []slog.Record - attrs []slog.Attr - groups []string -} - -func (h *captureHandler) Enabled(_ context.Context, _ slog.Level) bool { return true } -func (h *captureHandler) Handle(_ context.Context, r slog.Record) error { - // Prepend any inherited attrs so they appear in captured records. - if len(h.attrs) > 0 { - r2 := slog.NewRecord(r.Time, r.Level, r.Message, r.PC) - r2.AddAttrs(h.attrs...) - r.Attrs(func(a slog.Attr) bool { r2.AddAttrs(a); return true }) - r = r2 - } - h.mu.Lock() - defer h.mu.Unlock() - h.records = append(h.records, r.Clone()) - return nil -} -func (h *captureHandler) WithAttrs(attrs []slog.Attr) slog.Handler { - h.mu.Lock() - defer h.mu.Unlock() - merged := make([]slog.Attr, len(h.attrs)+len(attrs)) - copy(merged, h.attrs) - copy(merged[len(h.attrs):], attrs) - return &captureHandler{records: h.records, attrs: merged, groups: h.groups} -} -func (h *captureHandler) WithGroup(name string) slog.Handler { - h.mu.Lock() - defer h.mu.Unlock() - groups := append(append([]string{}, h.groups...), name) - return &captureHandler{records: h.records, attrs: h.attrs, groups: groups} -} - func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderNonContextError(t *testing.T) { // Non-context provider errors must be logged at ERROR level. privateKey, csaPubKey := createValidatorTestKeys() @@ -500,8 +461,8 @@ func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderNonContextError(t *testing mockProvider := &mocks.NodeAuthProvider{} mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, providerErr) - h := &captureHandler{} - authenticator := NewNodeJWTAuthenticator(mockProvider, slog.New(h)) + logger, buf := newCaptureLogger() + authenticator := NewNodeJWTAuthenticator(mockProvider, logger) testRequest := testRequest{Field: "test-request"} valid, claims, err := authenticator.AuthenticateJWT(context.Background(), createValidJWT(privateKey, csaPubKey), testRequest) @@ -511,8 +472,8 @@ func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderNonContextError(t *testing assert.NotNil(t, claims) assert.Contains(t, err.Error(), "node validation failed") - require.Len(t, h.records, 1) - assert.Equal(t, slog.LevelError, h.records[0].Level, "non-context provider errors should log at ERROR") + entry := readLogEntry(t, buf) + assert.Equal(t, "ERROR", entry["level"], "non-context provider errors should log at ERROR") mockProvider.AssertExpectations(t) } @@ -523,8 +484,8 @@ func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderContextCancelledError(t *t mockProvider := &mocks.NodeAuthProvider{} mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.Canceled) - h := &captureHandler{} - authenticator := NewNodeJWTAuthenticator(mockProvider, slog.New(h)) + logger, buf := newCaptureLogger() + authenticator := NewNodeJWTAuthenticator(mockProvider, logger) ctx, cancel := context.WithCancel(context.Background()) cancel() // already cancelled @@ -537,8 +498,8 @@ func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderContextCancelledError(t *t assert.NotNil(t, claims) assert.ErrorIs(t, err, context.Canceled) - require.Len(t, h.records, 1) - assert.Equal(t, slog.LevelWarn, h.records[0].Level, "context cancellation from provider should log at WARN not ERROR") + entry := readLogEntry(t, buf) + assert.Equal(t, "WARN", entry["level"], "context cancellation from provider should log at WARN not ERROR") mockProvider.AssertExpectations(t) } @@ -549,8 +510,8 @@ func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderDeadlineExceededError(t *t mockProvider := &mocks.NodeAuthProvider{} mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.DeadlineExceeded) - h := &captureHandler{} - authenticator := NewNodeJWTAuthenticator(mockProvider, slog.New(h)) + logger, buf := newCaptureLogger() + authenticator := NewNodeJWTAuthenticator(mockProvider, logger) ctx, cancel := context.WithTimeout(context.Background(), 0) // immediately expired defer cancel() @@ -563,7 +524,20 @@ func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderDeadlineExceededError(t *t assert.NotNil(t, claims) assert.ErrorIs(t, err, context.DeadlineExceeded) - require.Len(t, h.records, 1) - assert.Equal(t, slog.LevelWarn, h.records[0].Level, "deadline exceeded from provider should log at WARN not ERROR") + entry := readLogEntry(t, buf) + assert.Equal(t, "WARN", entry["level"], "deadline exceeded from provider should log at WARN not ERROR") mockProvider.AssertExpectations(t) } + +func newCaptureLogger() (*slog.Logger, *bytes.Buffer) { + var buf bytes.Buffer + return slog.New(slog.NewJSONHandler(&buf, nil)), &buf +} + +func readLogEntry(t *testing.T, buf *bytes.Buffer) map[string]any { + t.Helper() + + var entry map[string]any + require.NoError(t, json.Unmarshal(buf.Bytes(), &entry)) + return entry +} From d8861ab2c1ca061f7a90e78c3aa9c78080605675 Mon Sep 17 00:00:00 2001 From: Dzianis Vashchuk Date: Tue, 2 Jun 2026 10:44:38 +0000 Subject: [PATCH 4/6] ci: remove -coverpkg=./... to fix SonarQube coverage for nodeauth package Using -coverpkg=./... causes Go's coverage merge to produce incorrect results for packages imported-but-not-directly-called by other test packages (such as pkg/nodeauth/jwt). Those other test packages write 0 counts for nodeauth lines, overwriting the 1s from nodeauth's own tests, resulting in 0% "new code" coverage reported to SonarQube. Without -coverpkg=./..., each package reports coverage only for its own code, which correctly shows nodeauth/jwt test coverage. Co-Authored-By: Claude Sonnet 4.6 --- .github/workflows/pkg.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/pkg.yml b/.github/workflows/pkg.yml index 3ba6a9e554..1d7a97e73a 100644 --- a/.github/workflows/pkg.yml +++ b/.github/workflows/pkg.yml @@ -23,7 +23,7 @@ jobs: - name: Unit Tests id: run-tests continue-on-error: true - run: gotestsum --format standard-quiet --junitfile test-results.xml -- ./... -coverpkg=./... -coverprofile=coverage.txt + run: gotestsum --format standard-quiet --junitfile test-results.xml -- ./... -coverprofile=coverage.txt - name: Analyze and upload test results uses: smartcontractkit/.github/actions/branch-out-upload@branch-out-upload/v1 From c7b3c87a79175081703318d4b267ba83bb87ee3c Mon Sep 17 00:00:00 2001 From: "Dzianis Vashchuk (Chainlink)" Date: Thu, 9 Jul 2026 07:31:30 -0700 Subject: [PATCH 5/6] Revert .github/workflows/pkg.yml --- .github/workflows/pkg.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.github/workflows/pkg.yml b/.github/workflows/pkg.yml index 498cfdfc6c..769f359377 100644 --- a/.github/workflows/pkg.yml +++ b/.github/workflows/pkg.yml @@ -30,7 +30,7 @@ jobs: - name: Unit Tests id: run-tests continue-on-error: true - run: gotestsum --format standard-quiet --junitfile test-results.xml -- ./... -coverprofile=coverage.txt + run: gotestsum --format standard-quiet --junitfile test-results.xml -- ./... -coverpkg=./... -coverprofile=coverage.txt - name: Analyze and upload test results uses: smartcontractkit/.github/actions/branch-out-upload@branch-out-upload/v1 From 28dfd4dbc41ae7681c4b0490e993338e19f37fe3 Mon Sep 17 00:00:00 2001 From: "Dzianis Vashchuk (Chainlink)" Date: Thu, 9 Jul 2026 14:27:28 -0700 Subject: [PATCH 6/6] Group tests at func TestNodeJWTAuthenticator --- .../jwt/node_jwt_authenticator_test.go | 126 +++++++++--------- 1 file changed, 64 insertions(+), 62 deletions(-) diff --git a/pkg/nodeauth/jwt/node_jwt_authenticator_test.go b/pkg/nodeauth/jwt/node_jwt_authenticator_test.go index 9789b69e9c..798170e734 100644 --- a/pkg/nodeauth/jwt/node_jwt_authenticator_test.go +++ b/pkg/nodeauth/jwt/node_jwt_authenticator_test.go @@ -452,84 +452,86 @@ func TestNewNodeJWTAuthenticator_WithAndWithoutLeeway(t *testing.T) { }) } -func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderNonContextError(t *testing.T) { - // Non-context provider errors must be logged at ERROR level. - privateKey, csaPubKey := createValidatorTestKeys() - providerErr := errors.New("database unavailable") - mockProvider := &mocks.NodeAuthProvider{} - mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, providerErr) +func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderErrors(t *testing.T) { + t.Run("non-context error logs at error level", func(t *testing.T) { + // Non-context provider errors must be logged at ERROR level. + privateKey, csaPubKey := createValidatorTestKeys() + providerErr := errors.New("database unavailable") + mockProvider := &mocks.NodeAuthProvider{} + mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, providerErr) - lggr, observedLogs := logger.TestObserved(t, zapcore.DebugLevel) - authenticator := NodeJWTAuthenticatorConfig{Logger: lggr}.New(mockProvider) + lggr, observedLogs := logger.TestObserved(t, zapcore.DebugLevel) + authenticator := NodeJWTAuthenticatorConfig{Logger: lggr}.New(mockProvider) - testRequest := testRequest{Field: "test-request"} - valid, claims, err := authenticator.AuthenticateJWT(context.Background(), createValidJWT(privateKey, csaPubKey), testRequest) + testRequest := testRequest{Field: "test-request"} + valid, claims, err := authenticator.AuthenticateJWT(context.Background(), createValidJWT(privateKey, csaPubKey), testRequest) - require.Error(t, err) - assert.False(t, valid) - assert.NotNil(t, claims) - assert.Contains(t, err.Error(), "node validation failed") + require.Error(t, err) + assert.False(t, valid) + assert.NotNil(t, claims) + assert.Contains(t, err.Error(), "node validation failed") - entries := observedLogs.FilterMessage("Node validation failed").All() - require.Len(t, entries, 1, "expected exactly one 'Node validation failed' log entry") - assert.Equal(t, zapcore.ErrorLevel, entries[0].Level, "non-context provider errors should log at ERROR") - mockProvider.AssertExpectations(t) -} + entries := observedLogs.FilterMessage("Node validation failed").All() + require.Len(t, entries, 1, "expected exactly one 'Node validation failed' log entry") + assert.Equal(t, zapcore.ErrorLevel, entries[0].Level, "non-context provider errors should log at ERROR") + mockProvider.AssertExpectations(t) + }) -func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderContextCancelledError(t *testing.T) { - // Context-cancellation errors from the provider must be logged at WARN, not ERROR, - // because they are caused by the caller cancelling the request — not a system fault. - privateKey, csaPubKey := createValidatorTestKeys() - mockProvider := &mocks.NodeAuthProvider{} - mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.Canceled) + t.Run("context cancelled error logs at warn level", func(t *testing.T) { + // Context-cancellation errors from the provider must be logged at WARN, not ERROR, + // because they are caused by the caller cancelling the request — not a system fault. + privateKey, csaPubKey := createValidatorTestKeys() + mockProvider := &mocks.NodeAuthProvider{} + mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.Canceled) - lggr, observedLogs := logger.TestObserved(t, zapcore.DebugLevel) - authenticator := NodeJWTAuthenticatorConfig{Logger: lggr}.New(mockProvider) + lggr, observedLogs := logger.TestObserved(t, zapcore.DebugLevel) + authenticator := NodeJWTAuthenticatorConfig{Logger: lggr}.New(mockProvider) - ctx, cancel := context.WithCancel(context.Background()) - cancel() // already cancelled + ctx, cancel := context.WithCancel(context.Background()) + cancel() // already cancelled - testRequest := testRequest{Field: "test-request"} - valid, claims, err := authenticator.AuthenticateJWT(ctx, createValidJWT(privateKey, csaPubKey), testRequest) + testRequest := testRequest{Field: "test-request"} + valid, claims, err := authenticator.AuthenticateJWT(ctx, createValidJWT(privateKey, csaPubKey), testRequest) - require.Error(t, err) - assert.False(t, valid) - assert.NotNil(t, claims) - assert.ErrorIs(t, err, context.Canceled) + require.Error(t, err) + assert.False(t, valid) + assert.NotNil(t, claims) + assert.ErrorIs(t, err, context.Canceled) - entries := observedLogs.FilterMessage("Node validation skipped: context canceled or deadline exceeded").All() - require.Len(t, entries, 1, "expected exactly one context-cancellation log entry") - assert.Equal(t, zapcore.WarnLevel, entries[0].Level, "context cancellation from provider should log at WARN not ERROR") - assert.Equal(t, context.Canceled.Error(), entries[0].ContextMap()["contextErr"]) - mockProvider.AssertExpectations(t) -} + entries := observedLogs.FilterMessage("Node validation skipped: context canceled or deadline exceeded").All() + require.Len(t, entries, 1, "expected exactly one context-cancellation log entry") + assert.Equal(t, zapcore.WarnLevel, entries[0].Level, "context cancellation from provider should log at WARN not ERROR") + assert.Equal(t, context.Canceled.Error(), entries[0].ContextMap()["contextErr"]) + mockProvider.AssertExpectations(t) + }) -func TestNodeJWTAuthenticator_AuthenticateJWT_ProviderDeadlineExceededError(t *testing.T) { - // context.DeadlineExceeded from the provider must also be logged at WARN, not ERROR, - // because it is an expected transient condition (e.g. slow upstream), not a system fault. - privateKey, csaPubKey := createValidatorTestKeys() - mockProvider := &mocks.NodeAuthProvider{} - mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.DeadlineExceeded) + t.Run("deadline exceeded error logs at warn level", func(t *testing.T) { + // context.DeadlineExceeded from the provider must also be logged at WARN, not ERROR, + // because it is an expected transient condition (e.g. slow upstream), not a system fault. + privateKey, csaPubKey := createValidatorTestKeys() + mockProvider := &mocks.NodeAuthProvider{} + mockProvider.On("IsNodePubKeyTrusted", mock.Anything, csaPubKey).Return(false, context.DeadlineExceeded) - lggr, observedLogs := logger.TestObserved(t, zapcore.DebugLevel) - authenticator := NodeJWTAuthenticatorConfig{Logger: lggr}.New(mockProvider) + lggr, observedLogs := logger.TestObserved(t, zapcore.DebugLevel) + authenticator := NodeJWTAuthenticatorConfig{Logger: lggr}.New(mockProvider) - ctx, cancel := context.WithTimeout(context.Background(), 0) // immediately expired - defer cancel() + ctx, cancel := context.WithTimeout(context.Background(), 0) // immediately expired + defer cancel() - testRequest := testRequest{Field: "test-request"} - valid, claims, err := authenticator.AuthenticateJWT(ctx, createValidJWT(privateKey, csaPubKey), testRequest) + testRequest := testRequest{Field: "test-request"} + valid, claims, err := authenticator.AuthenticateJWT(ctx, createValidJWT(privateKey, csaPubKey), testRequest) - require.Error(t, err) - assert.False(t, valid) - assert.NotNil(t, claims) - assert.ErrorIs(t, err, context.DeadlineExceeded) + require.Error(t, err) + assert.False(t, valid) + assert.NotNil(t, claims) + assert.ErrorIs(t, err, context.DeadlineExceeded) - entries := observedLogs.FilterMessage("Node validation skipped: context canceled or deadline exceeded").All() - require.Len(t, entries, 1, "expected exactly one context-cancellation log entry") - assert.Equal(t, zapcore.WarnLevel, entries[0].Level, "deadline exceeded from provider should log at WARN not ERROR") - assert.Equal(t, context.DeadlineExceeded.Error(), entries[0].ContextMap()["contextErr"]) - mockProvider.AssertExpectations(t) + entries := observedLogs.FilterMessage("Node validation skipped: context canceled or deadline exceeded").All() + require.Len(t, entries, 1, "expected exactly one context-cancellation log entry") + assert.Equal(t, zapcore.WarnLevel, entries[0].Level, "deadline exceeded from provider should log at WARN not ERROR") + assert.Equal(t, context.DeadlineExceeded.Error(), entries[0].ContextMap()["contextErr"]) + mockProvider.AssertExpectations(t) + }) } func TestNodeJWTAuthenticatorConfig_New(t *testing.T) {