From 64fcbf51dffb4148802fa176e7f35ad1a6432cdd Mon Sep 17 00:00:00 2001 From: Michael Smithhisler Date: Fri, 17 Jan 2025 11:07:10 -0500 Subject: [PATCH] auth: adds option to enable verbose logging during sso --- api/acl.go | 3 + lib/auth/binder.go | 13 +++- lib/auth/binder_test.go | 4 +- nomad/acl_endpoint.go | 67 ++++++++++++++++++- nomad/acl_endpoint_test.go | 36 +++++++++- nomad/mock/acl.go | 1 + nomad/structs/acl.go | 5 ++ website/content/api-docs/acl/auth-methods.mdx | 4 ++ 8 files changed, 127 insertions(+), 6 deletions(-) diff --git a/api/acl.go b/api/acl.go index 64d1a22afb5..88a64a107b6 100644 --- a/api/acl.go +++ b/api/acl.go @@ -857,6 +857,9 @@ type ACLAuthMethodConfig struct { // (value). ClaimMappings map[string]string ListClaimMappings map[string]string + // Enables logging of claims and binding-rule evaluations when + // debug level logging is enabled. + VerboseLogging bool } // MarshalJSON implements the json.Marshaler interface and allows diff --git a/lib/auth/binder.go b/lib/auth/binder.go index 0614784a575..7c2abe31550 100644 --- a/lib/auth/binder.go +++ b/lib/auth/binder.go @@ -8,6 +8,7 @@ import ( "strings" "github.com/hashicorp/go-bexpr" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/go-memdb" "github.com/hashicorp/hil" "github.com/hashicorp/hil/ast" @@ -53,7 +54,7 @@ func (b *Bindings) None() bool { } // Bind collects the ACL roles and policies to be assigned to the created token. -func (b *Binder) Bind(authMethod *structs.ACLAuthMethod, identity *Identity) (*Bindings, error) { +func (b *Binder) Bind(vlog hclog.Logger, authMethod *structs.ACLAuthMethod, identity *Identity) (*Bindings, error) { var ( bindings Bindings err error @@ -75,6 +76,9 @@ func (b *Binder) Bind(authMethod *structs.ACLAuthMethod, identity *Identity) (*B rule := raw.(*structs.ACLBindingRule) if doesSelectorMatch(rule.Selector, identity.Claims) { matchingRules = append(matchingRules, rule) + vlog.Debug("binding-rule selector matches an identity claim, will evaluate bind-name", "selector", rule.Selector) + } else { + vlog.Debug("bind-rule selector did not match any claims", "selector", rule.Selector) } } if len(matchingRules) == 0 { @@ -103,6 +107,9 @@ func (b *Binder) Bind(authMethod *structs.ACLAuthMethod, identity *Identity) (*B bindings.Roles = append(bindings.Roles, &structs.ACLTokenRoleLink{ ID: role.ID, }) + vlog.Debug("role found with name matching ACL binding-rule", "name", bindName) + } else { + vlog.Debug("no role found with name matching ACL binding-rule", "name", bindName) } case structs.ACLBindingRuleBindTypePolicy: policy, err := b.store.ACLPolicyByName(nil, bindName) @@ -112,8 +119,12 @@ func (b *Binder) Bind(authMethod *structs.ACLAuthMethod, identity *Identity) (*B if policy != nil { bindings.Policies = append(bindings.Policies, policy.Name) + vlog.Debug("policy found with name matching ACL binding-rule", "name", bindName) + } else { + vlog.Debug("no policy found with name matching ACL binding-rule", "name", bindName) } case structs.ACLBindingRuleBindTypeManagement: + vlog.Debug("management ACL binding-rule found", "name", bindName) bindings.Management = true bindings.Policies = nil bindings.Roles = nil diff --git a/lib/auth/binder_test.go b/lib/auth/binder_test.go index f9662ca6c1e..671d1caacd9 100644 --- a/lib/auth/binder_test.go +++ b/lib/auth/binder_test.go @@ -8,6 +8,7 @@ import ( "github.com/shoenig/test/must" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/nomad/ci" "github.com/hashicorp/nomad/helper/uuid" "github.com/hashicorp/nomad/nomad/mock" @@ -115,7 +116,8 @@ func TestBinder_Bind(t *testing.T) { } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - got, err := testBind.Bind(tt.authMethod, tt.identity) + l := hclog.NewNullLogger() + got, err := testBind.Bind(l, tt.authMethod, tt.identity) if tt.wantErr { must.Error(t, err) } else { diff --git a/nomad/acl_endpoint.go b/nomad/acl_endpoint.go index 353d3b5123d..df13456611e 100644 --- a/nomad/acl_endpoint.go +++ b/nomad/acl_endpoint.go @@ -5,6 +5,7 @@ package nomad import ( "context" + "encoding/json" "errors" "fmt" "net/http" @@ -52,6 +53,10 @@ const ( // aclLoginRequestExpiryTime is the deadline used when performing HTTP // requests to external APIs during the validation of bearer tokens. aclLoginRequestExpiryTime = 60 * time.Second + + // verboseLoggingMessage is the message displayed to a user when + // this auth config is enabled + verboseLoggingMessage = "attempting login with verbose logging enabled" ) // ACL endpoint is used for manipulating ACL tokens and policies @@ -2691,6 +2696,14 @@ func (a *ACL) OIDCCompleteAuth( return structs.NewErrRPCCodedf(http.StatusBadRequest, "auth-method %q not found", args.AuthMethodName) } + // vlog is a verbose logger used for debugging OIDC in test environments + vlog := hclog.NewNullLogger() + if authMethod.Config.VerboseLogging { + vlog = a.logger + } + + vlog.Debug(verboseLoggingMessage) + // If the authentication method generates global ACL tokens, we need to // forward the request onto the authoritative regional leader. if authMethod.TokenLocalityIsGlobal() { @@ -2761,6 +2774,30 @@ func (a *ACL) OIDCCompleteAuth( return err } + // No need to do all this marshaling if VerboseLogging is disabled + if authMethod.Config.VerboseLogging { + idTokenClaimBytes, err := json.MarshalIndent(idTokenClaims, "", " ") + if err != nil { + return fmt.Errorf("failed to marshal ID token claims") + } + + userClaimBytes, err := json.MarshalIndent(userClaims, "", " ") + if err != nil { + return fmt.Errorf("failed to marshal user claims") + } + + internalClaimBytes, err := json.MarshalIndent(oidcInternalClaims.List, "", " ") + if err != nil { + return fmt.Errorf("failed to marshal OIDC internal claims list") + } + + vlog.Debug("Claims", + "Token Claims", string(idTokenClaimBytes), + "User Claims", string(userClaimBytes), + "Claims after mapping to Nomad identity attributes", string(internalClaimBytes), + ) + } + // Create a new binder object based on the current state snapshot to // provide consistency within the RPC handler. oidcBinder := auth.NewBinder(stateSnapshot) @@ -2768,7 +2805,7 @@ func (a *ACL) OIDCCompleteAuth( // Generate the role and policy bindings that will be assigned to the ACL // token. Ensure we have at least 1 role or policy, otherwise the RPC will // fail anyway. - tokenBindings, err := oidcBinder.Bind(authMethod, auth.NewIdentity(authMethod.Config, oidcInternalClaims)) + tokenBindings, err := oidcBinder.Bind(vlog, authMethod, auth.NewIdentity(authMethod.Config, oidcInternalClaims)) if err != nil { return err } @@ -2910,6 +2947,14 @@ func (a *ACL) Login(args *structs.ACLLoginRequest, reply *structs.ACLLoginRespon ) } + // vlog is a verbose logger used for debugging in test environments + vlog := hclog.NewNullLogger() + if authMethod.Config.VerboseLogging { + vlog = a.logger + } + + vlog.Debug(verboseLoggingMessage) + // Create a new binder object based on the current state snapshot to // provide consistency within the RPC handler. jwtBinder := auth.NewBinder(stateSnapshot) @@ -2921,7 +2966,25 @@ func (a *ACL) Login(args *structs.ACLLoginRequest, reply *structs.ACLLoginRespon return err } - tokenBindings, err := jwtBinder.Bind(authMethod, auth.NewIdentity(authMethod.Config, jwtClaims)) + // No need to do marshaling if VerboseLogging is not enabled + if authMethod.Config.VerboseLogging { + idTokenClaimBytes, err := json.MarshalIndent(claims, "", " ") + if err != nil { + return fmt.Errorf("failed to marshal token claims") + } + + internalClaimBytes, err := json.MarshalIndent(jwtClaims.List, "", " ") + if err != nil { + return fmt.Errorf("failed to marshal claims list") + } + + vlog.Debug("Claims", + "Token Claims", string(idTokenClaimBytes), + "Claims after mapping to Nomad identity attributes", string(internalClaimBytes), + ) + } + + tokenBindings, err := jwtBinder.Bind(vlog, authMethod, auth.NewIdentity(authMethod.Config, jwtClaims)) if err != nil { return err } diff --git a/nomad/acl_endpoint_test.go b/nomad/acl_endpoint_test.go index ce26d6a4d2a..3520b4fd045 100644 --- a/nomad/acl_endpoint_test.go +++ b/nomad/acl_endpoint_test.go @@ -4,15 +4,19 @@ package nomad import ( + "bytes" "fmt" + "io" "net/url" "os" "path/filepath" + "strings" "testing" "time" "github.com/golang-jwt/jwt/v5" capOIDC "github.com/hashicorp/cap/oidc" + "github.com/hashicorp/go-hclog" "github.com/hashicorp/go-memdb" msgpackrpc "github.com/hashicorp/net-rpc-msgpackrpc/v2" "github.com/hashicorp/nomad/ci" @@ -3631,7 +3635,14 @@ func TestACL_OIDCAuthURL(t *testing.T) { func TestACL_OIDCCompleteAuth(t *testing.T) { ci.Parallel(t) - testServer, _, testServerCleanupFn := TestACLServer(t, nil) + // setup logging output to test verbose logging + var buf bytes.Buffer + testServer, _, testServerCleanupFn := TestACLServer(t, func(c *Config) { + c.Logger = hclog.NewInterceptLogger(&hclog.LoggerOptions{ + Level: hclog.Debug, + Output: io.MultiWriter(&buf, os.Stderr), + }) + }) defer testServerCleanupFn() codec := rpcClient(t, testServer) testutil.WaitForLeader(t, testServer.RPC) @@ -3720,6 +3731,12 @@ func TestACL_OIDCCompleteAuth(t *testing.T) { must.Error(t, err) must.ErrorContains(t, err, "400") must.ErrorContains(t, err, "no role or policy bindings matched") + must.False(t, strings.Contains(buf.String(), verboseLoggingMessage)) + + // Reset buf and enable verbose logging + buf.Reset() + mockedAuthMethod.Config.VerboseLogging = true + must.NoError(t, testServer.fsm.State().UpsertACLAuthMethods(11, []*structs.ACLAuthMethod{mockedAuthMethod})) // Upsert an ACL policy and role, so that we can reference this within our // OIDC claims. @@ -3767,6 +3784,7 @@ func TestACL_OIDCCompleteAuth(t *testing.T) { must.Len(t, 1, completeAuthResp4.ACLToken.Roles) must.Eq(t, mockACLRole.Name, completeAuthResp4.ACLToken.Roles[0].Name) must.Eq(t, mockACLRole.ID, completeAuthResp4.ACLToken.Roles[0].ID) + must.True(t, strings.Contains(buf.String(), verboseLoggingMessage)) // Create a binding rule which generates management tokens. This should // override the other rules, giving us a management token when we next @@ -3803,7 +3821,14 @@ func TestACL_OIDCCompleteAuth(t *testing.T) { func TestACL_Login(t *testing.T) { ci.Parallel(t) - testServer, _, testServerCleanupFn := TestACLServer(t, nil) + // setup logging output to test verbose logging + var buf bytes.Buffer + testServer, _, testServerCleanupFn := TestACLServer(t, func(c *Config) { + c.Logger = hclog.NewInterceptLogger(&hclog.LoggerOptions{ + Level: hclog.Debug, + Output: io.MultiWriter(&buf, os.Stderr), + }) + }) defer testServerCleanupFn() codec := rpcClient(t, testServer) testutil.WaitForLeader(t, testServer.RPC) @@ -3885,6 +3910,12 @@ func TestACL_Login(t *testing.T) { must.Error(t, err) must.ErrorContains(t, err, "400") must.ErrorContains(t, err, "no role or policy bindings matched") + must.False(t, strings.Contains(buf.String(), verboseLoggingMessage)) + + // Reset buf and enable verbose logging + buf.Reset() + mockedAuthMethod.Config.VerboseLogging = true + must.NoError(t, testServer.fsm.State().UpsertACLAuthMethods(11, []*structs.ACLAuthMethod{mockedAuthMethod})) // Upsert an ACL policy and role, so that we can reference this within our // JWT claims. @@ -3930,6 +3961,7 @@ func TestACL_Login(t *testing.T) { must.Eq(t, mockACLRole.Name, completeAuthResp4.ACLToken.Roles[0].Name) must.Eq(t, mockACLRole.ID, completeAuthResp4.ACLToken.Roles[0].ID) must.Eq(t, mockedAuthMethod.Type+"-"+mockedAuthMethod.Name, completeAuthResp4.ACLToken.Name) + must.True(t, strings.Contains(buf.String(), verboseLoggingMessage)) // Create a binding rule which generates management tokens. This should // override the other rules, giving us a management token when we next diff --git a/nomad/mock/acl.go b/nomad/mock/acl.go index dde6174b6dd..6bec60495c8 100644 --- a/nomad/mock/acl.go +++ b/nomad/mock/acl.go @@ -283,6 +283,7 @@ func ACLOIDCAuthMethod() *structs.ACLAuthMethod { SigningAlgs: []string{"RS256"}, ClaimMappings: map[string]string{"foo": "bar"}, ListClaimMappings: map[string]string{"foo": "bar"}, + VerboseLogging: false, }, CreateTime: time.Now().UTC(), CreateIndex: 10, diff --git a/nomad/structs/acl.go b/nomad/structs/acl.go index eed00046fa8..afdea9b6001 100644 --- a/nomad/structs/acl.go +++ b/nomad/structs/acl.go @@ -795,6 +795,7 @@ func (a *ACLAuthMethod) SetHash() []byte { _, _ = hash.Write([]byte(a.Config.OIDCClientID)) _, _ = hash.Write([]byte(a.Config.OIDCClientSecret)) _, _ = hash.Write([]byte(strconv.FormatBool(a.Config.OIDCDisableUserInfo))) + _, _ = hash.Write([]byte(strconv.FormatBool(a.Config.VerboseLogging))) _, _ = hash.Write([]byte(a.Config.ExpirationLeeway.String())) _, _ = hash.Write([]byte(a.Config.NotBeforeLeeway.String())) _, _ = hash.Write([]byte(a.Config.ClockSkewLeeway.String())) @@ -1043,6 +1044,10 @@ type ACLAuthMethodConfig struct { // (value). ClaimMappings map[string]string ListClaimMappings map[string]string + + // Enables logging of claims and binding-rule evaluations when + // debug level logging is enabled. + VerboseLogging bool } func (a *ACLAuthMethodConfig) Copy() *ACLAuthMethodConfig { diff --git a/website/content/api-docs/acl/auth-methods.mdx b/website/content/api-docs/acl/auth-methods.mdx index 56d503378a4..56b0a6ce215 100644 --- a/website/content/api-docs/acl/auth-methods.mdx +++ b/website/content/api-docs/acl/auth-methods.mdx @@ -116,6 +116,10 @@ The table below shows this endpoint's support for copied to a metadata field (value). Use this if the claim you are capturing is list-like (such as groups). + - `VerboseLogging` `(bool: false)` - When set to `true`, Nomad will log token claims + and information related to binding-rule and role/policy evaluations. Not recommended + in production since sensitive information may be present. + ### Sample payload ```json