diff --git a/pkg/nodeauth/jwt/node_jwt_authenticator.go b/pkg/nodeauth/jwt/node_jwt_authenticator.go index 8b4fef5bdd..1cbf53c445 100644 --- a/pkg/nodeauth/jwt/node_jwt_authenticator.go +++ b/pkg/nodeauth/jwt/node_jwt_authenticator.go @@ -124,10 +124,21 @@ 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.Errorw("Node validation failed", - "csaPubKey", hex.EncodeToString(publicKey), - "error", err, - ) + if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) { + attrs := []any{ + "csaPubKey", hex.EncodeToString(publicKey), + "error", err, + } + if ctxErr := ctx.Err(); ctxErr != nil { + attrs = append(attrs, "contextErr", ctxErr) + } + v.logger.Warnw("Node validation skipped: context canceled or deadline exceeded", attrs...) + } else { + v.logger.Errorw("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 a0b2d090be..798170e734 100644 --- a/pkg/nodeauth/jwt/node_jwt_authenticator_test.go +++ b/pkg/nodeauth/jwt/node_jwt_authenticator_test.go @@ -5,6 +5,7 @@ import ( "crypto/ed25519" "crypto/rand" "encoding/hex" + "errors" "testing" "time" @@ -12,6 +13,7 @@ import ( "github.com/stretchr/testify/assert" "github.com/stretchr/testify/mock" "github.com/stretchr/testify/require" + "go.uber.org/zap/zapcore" "github.com/smartcontractkit/chainlink-common/pkg/logger" "github.com/smartcontractkit/chainlink-common/pkg/nodeauth/jwt/mocks" @@ -450,6 +452,88 @@ func TestNewNodeJWTAuthenticator_WithAndWithoutLeeway(t *testing.T) { }) } +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) + + 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") + + 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) + }) + + 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) + + 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) + + 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) + }) + + 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) + + 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) + + 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) { t.Run("basic construction via config.New", func(t *testing.T) { mockProvider := &mocks.NodeAuthProvider{}