Callback endpoint emits audit log with authorizeID even when code param not found

Co-authored-by: Ryan Richard <richardry@vmware.com>

hack/lib/kind-config/single-node.yaml

@@ -1,31 +1,31 @@
 #@ load("@ytt:data", "data")
-
+---
 kind: Cluster
 apiVersion: kind.x-k8s.io/v1alpha4
 nodes:
-  - role: control-plane
-    extraPortMappings:
-    - protocol: TCP
-      #! This same port number is hardcoded in the integration test setup
-      #! when creating a Service on a kind cluster. It is used to talk to
-      #! the supervisor app via HTTPS.
-      containerPort: 31243
-      hostPort: 12344
-      listenAddress: 127.0.0.1
-    - protocol: TCP
-      #! This same port number is hardcoded in the integration test setup
-      #! when creating a Service on a kind cluster. It is used to talk to
-      #! the Dex app.
-      containerPort: 31235
-      hostPort: 12346
-      listenAddress: 127.0.0.1
-    #@ if data.values.enable_audit_logs:
-    #! mount the local file on the control plane
-    extraMounts:
-      - hostPath: /tmp/metadata-audit-policy.yaml
-        containerPath: /etc/kubernetes/policies/audit-policy.yaml
-        readOnly: true
-    #@ end
+- role: control-plane
+  extraPortMappings:
+  - protocol: TCP
+    #! This same port number is hardcoded in the integration test setup
+    #! when creating a Service on a kind cluster. It is used to talk to
+    #! the supervisor app via HTTPS.
+    containerPort: 31243
+    hostPort: 12344
+    listenAddress: 127.0.0.1
+  - protocol: TCP
+    #! This same port number is hardcoded in the integration test setup
+    #! when creating a Service on a kind cluster. It is used to talk to
+    #! the Dex app.
+    containerPort: 31235
+    hostPort: 12346
+    listenAddress: 127.0.0.1
+  #@ if data.values.enable_audit_logs:
+  #! mount the local file on the control plane
+  extraMounts:
+  - hostPath: /tmp/metadata-audit-policy.yaml
+    containerPath: /etc/kubernetes/policies/audit-policy.yaml
+    readOnly: true
+  #@ end
 #! Apply these patches to all nodes.
 kubeadmConfigPatches:
 - |
@@ -45,20 +45,20 @@ kubeadmConfigPatches:
 - |
   kind: ClusterConfiguration
   apiServer:
-      #! enable auditing flags on the API server
-      extraArgs:
-        audit-log-path: /var/log/kubernetes/kube-apiserver-audit.log
-        audit-policy-file: /etc/kubernetes/policies/audit-policy.yaml
-      #! mount new files / directories on the control plane
-      extraVolumes:
-        - name: audit-policies
-          hostPath: /etc/kubernetes/policies
-          mountPath: /etc/kubernetes/policies
-          readOnly: true
-          pathType: "DirectoryOrCreate"
-        - name: "audit-logs"
-          hostPath: "/var/log/kubernetes"
-          mountPath: "/var/log/kubernetes"
-          readOnly: false
-          pathType: DirectoryOrCreate
+    #! enable auditing flags on the API server
+    extraArgs:
+      audit-log-path: /var/log/kubernetes/kube-apiserver-audit.log
+      audit-policy-file: /etc/kubernetes/policies/audit-policy.yaml
+    #! mount new files / directories on the control plane
+    extraVolumes:
+    - name: audit-policies
+      hostPath: /etc/kubernetes/policies
+      mountPath: /etc/kubernetes/policies
+      readOnly: true
+      pathType: "DirectoryOrCreate"
+    - name: "audit-logs"
+      hostPath: "/var/log/kubernetes"
+      mountPath: "/var/log/kubernetes"
+      readOnly: false
+      pathType: DirectoryOrCreate
 #@ end

internal/federationdomain/endpoints/callback/callback_handler.go

@@ -18,7 +18,6 @@ import (
 	"go.pinniped.dev/internal/federationdomain/federationdomainproviders"
 	"go.pinniped.dev/internal/federationdomain/formposthtml"
 	"go.pinniped.dev/internal/federationdomain/oidc"
-	"go.pinniped.dev/internal/federationdomain/stateparam"
 	"go.pinniped.dev/internal/httputil/httperr"
 	"go.pinniped.dev/internal/httputil/securityheader"
 	"go.pinniped.dev/internal/plog"
@@ -46,16 +45,11 @@ func NewHandler(
 			return httperr.New(http.StatusBadRequest, "error parsing request params")
 		}
 
-		encodedState, decodedState, err := validateRequest(r, stateDecoder, cookieDecoder)
+		decodedState, err := validateRequest(r, stateDecoder, cookieDecoder, auditLogger)
 		if err != nil {
 			return err
 		}
 
-		auditLogger.Audit(auditevent.AuthorizeIDFromParameters, &plog.AuditParams{
-			ReqCtx:        r.Context(),
-			KeysAndValues: []any{"authorizeID", encodedState.AuthorizeID()},
-		})
-
 		idp, err := upstreamIDPs.FindUpstreamIDPByDisplayName(decodedState.UpstreamName)
 		if err != nil || idp == nil {
 			plog.Warning("upstream provider not found")
@@ -141,23 +135,28 @@ func authcode(r *http.Request) string {
 	return r.FormValue("code")
 }
 
-func validateRequest(r *http.Request, stateDecoder, cookieDecoder oidc.Decoder) (stateparam.Encoded, *oidc.UpstreamStateParamData, error) {
+func validateRequest(r *http.Request, stateDecoder, cookieDecoder oidc.Decoder, auditLogger plog.AuditLogger) (*oidc.UpstreamStateParamData, error) {
 	if r.Method != http.MethodGet {
-		return "", nil, httperr.Newf(http.StatusMethodNotAllowed, "%s (try GET)", r.Method)
+		return nil, httperr.Newf(http.StatusMethodNotAllowed, "%s (try GET)", r.Method)
 	}
 
 	encodedState, decodedState, err := oidc.ReadStateParamAndValidateCSRFCookie(r, cookieDecoder, stateDecoder)
 	if err != nil {
 		plog.InfoErr("state or CSRF error", err)
-		return "", nil, err
+		return nil, err
 	}
 
+	auditLogger.Audit(auditevent.AuthorizeIDFromParameters, &plog.AuditParams{
+		ReqCtx:        r.Context(),
+		KeysAndValues: []any{"authorizeID", encodedState.AuthorizeID()},
+	})
+
 	if authcode(r) == "" {
 		plog.Info("code param not found")
-		return "", nil, httperr.New(http.StatusBadRequest, errorMsgForNoCodeParam(r))
+		return nil, httperr.New(http.StatusBadRequest, errorMsgForNoCodeParam(r))
 	}
 
-	return encodedState, decodedState, nil
+	return decodedState, nil
 }
 
 func errorMsgForNoCodeParam(r *http.Request) string {

internal/federationdomain/endpoints/callback/callback_handler_test.go

@@ -1206,6 +1206,9 @@ func TestCallbackEndpoint(t *testing.T) {
 							"error_uri":         "some uri",
 						},
 					}),
+					testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{
+						"authorizeID": encodedStateParam.AuthorizeID(),
+					}),
 				}
 			},
 		},
@@ -1233,6 +1236,9 @@ func TestCallbackEndpoint(t *testing.T) {
 							"error_description": "some description",
 						},
 					}),
+					testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{
+						"authorizeID": encodedStateParam.AuthorizeID(),
+					}),
 				}
 			},
 		},
@@ -1255,6 +1261,9 @@ func TestCallbackEndpoint(t *testing.T) {
 					testutil.WantAuditLog("HTTP Request Parameters", map[string]any{
 						"params": map[string]any{"state": "redacted"},
 					}),
+					testutil.WantAuditLog("AuthorizeID From Parameters", map[string]any{
+						"authorizeID": encodedStateParam.AuthorizeID(),
+					}),
 				}
 			},
 		},