From 8cf9c599574828d48e1761aa8531563d9086bb56 Mon Sep 17 00:00:00 2001 From: Ryan Richard Date: Thu, 7 Nov 2024 14:15:04 -0800 Subject: [PATCH] refactor to move audit event message types to their own pkg --- internal/auditevent/audit_event.go | 68 +++++++++++++++++++ .../{plog => auditevent}/audit_event_test.go | 2 +- .../supervisorstorage/garbage_collector.go | 7 +- .../downstreamsession/downstream_session.go | 7 +- .../endpoints/auth/auth_handler.go | 11 +-- .../endpoints/callback/callback_handler.go | 3 +- .../endpoints/login/login_handler.go | 3 +- .../endpoints/token/token_handler.go | 7 +- .../tokenendpointauditor/parameter_auditor.go | 5 +- .../requestlogger/request_logger.go | 5 +- internal/plog/audit_event.go | 68 ------------------- internal/plog/plog.go | 5 +- internal/registry/credentialrequest/rest.go | 3 +- 13 files changed, 102 insertions(+), 92 deletions(-) create mode 100644 internal/auditevent/audit_event.go rename internal/{plog => auditevent}/audit_event_test.go (99%) delete mode 100644 internal/plog/audit_event.go diff --git a/internal/auditevent/audit_event.go b/internal/auditevent/audit_event.go new file mode 100644 index 000000000..e8b0caf48 --- /dev/null +++ b/internal/auditevent/audit_event.go @@ -0,0 +1,68 @@ +// Copyright 2024 the Pinniped contributors. All Rights Reserved. +// SPDX-License-Identifier: Apache-2.0 + +package auditevent + +import ( + "net/url" + + "k8s.io/apimachinery/pkg/util/sets" +) + +type Message string + +const ( + HTTPRequestReceived Message = "HTTP Request Received" + HTTPRequestCompleted Message = "HTTP Request Completed" + HTTPRequestParameters Message = "HTTP Request Parameters" + HTTPRequestCustomHeadersUsed Message = "HTTP Request Custom Headers Used" + UsingUpstreamIDP Message = "Using Upstream IDP" + AuthorizeIDFromParameters Message = "AuthorizeID From Parameters" + IdentityFromUpstreamIDP Message = "Identity From Upstream IDP" + IdentityRefreshedFromUpstreamIDP Message = "Identity Refreshed From Upstream IDP" + SessionStarted Message = "Session Started" + SessionRefreshed Message = "Session Refreshed" + AuthenticationRejectedByTransforms Message = "Authentication Rejected By Transforms" + UpstreamOIDCTokenRevoked Message = "Upstream OIDC Token Revoked" //nolint:gosec // this is not a credential + SessionGarbageCollected Message = "Session Garbage Collected" + TokenCredentialRequest Message = "TokenCredentialRequest" //nolint:gosec // this is not a credential + UpstreamAuthorizeRedirect Message = "Upstream Authorize Redirect" +) + +// SanitizeParams can be used to redact all params not included in the allowedKeys set. +// Useful when audit logging HTTPRequestParameters events. +func SanitizeParams(inputParams url.Values, allowedKeys sets.Set[string]) []any { + params := make(map[string]string) + multiValueParams := make(url.Values) + + transform := func(key, value string) string { + if !allowedKeys.Has(key) { + return "redacted" + } + + unescape, err := url.QueryUnescape(value) + if err != nil { + // ignore these errors and just use the original query parameter + unescape = value + } + return unescape + } + + for key := range inputParams { + for i, p := range inputParams[key] { + transformed := transform(key, p) + if i == 0 { + params[key] = transformed + } + + if len(inputParams[key]) > 1 { + multiValueParams[key] = append(multiValueParams[key], transformed) + } + } + } + + if len(multiValueParams) > 0 { + return []any{"params", params, "multiValueParams", multiValueParams} + } + return []any{"params", params} +} diff --git a/internal/plog/audit_event_test.go b/internal/auditevent/audit_event_test.go similarity index 99% rename from internal/plog/audit_event_test.go rename to internal/auditevent/audit_event_test.go index 99658f8da..51924710c 100644 --- a/internal/plog/audit_event_test.go +++ b/internal/auditevent/audit_event_test.go @@ -1,7 +1,7 @@ // Copyright 2024 the Pinniped contributors. All Rights Reserved. // SPDX-License-Identifier: Apache-2.0 -package plog +package auditevent import ( "net/url" diff --git a/internal/controller/supervisorstorage/garbage_collector.go b/internal/controller/supervisorstorage/garbage_collector.go index 4e92f1da8..3f0eb4bbd 100644 --- a/internal/controller/supervisorstorage/garbage_collector.go +++ b/internal/controller/supervisorstorage/garbage_collector.go @@ -19,6 +19,7 @@ import ( clocktesting "k8s.io/utils/clock/testing" oidcapi "go.pinniped.dev/generated/latest/apis/supervisor/oidc" + "go.pinniped.dev/internal/auditevent" pinnipedcontroller "go.pinniped.dev/internal/controller" "go.pinniped.dev/internal/controllerlib" "go.pinniped.dev/internal/crud" @@ -283,7 +284,7 @@ func (c *garbageCollectorController) tryRevokeUpstreamOIDCToken( if err != nil { return err } - c.auditLogger.Audit(plog.AuditEventUpstreamOIDCTokenRevoked, plog.NoHTTPRequestAvailable(), request, + c.auditLogger.Audit(auditevent.UpstreamOIDCTokenRevoked, plog.NoHTTPRequestAvailable(), request, "type", upstreamprovider.RefreshTokenType) plog.Trace("garbage collector successfully revoked upstream OIDC refresh token (or provider has no revocation endpoint)", logKV(secret)...) } @@ -293,7 +294,7 @@ func (c *garbageCollectorController) tryRevokeUpstreamOIDCToken( if err != nil { return err } - c.auditLogger.Audit(plog.AuditEventUpstreamOIDCTokenRevoked, plog.NoHTTPRequestAvailable(), request, + c.auditLogger.Audit(auditevent.UpstreamOIDCTokenRevoked, plog.NoHTTPRequestAvailable(), request, "type", upstreamprovider.AccessTokenType) plog.Trace("garbage collector successfully revoked upstream OIDC access token (or provider has no revocation endpoint)", logKV(secret)...) } @@ -304,7 +305,7 @@ func (c *garbageCollectorController) tryRevokeUpstreamOIDCToken( func (c *garbageCollectorController) maybeAuditLogGC(storageType string, secret *corev1.Secret) { r, err := c.requestFromSecret(storageType, secret) if err == nil && r != nil { - c.auditLogger.Audit(plog.AuditEventSessionGarbageCollected, plog.NoHTTPRequestAvailable(), r, + c.auditLogger.Audit(auditevent.SessionGarbageCollected, plog.NoHTTPRequestAvailable(), r, "storageType", storageType) } } diff --git a/internal/federationdomain/downstreamsession/downstream_session.go b/internal/federationdomain/downstreamsession/downstream_session.go index 7dd1d377e..8a4bcb4d8 100644 --- a/internal/federationdomain/downstreamsession/downstream_session.go +++ b/internal/federationdomain/downstreamsession/downstream_session.go @@ -15,6 +15,7 @@ import ( fositejwt "github.com/ory/fosite/token/jwt" oidcapi "go.pinniped.dev/generated/latest/apis/supervisor/oidc" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/constable" "go.pinniped.dev/internal/federationdomain/oidc" "go.pinniped.dev/internal/federationdomain/resolvedprovider" @@ -49,7 +50,7 @@ func NewPinnipedSession( ) (*psession.PinnipedSession, error) { now := time.Now().UTC() - auditLogger.Audit(plog.AuditEventIdentityFromUpstreamIDP, ctx, plog.NoSessionPersisted(), + auditLogger.Audit(auditevent.IdentityFromUpstreamIDP, ctx, plog.NoSessionPersisted(), "upstreamIDPDisplayName", c.IdentityProvider.GetDisplayName(), "upstreamIDPType", c.IdentityProvider.GetSessionProviderType(), "upstreamIDPResourceName", c.IdentityProvider.GetProvider().GetResourceName(), @@ -60,7 +61,7 @@ func NewPinnipedSession( downstreamUsername, downstreamGroups, err := applyIdentityTransformations(ctx, c.IdentityProvider.GetTransforms(), c.UpstreamIdentity.UpstreamUsername, c.UpstreamIdentity.UpstreamGroups) if err != nil { - auditLogger.Audit(plog.AuditEventAuthenticationRejectedByTransforms, ctx, plog.NoSessionPersisted(), + auditLogger.Audit(auditevent.AuthenticationRejectedByTransforms, ctx, plog.NoSessionPersisted(), "reason", err) return nil, err } @@ -108,7 +109,7 @@ func NewPinnipedSession( pinnipedSession.IDTokenClaims().Extra = extras - auditLogger.Audit(plog.AuditEventSessionStarted, ctx, c.SessionIDGetter, + auditLogger.Audit(auditevent.SessionStarted, ctx, c.SessionIDGetter, "username", downstreamUsername, "groups", downstreamGroups, "subject", c.UpstreamIdentity.DownstreamSubject, diff --git a/internal/federationdomain/endpoints/auth/auth_handler.go b/internal/federationdomain/endpoints/auth/auth_handler.go index 19cd100f6..a046ccc75 100644 --- a/internal/federationdomain/endpoints/auth/auth_handler.go +++ b/internal/federationdomain/endpoints/auth/auth_handler.go @@ -17,6 +17,7 @@ import ( "k8s.io/apimachinery/pkg/util/sets" oidcapi "go.pinniped.dev/generated/latest/apis/supervisor/oidc" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/federationdomain/csrftoken" "go.pinniped.dev/internal/federationdomain/downstreamsession" "go.pinniped.dev/internal/federationdomain/federationdomainproviders" @@ -111,12 +112,12 @@ func (h *authorizeHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { // Log if these headers were present, but don't log the actual values. The password is obviously sensitive, // and sometimes users use their password as their username by mistake. - h.auditLogger.Audit(plog.AuditEventHTTPRequestCustomHeadersUsed, r.Context(), plog.NoSessionPersisted(), + h.auditLogger.Audit(auditevent.HTTPRequestCustomHeadersUsed, r.Context(), plog.NoSessionPersisted(), oidcapi.AuthorizeUsernameHeaderName, hadUsernameHeader, oidcapi.AuthorizePasswordHeaderName, hadPasswordHeader) - h.auditLogger.Audit(plog.AuditEventHTTPRequestParameters, r.Context(), plog.NoSessionPersisted(), - plog.SanitizeParams(r.Form, paramsSafeToLog())...) + h.auditLogger.Audit(auditevent.HTTPRequestParameters, r.Context(), plog.NoSessionPersisted(), + auditevent.SanitizeParams(r.Form, paramsSafeToLog())...) if r.Method != http.MethodPost && r.Method != http.MethodGet { // https://openid.net/specs/openid-connect-core-1_0.html#AuthRequest @@ -155,7 +156,7 @@ func (h *authorizeHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { return } - h.auditLogger.Audit(plog.AuditEventUsingUpstreamIDP, r.Context(), plog.NoSessionPersisted(), + h.auditLogger.Audit(auditevent.UsingUpstreamIDP, r.Context(), plog.NoSessionPersisted(), "displayName", idp.GetDisplayName(), "resourceName", idp.GetProvider().GetResourceName(), "resourceUID", idp.GetProvider().GetResourceUID(), @@ -220,7 +221,7 @@ func (h *authorizeHandler) authorize( authorizeID, err = h.authorizeWithBrowser(r, w, oauthHelper, authorizeRequester, idp) if err == nil { - h.auditLogger.Audit(plog.AuditEventUpstreamAuthorizeRedirect, r.Context(), plog.NoSessionPersisted(), + h.auditLogger.Audit(auditevent.UpstreamAuthorizeRedirect, r.Context(), plog.NoSessionPersisted(), "authorizeID", authorizeID) } } diff --git a/internal/federationdomain/endpoints/callback/callback_handler.go b/internal/federationdomain/endpoints/callback/callback_handler.go index 60853f6b1..8078e530b 100644 --- a/internal/federationdomain/endpoints/callback/callback_handler.go +++ b/internal/federationdomain/endpoints/callback/callback_handler.go @@ -10,6 +10,7 @@ import ( "github.com/ory/fosite" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/federationdomain/downstreamsession" "go.pinniped.dev/internal/federationdomain/federationdomainproviders" "go.pinniped.dev/internal/federationdomain/formposthtml" @@ -33,7 +34,7 @@ func NewHandler( return err } - auditLogger.Audit(plog.AuditEventAuthorizeIDFromParameters, r.Context(), plog.NoSessionPersisted(), + auditLogger.Audit(auditevent.AuthorizeIDFromParameters, r.Context(), plog.NoSessionPersisted(), "authorizeID", encodedState.AuthorizeID()) idp, err := upstreamIDPs.FindUpstreamIDPByDisplayName(decodedState.UpstreamName) diff --git a/internal/federationdomain/endpoints/login/login_handler.go b/internal/federationdomain/endpoints/login/login_handler.go index e37c6d40b..d1a4c4126 100644 --- a/internal/federationdomain/endpoints/login/login_handler.go +++ b/internal/federationdomain/endpoints/login/login_handler.go @@ -7,6 +7,7 @@ import ( "net/http" idpdiscoveryv1alpha1 "go.pinniped.dev/generated/latest/apis/supervisor/idpdiscovery/v1alpha1" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/federationdomain/endpoints/login/loginhtml" "go.pinniped.dev/internal/federationdomain/formposthtml" "go.pinniped.dev/internal/federationdomain/oidc" @@ -58,7 +59,7 @@ func NewHandler( return err } - auditLogger.Audit(plog.AuditEventAuthorizeIDFromParameters, r.Context(), plog.NoSessionPersisted(), + auditLogger.Audit(auditevent.AuthorizeIDFromParameters, r.Context(), plog.NoSessionPersisted(), "authorizeID", encodedState.AuthorizeID()) switch decodedState.UpstreamType { diff --git a/internal/federationdomain/endpoints/token/token_handler.go b/internal/federationdomain/endpoints/token/token_handler.go index e50811748..e701be106 100644 --- a/internal/federationdomain/endpoints/token/token_handler.go +++ b/internal/federationdomain/endpoints/token/token_handler.go @@ -19,6 +19,7 @@ import ( "k8s.io/apiserver/pkg/warning" oidcapi "go.pinniped.dev/generated/latest/apis/supervisor/oidc" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/federationdomain/federationdomainproviders" "go.pinniped.dev/internal/federationdomain/idtokenlifespan" "go.pinniped.dev/internal/federationdomain/oidc" @@ -191,7 +192,7 @@ func upstreamRefresh( return err } - auditLogger.Audit(plog.AuditEventIdentityRefreshedFromUpstreamIDP, ctx, accessRequest, + auditLogger.Audit(auditevent.IdentityRefreshedFromUpstreamIDP, ctx, accessRequest, "upstreamUsername", refreshedIdentity.UpstreamUsername, "upstreamGroups", refreshedIdentity.UpstreamGroups) @@ -220,7 +221,7 @@ func upstreamRefresh( if fositeErr != nil { // The HintField is always populated by applyIdentityTransformationsDuringRefresh, // and more descriptive than fositeErr.Error() which is just "error". - auditLogger.Audit(plog.AuditEventAuthenticationRejectedByTransforms, ctx, accessRequest, + auditLogger.Audit(auditevent.AuthenticationRejectedByTransforms, ctx, accessRequest, "reason", fositeErr.HintField) return fositeErr } @@ -238,7 +239,7 @@ func upstreamRefresh( session.Fosite.Claims.Extra[oidcapi.IDTokenClaimGroups] = refreshedTransformedGroups } - auditLogger.Audit(plog.AuditEventSessionRefreshed, ctx, accessRequest, + auditLogger.Audit(auditevent.SessionRefreshed, ctx, accessRequest, "username", oldTransformedUsername, // not allowed to change above so must be the same as old "groups", refreshedTransformedGroups, "subject", previousIdentity.DownstreamSubject) diff --git a/internal/federationdomain/endpoints/tokenendpointauditor/parameter_auditor.go b/internal/federationdomain/endpoints/tokenendpointauditor/parameter_auditor.go index 37f5413c3..011949f91 100644 --- a/internal/federationdomain/endpoints/tokenendpointauditor/parameter_auditor.go +++ b/internal/federationdomain/endpoints/tokenendpointauditor/parameter_auditor.go @@ -10,6 +10,7 @@ import ( "github.com/ory/fosite/compose" "k8s.io/apimachinery/pkg/util/sets" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/plog" ) @@ -52,8 +53,8 @@ func paramsSafeToLogTokenEndpoint() sets.Set[string] { } func (p parameterAuditorHandler) CanHandleTokenEndpointRequest(ctx context.Context, requester fosite.AccessRequester) bool { - p.auditLogger.Audit(plog.AuditEventHTTPRequestParameters, ctx, plog.NoSessionPersisted(), - plog.SanitizeParams(requester.GetRequestForm(), paramsSafeToLogTokenEndpoint())...) + p.auditLogger.Audit(auditevent.HTTPRequestParameters, ctx, plog.NoSessionPersisted(), + auditevent.SanitizeParams(requester.GetRequestForm(), paramsSafeToLogTokenEndpoint())...) return false } diff --git a/internal/federationdomain/requestlogger/request_logger.go b/internal/federationdomain/requestlogger/request_logger.go index 11e2400eb..e2f9e74d7 100644 --- a/internal/federationdomain/requestlogger/request_logger.go +++ b/internal/federationdomain/requestlogger/request_logger.go @@ -18,6 +18,7 @@ import ( "k8s.io/apiserver/pkg/endpoints/responsewriter" "k8s.io/utils/clock" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/config/supervisor" "go.pinniped.dev/internal/httputil/requestutil" "go.pinniped.dev/internal/plog" @@ -102,7 +103,7 @@ func (rl *requestLogger) logRequestReceived() { } // Always log all other requests, including 404's caused by bad paths, for debugging purposes. - rl.auditLogger.Audit(plog.AuditEventHTTPRequestReceived, + rl.auditLogger.Audit(auditevent.HTTPRequestReceived, r.Context(), plog.NoSessionPersisted(), "proto", r.Proto, @@ -142,7 +143,7 @@ func (rl *requestLogger) logRequestComplete() { } } - rl.auditLogger.Audit(plog.AuditEventHTTPRequestCompleted, + rl.auditLogger.Audit(auditevent.HTTPRequestCompleted, r.Context(), plog.NoSessionPersisted(), "path", r.URL.Path, // include the path again to make it easy to "grep -v healthz" to watch all other audit events diff --git a/internal/plog/audit_event.go b/internal/plog/audit_event.go deleted file mode 100644 index b3d2d4492..000000000 --- a/internal/plog/audit_event.go +++ /dev/null @@ -1,68 +0,0 @@ -// Copyright 2024 the Pinniped contributors. All Rights Reserved. -// SPDX-License-Identifier: Apache-2.0 - -package plog - -import ( - "net/url" - - "k8s.io/apimachinery/pkg/util/sets" -) - -type AuditEventMessage string - -const ( - AuditEventHTTPRequestReceived AuditEventMessage = "HTTP Request Received" - AuditEventHTTPRequestCompleted AuditEventMessage = "HTTP Request Completed" - AuditEventHTTPRequestParameters AuditEventMessage = "HTTP Request Parameters" - AuditEventHTTPRequestCustomHeadersUsed AuditEventMessage = "HTTP Request Custom Headers Used" - AuditEventUsingUpstreamIDP AuditEventMessage = "Using Upstream IDP" - AuditEventAuthorizeIDFromParameters AuditEventMessage = "AuthorizeID From Parameters" - AuditEventIdentityFromUpstreamIDP AuditEventMessage = "Identity From Upstream IDP" - AuditEventIdentityRefreshedFromUpstreamIDP AuditEventMessage = "Identity Refreshed From Upstream IDP" - AuditEventSessionStarted AuditEventMessage = "Session Started" - AuditEventSessionRefreshed AuditEventMessage = "Session Refreshed" - AuditEventAuthenticationRejectedByTransforms AuditEventMessage = "Authentication Rejected By Transforms" - AuditEventUpstreamOIDCTokenRevoked AuditEventMessage = "Upstream OIDC Token Revoked" //nolint:gosec // this is not a credential - AuditEventSessionGarbageCollected AuditEventMessage = "Session Garbage Collected" - AuditEventTokenCredentialRequest AuditEventMessage = "TokenCredentialRequest" //nolint:gosec // this is not a credential - AuditEventUpstreamAuthorizeRedirect AuditEventMessage = "Upstream Authorize Redirect" -) - -// SanitizeParams can be used to redact all params not included in the allowedKeys set. -// Useful when audit logging AuditEventHTTPRequestParameters events. -func SanitizeParams(inputParams url.Values, allowedKeys sets.Set[string]) []any { - params := make(map[string]string) - multiValueParams := make(url.Values) - - transform := func(key, value string) string { - if !allowedKeys.Has(key) { - return "redacted" - } - - unescape, err := url.QueryUnescape(value) - if err != nil { - // ignore these errors and just use the original query parameter - unescape = value - } - return unescape - } - - for key := range inputParams { - for i, p := range inputParams[key] { - transformed := transform(key, p) - if i == 0 { - params[key] = transformed - } - - if len(inputParams[key]) > 1 { - multiValueParams[key] = append(multiValueParams[key], transformed) - } - } - } - - if len(multiValueParams) > 0 { - return []any{"params", params, "multiValueParams", multiValueParams} - } - return []any{"params", params} -} diff --git a/internal/plog/plog.go b/internal/plog/plog.go index 81e9893da..8768071e4 100644 --- a/internal/plog/plog.go +++ b/internal/plog/plog.go @@ -33,6 +33,7 @@ import ( "slices" "github.com/go-logr/logr" + "go.pinniped.dev/internal/auditevent" "k8s.io/apiserver/pkg/audit" ) @@ -61,7 +62,7 @@ type AuditLogger interface { // reqCtx and session may be null. // When possible, pass the http request's context as reqCtx, so we may read the audit ID from the context. // When possible, pass the fosite.Requester or fosite.Request as the session, so we can log the session ID. - Audit(msg AuditEventMessage, reqCtx context.Context, session SessionIDGetter, keysAndValues ...any) + Audit(msg auditevent.Message, reqCtx context.Context, session SessionIDGetter, keysAndValues ...any) } // Logger implements the plog logging convention described above. The global functions in this package @@ -126,7 +127,7 @@ func (p pLogger) Error(msg string, err error, keysAndValues ...any) { // by their own separate configuration. This is because Audit logs should always be printed when they are desired // by the admin, regardless of global log level, yet the admin should also have a way to entirely disable them // when they want to avoid potential PII (e.g. usernames) in their pod logs. -func (p pLogger) Audit(msg AuditEventMessage, reqCtx context.Context, session SessionIDGetter, keysAndValues ...any) { +func (p pLogger) Audit(msg auditevent.Message, reqCtx context.Context, session SessionIDGetter, keysAndValues ...any) { // Always add a key/value auditEvent=true. keysAndValues = slices.Concat([]any{"auditEvent", true}, keysAndValues) diff --git a/internal/registry/credentialrequest/rest.go b/internal/registry/credentialrequest/rest.go index 447a5500c..2ca645ce1 100644 --- a/internal/registry/credentialrequest/rest.go +++ b/internal/registry/credentialrequest/rest.go @@ -21,6 +21,7 @@ import ( "k8s.io/utils/trace" loginapi "go.pinniped.dev/generated/latest/apis/concierge/login" + "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/clientcertissuer" "go.pinniped.dev/internal/plog" ) @@ -131,7 +132,7 @@ func (r *REST) Create(ctx context.Context, obj runtime.Object, createValidation traceSuccess(t, userInfo, true) - r.auditLogger.Audit(plog.AuditEventTokenCredentialRequest, ctx, nil, + r.auditLogger.Audit(auditevent.TokenCredentialRequest, ctx, nil, "username", userInfo.GetName(), "groups", userInfo.GetGroups(), "authenticated", true,