From eab3fde3afef52b1a0bb1cb87c6678eae5f37a82 Mon Sep 17 00:00:00 2001 From: Ryan Richard Date: Wed, 13 Nov 2024 11:46:50 -0800 Subject: [PATCH] introduce common method to audit HTTP request parameters --- .../endpoints/auth/auth_handler.go | 32 +--- .../endpoints/auth/auth_handler_test.go | 168 +++++++++--------- .../endpoints/callback/callback_handler.go | 18 +- .../callback/callback_handler_test.go | 72 +++++++- internal/plog/plog.go | 33 ++++ 5 files changed, 207 insertions(+), 116 deletions(-) diff --git a/internal/federationdomain/endpoints/auth/auth_handler.go b/internal/federationdomain/endpoints/auth/auth_handler.go index e2454f559..a06ad4a91 100644 --- a/internal/federationdomain/endpoints/auth/auth_handler.go +++ b/internal/federationdomain/endpoints/auth/auth_handler.go @@ -5,7 +5,6 @@ package auth import ( - "errors" "fmt" "net/http" "net/url" @@ -104,8 +103,9 @@ func (h *authorizeHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { hadPasswordHeader := len(r.Header.Values(oidcapi.AuthorizePasswordHeaderName)) > 0 requestedBrowserlessFlow := hadUsernameHeader || hadPasswordHeader - // Need to parse the request params, so we can get the IDP name and audit log the params. - if err := parseForm(r); err != nil { + // Audit the request params. Also gives us access to the IDP name param for use below, + // before fosite would normally parse the params. + if err := h.auditLogger.AuditRequestParams(r, paramsSafeToLog()); err != nil { oidc.WriteAuthorizeError(r, w, h.oauthHelperWithoutStorage, fosite.NewAuthorizeRequest(), err, requestedBrowserlessFlow) return @@ -121,11 +121,6 @@ func (h *authorizeHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { }, }) - h.auditLogger.Audit(auditevent.HTTPRequestParameters, &plog.AuditParams{ - ReqCtx: r.Context(), - KeysAndValues: 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 // Authorization Servers MUST support the use of the HTTP GET and POST methods defined in @@ -176,27 +171,6 @@ func (h *authorizeHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { h.authorize(w, r, requestedBrowserlessFlow, idp) } -// parseForm parses the query params and/or POST body form params. It returns an error, or in the case of success it -// has the side effect of leaving the parsed form params on the http.Request in the Form field. Request body -// parameters take precedence over URL query string values. -func parseForm(r *http.Request) error { - // The style of form parsing and the text of the error is inspired by fosite's implementation of NewAuthorizeRequest(). - // Fosite only calls ParseMultipartForm() there. However, although ParseMultipartForm() calls ParseForm(), - // it swallows errors from ParseForm() sometimes. To avoid having any errors swallowed, we call both. - // When fosite calls ParseMultipartForm() later, it will be a noop. - if err := r.ParseForm(); err != nil { - return fosite.ErrInvalidRequest. - WithHint("Unable to parse form params, make sure to send a properly formatted query params or form request body."). - WithWrap(err).WithDebug(err.Error()) - } - if err := r.ParseMultipartForm(1 << 20); err != nil && !errors.Is(err, http.ErrNotMultipart) { - return fosite.ErrInvalidRequest. - WithHint("Unable to parse multipart HTTP body, make sure to send a properly formatted form request body."). - WithWrap(err).WithDebug(err.Error()) - } - return nil -} - func (h *authorizeHandler) authorize( w http.ResponseWriter, r *http.Request, diff --git a/internal/federationdomain/endpoints/auth/auth_handler_test.go b/internal/federationdomain/endpoints/auth/auth_handler_test.go index 985666210..c3af4ffe0 100644 --- a/internal/federationdomain/endpoints/auth/auth_handler_test.go +++ b/internal/federationdomain/endpoints/auth/auth_handler_test.go @@ -726,10 +726,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -743,6 +739,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-oidc-idp", "resourceName": "some-oidc-idp", @@ -774,10 +774,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": dynamicClientID, @@ -791,6 +787,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-oidc-idp", "resourceName": "some-oidc-idp", @@ -821,10 +821,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -838,6 +834,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-github-idp", "resourceName": "some-github-idp", @@ -869,10 +869,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": dynamicClientID, @@ -886,6 +882,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-github-idp", "resourceName": "some-github-idp", @@ -916,10 +916,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -933,6 +929,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-ldap-idp", "resourceName": "some-ldap-idp", @@ -964,10 +964,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -980,6 +976,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-oidc-idp", "resourceName": "some-oidc-idp", @@ -1012,10 +1012,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(_ stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1028,6 +1024,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), } }, }, @@ -1051,10 +1051,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyStringWithLocationInHref: true, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1068,6 +1064,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-oidc-idp", "resourceName": "some-oidc-idp", @@ -1175,10 +1175,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantDownstreamCustomSessionData: expectedHappyOIDCPasswordGrantCustomSession, wantAuditLogs: func(_ stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": true, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1192,6 +1188,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": true, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-password-granting-oidc-idp", "resourceName": "some-password-granting-oidc-idp", @@ -1264,10 +1264,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": true, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1281,6 +1277,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": true, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-password-granting-oidc-idp", "resourceName": "some-password-granting-oidc-idp", @@ -1387,10 +1387,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantDownstreamCustomSessionData: expectedHappyLDAPUpstreamCustomSession, wantAuditLogs: func(_ stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": true, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1404,6 +1400,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": true, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-ldap-idp", "resourceName": "some-ldap-idp", @@ -1461,10 +1461,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo ), wantAuditLogs: func(_ stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": true, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1478,6 +1474,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": true, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-ldap-idp", "resourceName": "some-ldap-idp", @@ -1780,10 +1780,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantDownstreamCustomSessionData: expectedHappyActiveDirectoryUpstreamCustomSession, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": true, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1797,6 +1793,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": true, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-active-directory-idp", "resourceName": "some-active-directory-idp", @@ -1894,10 +1894,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "", wantAuditLogs: func(_ stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -1912,6 +1908,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-oidc-idp", "resourceName": "some-oidc-idp", @@ -2180,10 +2180,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": true, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -2197,6 +2193,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": true, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-password-granting-oidc-idp", "resourceName": "some-password-granting-oidc-idp", @@ -2219,10 +2219,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": true, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -2236,6 +2232,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": true, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-ldap-idp", "resourceName": "some-ldap-idp", @@ -2295,10 +2295,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": true, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -2312,6 +2308,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": true, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-password-granting-oidc-idp", "resourceName": "some-password-granting-oidc-idp", @@ -4031,16 +4031,16 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "Method Not Allowed: PUT (try GET or POST)\n", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "baz", "foo": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), } }, }, @@ -4054,16 +4054,16 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "Method Not Allowed: PATCH (try GET or POST)\n", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "baz", "foo": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), } }, }, @@ -4077,16 +4077,16 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo wantBodyString: "Method Not Allowed: DELETE (try GET or POST)\n", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "baz", "foo": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), } }, }, @@ -4328,10 +4328,6 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo ) test.wantAuditLogs = func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ - testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ - "Pinniped-Username": false, - "Pinniped-Password": false, - }), testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ "params": map[string]any{ "client_id": "pinniped-cli", @@ -4345,6 +4341,10 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo "state": "redacted", }, }), + testutil.WantAuditLog("HTTP Request Custom Headers Used", map[string]any{ + "Pinniped-Username": false, + "Pinniped-Password": false, + }), testutil.WantAuditLog("Using Upstream IDP", map[string]any{ "displayName": "some-other-new-idp-display-name", "resourceName": "some-other-new-idp-name", diff --git a/internal/federationdomain/endpoints/callback/callback_handler.go b/internal/federationdomain/endpoints/callback/callback_handler.go index 022d1569e..4cd330505 100644 --- a/internal/federationdomain/endpoints/callback/callback_handler.go +++ b/internal/federationdomain/endpoints/callback/callback_handler.go @@ -9,6 +9,7 @@ import ( "net/url" "github.com/ory/fosite" + "k8s.io/apimachinery/pkg/util/sets" "go.pinniped.dev/internal/auditevent" "go.pinniped.dev/internal/federationdomain/downstreamsession" @@ -21,6 +22,15 @@ import ( "go.pinniped.dev/internal/plog" ) +func paramsSafeToLog() sets.Set[string] { + return sets.New[string]( + // Due to https://datatracker.ietf.org/doc/html/rfc6749#section-4.1.2.1, + // authorize errors can have these parameters, which should not contain PII or secrets and are safe to log. + "error", "error_description", "error_uri", + // Note that this endpoint also receives 'code' and 'state' params, which are not safe to log. + ) +} + func NewHandler( upstreamIDPs federationdomainproviders.FederationDomainIdentityProvidersFinderI, oauthHelper fosite.OAuth2Provider, @@ -29,6 +39,11 @@ func NewHandler( auditLogger plog.AuditLogger, ) http.Handler { handler := httperr.HandlerFunc(func(w http.ResponseWriter, r *http.Request) error { + if err := auditLogger.AuditRequestParams(r, paramsSafeToLog()); err != nil { + plog.DebugErr("error parsing callback request params", err) + return httperr.New(http.StatusBadRequest, "error parsing request params") + } + encodedState, decodedState, err := validateRequest(r, stateDecoder, cookieDecoder) if err != nil { return err @@ -137,7 +152,8 @@ func validateRequest(r *http.Request, stateDecoder, cookieDecoder oidc.Decoder) if authcode(r) == "" { plog.Info("code param not found") - return "", nil, httperr.New(http.StatusBadRequest, "code param not found") + return "", nil, httperr.New(http.StatusBadRequest, + "code param not found: check URL in browser's address bar for error parameters from upstream identity provider") } return encodedState, decodedState, nil diff --git a/internal/federationdomain/endpoints/callback/callback_handler_test.go b/internal/federationdomain/endpoints/callback/callback_handler_test.go index 30c59c068..bb54d270d 100644 --- a/internal/federationdomain/endpoints/callback/callback_handler_test.go +++ b/internal/federationdomain/endpoints/callback/callback_handler_test.go @@ -282,6 +282,9 @@ func TestCallbackEndpoint(t *testing.T) { }, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"code": "redacted", "state": "redacted"}, + }), testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{ "authorizeID": encodedStateParam.AuthorizeID(), }), @@ -346,6 +349,9 @@ func TestCallbackEndpoint(t *testing.T) { }, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"code": "redacted", "state": "redacted"}, + }), testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{ "authorizeID": encodedStateParam.AuthorizeID(), }), @@ -727,6 +733,9 @@ func TestCallbackEndpoint(t *testing.T) { }, wantAuditLogs: func(encodedStateParam stateparam.Encoded, _ string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"code": "redacted", "state": "redacted"}, + }), testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{ "authorizeID": encodedStateParam.AuthorizeID(), }), @@ -1122,6 +1131,13 @@ func TestCallbackEndpoint(t *testing.T) { wantStatus: http.StatusMethodNotAllowed, wantContentType: htmlContentType, wantBody: "Method Not Allowed: PUT (try GET)\n", + wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { + return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"code": "redacted", "state": "redacted"}, + }), + } + }, }, { name: "POST method is invalid", @@ -1150,6 +1166,41 @@ func TestCallbackEndpoint(t *testing.T) { wantContentType: htmlContentType, wantBody: "Method Not Allowed: DELETE (try GET)\n", }, + { + name: "params cannot be parsed", + idps: testidplister.NewUpstreamIDPListerBuilder().WithOIDC(happyOIDCUpstream().Build()), + method: http.MethodGet, + path: newRequestPath().String() + "&invalid;;param", + csrfCookie: happyCSRFCookie, + wantStatus: http.StatusBadRequest, + wantContentType: htmlContentType, + wantBody: "Bad Request: error parsing request params\n", + wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { + return []testutil.WantedAuditLog{} + }, + }, + { + name: "error redirect from upstream IDP audit logs the error params from the OAuth2 spec", + idps: testidplister.NewUpstreamIDPListerBuilder().WithOIDC(happyOIDCUpstream().Build()), + method: http.MethodGet, + path: newRequestPath().WithState(happyOIDCState).WithoutCode().String() + "&error=some_error&error_description=some_description&error_uri=some_uri", + csrfCookie: happyCSRFCookie, + wantStatus: http.StatusBadRequest, + wantContentType: htmlContentType, + wantBody: "Bad Request: code param not found: check URL in browser's address bar for error parameters from upstream identity provider\n", + wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { + return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{ + "state": "redacted", + "error": "some_error", + "error_description": "some_description", + "error_uri": "some_uri", + }, + }), + } + }, + }, { name: "code param was not included on request", idps: testidplister.NewUpstreamIDPListerBuilder().WithOIDC(happyOIDCUpstream().Build()), @@ -1158,7 +1209,14 @@ func TestCallbackEndpoint(t *testing.T) { csrfCookie: happyCSRFCookie, wantStatus: http.StatusBadRequest, wantContentType: htmlContentType, - wantBody: "Bad Request: code param not found\n", + wantBody: "Bad Request: code param not found: check URL in browser's address bar for error parameters from upstream identity provider\n", + wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { + return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"state": "redacted"}, + }), + } + }, }, { name: "state param was not included on request", @@ -1170,7 +1228,11 @@ func TestCallbackEndpoint(t *testing.T) { wantContentType: htmlContentType, wantBody: "Bad Request: state param not found\n", wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { - return []testutil.WantedAuditLog{} + return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"code": "redacted"}, + }), + } }, }, { @@ -1806,6 +1868,9 @@ func TestCallbackEndpoint(t *testing.T) { }, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"code": "redacted", "state": "redacted"}, + }), testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{ "authorizeID": encodedStateParam.AuthorizeID(), }), @@ -1847,6 +1912,9 @@ func TestCallbackEndpoint(t *testing.T) { }, wantAuditLogs: func(encodedStateParam stateparam.Encoded, sessionID string) []testutil.WantedAuditLog { return []testutil.WantedAuditLog{ + testutil.WantAuditLog("HTTP Request Parameters", map[string]any{ + "params": map[string]any{"code": "redacted", "state": "redacted"}, + }), testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{ "authorizeID": encodedStateParam.AuthorizeID(), }), diff --git a/internal/plog/plog.go b/internal/plog/plog.go index 1bdbfb763..c97e450fa 100644 --- a/internal/plog/plog.go +++ b/internal/plog/plog.go @@ -30,12 +30,16 @@ package plog import ( "context" "encoding/json" + "errors" "fmt" + "net/http" "os" "reflect" "slices" "github.com/go-logr/logr" + "github.com/ory/fosite" + "k8s.io/apimachinery/pkg/util/sets" "k8s.io/apiserver/pkg/audit" "go.pinniped.dev/internal/auditevent" @@ -72,6 +76,7 @@ type AuditParams struct { // that would make unit testing of audit logs harder. type AuditLogger interface { Audit(msg auditevent.Message, p *AuditParams) + AuditRequestParams(r *http.Request, reqParamsSafeToLog sets.Set[string]) error } // Logger implements the plog logging convention described above. The global functions in this package @@ -178,6 +183,34 @@ func (a *auditLogger) Audit(msg auditevent.Message, p *AuditParams) { a.logger.audit(string(msg), allKV...) } +// AuditRequestParams parses the URL's query params and/or POST body form params, and then audit logs them with +// redaction as specified by reqParamsSafeToLog. It can return an error, or in the case of success it has the side +// effect of leaving the parsed form params on the http.Request in the Form field. Note that request body parameters +// take precedence over URL query values. +func (a *auditLogger) AuditRequestParams(r *http.Request, reqParamsSafeToLog sets.Set[string]) error { + // The style of form parsing and the text of the error is inspired by fosite's implementation of NewAuthorizeRequest(). + // Fosite only calls ParseMultipartForm() there. However, although ParseMultipartForm() calls ParseForm(), + // it swallows errors from ParseForm() sometimes. To avoid having any errors swallowed, we call both. + // When fosite calls ParseMultipartForm() later, it will be a noop. + if err := r.ParseForm(); err != nil { + return fosite.ErrInvalidRequest. + WithHint("Unable to parse form params, make sure to send a properly formatted query params or form request body."). + WithWrap(err).WithDebug(err.Error()) + } + if err := r.ParseMultipartForm(1 << 20); err != nil && !errors.Is(err, http.ErrNotMultipart) { + return fosite.ErrInvalidRequest. + WithHint("Unable to parse multipart HTTP body, make sure to send a properly formatted form request body."). + WithWrap(err).WithDebug(err.Error()) + } + + a.Audit(auditevent.HTTPRequestParameters, &AuditParams{ + ReqCtx: r.Context(), + KeysAndValues: auditevent.SanitizeParams(r.Form, reqParamsSafeToLog), + }) + + return nil +} + // audit is used internally by AuditLogger to print an audit log event to the pLogger's output. func (p pLogger) audit(msg string, keysAndValues ...any) { // Always print log message (klogLevelWarning cannot be suppressed by configuration),