tokencredentialrequest audit logs failed requests

internal/auditevent/audit_event.go

@@ -12,21 +12,24 @@ import (
 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"
+	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"
+	UpstreamAuthorizeRedirect                  Message = "Upstream Authorize Redirect"
+	TokenCredentialRequestAuthenticatedUser    Message = "TokenCredentialRequest Authenticated User"    //nolint:gosec // this is not a credential
+	TokenCredentialRequestAuthenticationFailed Message = "TokenCredentialRequest Authentication Failed" //nolint:gosec // this is not a credential
+	TokenCredentialRequestUnexpectedError      Message = "TokenCredentialRequest Unexpected Error"      //nolint:gosec // this is not a credential
+	TokenCredentialRequestUnsupportedUserInfo  Message = "TokenCredentialRequest Unsupported UserInfo"  //nolint:gosec // this is not a credential
 )
 
 // SanitizeParams can be used to redact all params not included in the allowedKeys set.

internal/registry/credentialrequest/rest.go

@@ -6,6 +6,7 @@ package credentialrequest
 
 import (
 	"context"
+	"errors"
 	"fmt"
 	"time"
 
@@ -19,7 +20,6 @@ import (
 	genericapirequest "k8s.io/apiserver/pkg/endpoints/request"
 	"k8s.io/apiserver/pkg/registry/rest"
 	"k8s.io/utils/clock"
-	"k8s.io/utils/trace"
 
 	loginapi "go.pinniped.dev/generated/latest/apis/concierge/login"
 	"go.pinniped.dev/internal/auditevent"
@@ -105,46 +105,78 @@ func (*REST) GetSingularName() string {
 }
 
 func (r *REST) Create(ctx context.Context, obj runtime.Object, createValidation rest.ValidateObjectFunc, options *metav1.CreateOptions) (runtime.Object, error) {
-	t := trace.FromContext(ctx).Nest("create", trace.Field{
-		Key:   "kind",
-		Value: "TokenCredentialRequest",
-	})
-	defer t.Log()
-
-	credentialRequest, err := validateRequest(ctx, obj, createValidation, options, t)
+	credentialRequest, err := validateRequest(ctx, obj, createValidation, options)
 	if err != nil {
+		// Bad requests are not audit logged because the Kubernetes audit log will show the response's status error code.
+		plog.DebugErr("TokenCredentialRequest request object validation error", err)
 		return nil, err
 	}
 
 	userInfo, err := r.authenticator.AuthenticateTokenCredentialRequest(ctx, credentialRequest)
 	if err != nil {
-		traceFailureWithError(t, "token authentication", err)
-		return failureResponse(), nil
+		r.auditLogger.Audit(auditevent.TokenCredentialRequestUnexpectedError, &plog.AuditParams{
+			ReqCtx: ctx,
+			KeysAndValues: []any{
+				"reason", "authenticator returned an error",
+				"err", err.Error(),
+				"authenticator", credentialRequest.Spec.Authenticator,
+			},
+		})
+		return authenticationFailedResponse(), nil
 	}
-	if ok := isUserInfoValid(userInfo); !ok {
-		traceSuccess(t, userInfo, false)
-		return failureResponse(), nil
+
+	if userInfo == nil {
+		r.auditLogger.Audit(auditevent.TokenCredentialRequestAuthenticationFailed, &plog.AuditParams{
+			ReqCtx: ctx,
+			KeysAndValues: []any{
+				"reason", "auth rejected by authenticator",
+				"authenticator", credentialRequest.Spec.Authenticator,
+			},
+		})
+		return authenticationFailedResponse(), nil
+	}
+
+	if err = validateUserInfo(userInfo); err != nil {
+		r.auditLogger.Audit(auditevent.TokenCredentialRequestUnsupportedUserInfo, &plog.AuditParams{
+			ReqCtx: ctx,
+			PIIKeysAndValues: []any{
+				"userInfoName", userInfo.GetName(),
+				"userInfoUID", userInfo.GetUID(),
+			},
+			KeysAndValues: []any{
+				"userInfoExtrasCount", len(userInfo.GetExtra()),
+				"reason", "unsupported value in userInfo returned by authenticator",
+				"err", err.Error(),
+				"authenticator", credentialRequest.Spec.Authenticator,
+			},
+		})
+		return authenticationFailedResponse(), nil
 	}
 
 	// this timestamp should be returned from IssueClientCertPEM but this is a safe approximation
 	expires := metav1.NewTime(r.clock.Now().UTC().Add(clientCertificateTTL))
 	certPEM, keyPEM, err := r.issuer.IssueClientCertPEM(userInfo.GetName(), userInfo.GetGroups(), clientCertificateTTL)
 	if err != nil {
-		traceFailureWithError(t, "cert issuer", err)
-		return failureResponse(), nil
+		r.auditLogger.Audit(auditevent.TokenCredentialRequestUnexpectedError, &plog.AuditParams{
+			ReqCtx: ctx,
+			KeysAndValues: []any{
+				"reason", "cert issuer returned an error",
+				"err", err.Error(),
+				"authenticator", credentialRequest.Spec.Authenticator,
+			},
+		})
+		return authenticationFailedResponse(), nil
 	}
 
-	traceSuccess(t, userInfo, true)
-
-	r.auditLogger.Audit(auditevent.TokenCredentialRequest, &plog.AuditParams{
+	r.auditLogger.Audit(auditevent.TokenCredentialRequestAuthenticatedUser, &plog.AuditParams{
 		ReqCtx: ctx,
 		PIIKeysAndValues: []any{
 			"username", userInfo.GetName(),
 			"groups", userInfo.GetGroups(),
 		},
 		KeysAndValues: []any{
-			"authenticated", true,
-			"expires", expires.Format(time.RFC3339),
+			"issuedClientCertExpires", expires.Format(time.RFC3339),
+			"authenticator", credentialRequest.Spec.Authenticator,
 		},
 	})
 
@@ -159,15 +191,13 @@ func (r *REST) Create(ctx context.Context, obj runtime.Object, createValidation
 	}, nil
 }
 
-func validateRequest(ctx context.Context, obj runtime.Object, createValidation rest.ValidateObjectFunc, options *metav1.CreateOptions, t *trace.Trace) (*loginapi.TokenCredentialRequest, error) {
+func validateRequest(ctx context.Context, obj runtime.Object, createValidation rest.ValidateObjectFunc, options *metav1.CreateOptions) (*loginapi.TokenCredentialRequest, error) {
 	credentialRequest, ok := obj.(*loginapi.TokenCredentialRequest)
 	if !ok {
-		traceValidationFailure(t, "not a TokenCredentialRequest")
 		return nil, apierrors.NewBadRequest(fmt.Sprintf("not a TokenCredentialRequest: %#v", obj))
 	}
 
 	if len(credentialRequest.Spec.Token) == 0 {
-		traceValidationFailure(t, "token must be supplied")
 		errs := field.ErrorList{field.Required(field.NewPath("spec", "token", "value"), "token must be supplied")}
 		return nil, apierrors.NewInvalid(loginapi.Kind(credentialRequest.Kind), credentialRequest.Name, errs)
 	}
@@ -175,14 +205,12 @@ func validateRequest(ctx context.Context, obj runtime.Object, createValidation r
 	// just a sanity check, not sure how to honor a dry run on a virtual API
 	if options != nil {
 		if len(options.DryRun) != 0 {
-			traceValidationFailure(t, "dryRun not supported")
 			errs := field.ErrorList{field.NotSupported(field.NewPath("dryRun"), options.DryRun, []string(nil))}
 			return nil, apierrors.NewInvalid(loginapi.Kind(credentialRequest.Kind), credentialRequest.Name, errs)
 		}
 	}
 
 	if namespace := genericapirequest.NamespaceValue(ctx); len(namespace) != 0 {
-		traceValidationFailure(t, "namespace is not allowed")
 		return nil, apierrors.NewBadRequest(fmt.Sprintf("namespace is not allowed on TokenCredentialRequest: %v", namespace))
 	}
 
@@ -195,7 +223,6 @@ func validateRequest(ctx context.Context, obj runtime.Object, createValidation r
 		requestForValidation := obj.DeepCopyObject()
 		requestForValidation.(*loginapi.TokenCredentialRequest).Spec.Token = ""
 		if err := createValidation(ctx, requestForValidation); err != nil {
-			traceFailureWithError(t, "validation webhook", err)
 			return nil, err
 		}
 	}
@@ -203,48 +230,20 @@ func validateRequest(ctx context.Context, obj runtime.Object, createValidation r
 	return credentialRequest, nil
 }
 
-func isUserInfoValid(userInfo user.Info) bool {
+func validateUserInfo(userInfo user.Info) error {
 	switch {
-	case userInfo == nil, // must be non-nil
-		len(userInfo.GetName()) == 0,  // must have a username, groups are optional
-		len(userInfo.GetUID()) != 0,   // certs cannot assert UID
-		len(userInfo.GetExtra()) != 0: // certs cannot assert extra
-		return false
-
+	case len(userInfo.GetName()) == 0:
+		return errors.New("empty username is not allowed")
+	case len(userInfo.GetUID()) != 0:
+		return errors.New("UIDs are not supported") // certs cannot assert UID
+	case len(userInfo.GetExtra()) != 0:
+		return errors.New("extras are not supported") // certs cannot assert extra
 	default:
-		return true
+		return nil
 	}
 }
 
-func traceSuccess(t *trace.Trace, userInfo user.Info, authenticated bool) {
-	userID := "<none>"
-	hasExtra := false
-	if userInfo != nil {
-		userID = userInfo.GetUID()
-		hasExtra = len(userInfo.GetExtra()) > 0
-	}
-	t.Step("success",
-		trace.Field{Key: "userID", Value: userID},
-		trace.Field{Key: "hasExtra", Value: hasExtra},
-		trace.Field{Key: "authenticated", Value: authenticated},
-	)
-}
-
-func traceValidationFailure(t *trace.Trace, msg string) {
-	t.Step("failure",
-		trace.Field{Key: "failureType", Value: "request validation"},
-		trace.Field{Key: "msg", Value: msg},
-	)
-}
-
-func traceFailureWithError(t *trace.Trace, failureType string, err error) {
-	t.Step("failure",
-		trace.Field{Key: "failureType", Value: failureType},
-		trace.Field{Key: "msg", Value: err.Error()},
-	)
-}
-
-func failureResponse() *loginapi.TokenCredentialRequest {
+func authenticationFailedResponse() *loginapi.TokenCredentialRequest {
 	m := "authentication failed"
 	return &loginapi.TokenCredentialRequest{
 		Status: loginapi.TokenCredentialRequestStatus{

internal/registry/credentialrequest/rest_test.go

@@ -11,10 +11,10 @@ import (
 	"testing"
 	"time"
 
-	"github.com/go-logr/logr"
 	"github.com/sclevine/spec"
 	"github.com/stretchr/testify/require"
 	"go.uber.org/mock/gomock"
+	corev1 "k8s.io/api/core/v1"
 	apierrors "k8s.io/apimachinery/pkg/api/errors"
 	metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
 	"k8s.io/apimachinery/pkg/runtime"
@@ -23,7 +23,6 @@ import (
 	"k8s.io/apiserver/pkg/authentication/user"
 	genericapirequest "k8s.io/apiserver/pkg/endpoints/request"
 	"k8s.io/apiserver/pkg/registry/rest"
-	"k8s.io/klog/v2"
 	"k8s.io/utils/clock"
 	clocktesting "k8s.io/utils/clock/testing"
 	"k8s.io/utils/ptr"
@@ -72,8 +71,6 @@ func TestCreate(t *testing.T) {
 	spec.Run(t, "create", func(t *testing.T, when spec.G, it spec.S) {
 		var r *require.Assertions
 		var ctrl *gomock.Controller
-		var logger *testutil.TranscriptLogger
-		var originalKLogLevel klog.Level
 		var auditLogger plog.AuditLogger
 		var actualAuditLog *bytes.Buffer
 		var frozenNow time.Time
@@ -83,11 +80,6 @@ func TestCreate(t *testing.T) {
 		it.Before(func() {
 			r = require.New(t)
 			ctrl = gomock.NewController(t)
-			logger = testutil.NewTranscriptLogger(t) //nolint:staticcheck  // old test with lots of log statements
-			klog.SetLogger(logr.New(logger))         // this is unfortunately a global logger, so can't run these tests in parallel :(
-			originalKLogLevel = testutil.GetGlobalKlogLevel()
-			// trace.Log() utility will only log at level 2 or above, so set that for this test.
-			testutil.SetGlobalKlogLevel(t, 2) //nolint:staticcheck // old test of code using trace.Log()
 			auditLogger, actualAuditLog = plog.TestAuditLogger(t)
 			frozenNow = time.Date(2024, time.September, 12, 4, 25, 56, 778899, time.UTC)
 			frozenClock = clocktesting.NewFakeClock(frozenNow)
@@ -95,8 +87,6 @@ func TestCreate(t *testing.T) {
 
 		it.After(func() {
 			testutil.CompareAuditLogs(t, wantAuditLog, actualAuditLog.String())
-			klog.ClearLogger()
-			testutil.SetGlobalKlogLevel(t, originalKLogLevel) //nolint:staticcheck // old test of code using trace.Log()
 			ctrl.Finish()
 		})
 
@@ -134,13 +124,15 @@ func TestCreate(t *testing.T) {
 				},
 			})
 
-			requireOneLogStatement(r, logger, `"success" userID:,hasExtra:false,authenticated:true`)
-
 			wantAuditLog = []testutil.WantedAuditLog{
-				testutil.WantAuditLog("TokenCredentialRequest", map[string]any{
-					"auditID":       "fake-audit-id",
-					"authenticated": true,
-					"expires":       "2024-09-12T04:30:56Z", // this is frozenNow + 5 minutes in UTC
+				testutil.WantAuditLog("TokenCredentialRequest Authenticated User", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"issuedClientCertExpires": "2024-09-12T04:30:56Z", // this is frozenNow + 5 minutes in UTC
 					"personalInfo": map[string]any{
 						"username": "test-user",
 						"groups":   []any{"test-group-1", "test-group-2"},
@@ -168,7 +160,19 @@ func TestCreate(t *testing.T) {
 
 			response, err := callCreate(storage, req)
 			requireSuccessfulResponseWithAuthenticationFailureMessage(t, err, response)
-			requireOneLogStatement(r, logger, `"failure" failureType:cert issuer,msg:some certificate authority error`)
+
+			wantAuditLog = []testutil.WantedAuditLog{
+				testutil.WantAuditLog("TokenCredentialRequest Unexpected Error", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"reason": "cert issuer returned an error",
+					"err":    "some certificate authority error",
+				}),
+			}
 		})
 
 		it("CreateSucceedsWithAnUnauthenticatedStatusWhenGivenATokenAndTheWebhookReturnsNilUser", func() {
@@ -182,7 +186,18 @@ func TestCreate(t *testing.T) {
 			response, err := callCreate(storage, req)
 
 			requireSuccessfulResponseWithAuthenticationFailureMessage(t, err, response)
-			requireOneLogStatement(r, logger, `"success" userID:<none>,hasExtra:false,authenticated:false`)
+
+			wantAuditLog = []testutil.WantedAuditLog{
+				testutil.WantAuditLog("TokenCredentialRequest Authentication Failed", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"reason": "auth rejected by authenticator",
+				}),
+			}
 		})
 
 		it("CreateSucceedsWithAnUnauthenticatedStatusWhenWebhookFails", func() {
@@ -197,7 +212,19 @@ func TestCreate(t *testing.T) {
 			response, err := callCreate(storage, req)
 
 			requireSuccessfulResponseWithAuthenticationFailureMessage(t, err, response)
-			requireOneLogStatement(r, logger, `"failure" failureType:token authentication,msg:some webhook error`)
+
+			wantAuditLog = []testutil.WantedAuditLog{
+				testutil.WantAuditLog("TokenCredentialRequest Unexpected Error", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"reason": "authenticator returned an error",
+					"err":    "some webhook error",
+				}),
+			}
 		})
 
 		it("CreateSucceedsWithAnUnauthenticatedStatusWhenWebhookReturnsAnEmptyUsername", func() {
@@ -205,14 +232,31 @@ func TestCreate(t *testing.T) {
 
 			requestAuthenticator := mockcredentialrequest.NewMockTokenCredentialRequestAuthenticator(ctrl)
 			requestAuthenticator.EXPECT().AuthenticateTokenCredentialRequest(gomock.Any(), req).
-				Return(&user.DefaultInfo{Name: ""}, nil)
+				Return(&user.DefaultInfo{Name: "", UID: "test-uid"}, nil)
 
 			storage := NewREST(requestAuthenticator, nil, schema.GroupResource{}, auditLogger, frozenClock)
 
 			response, err := callCreate(storage, req)
 
 			requireSuccessfulResponseWithAuthenticationFailureMessage(t, err, response)
-			requireOneLogStatement(r, logger, `"success" userID:,hasExtra:false,authenticated:false`)
+
+			wantAuditLog = []testutil.WantedAuditLog{
+				testutil.WantAuditLog("TokenCredentialRequest Unsupported UserInfo", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"reason":              "unsupported value in userInfo returned by authenticator",
+					"err":                 "empty username is not allowed",
+					"userInfoExtrasCount": float64(0),
+					"personalInfo": map[string]any{
+						"userInfoName": "",
+						"userInfoUID":  "test-uid",
+					},
+				}),
+			}
 		})
 
 		it("CreateSucceedsWithAnUnauthenticatedStatusWhenWebhookReturnsAUserWithUID", func() {
@@ -231,7 +275,24 @@ func TestCreate(t *testing.T) {
 			response, err := callCreate(storage, req)
 
 			requireSuccessfulResponseWithAuthenticationFailureMessage(t, err, response)
-			requireOneLogStatement(r, logger, `"success" userID:test-uid,hasExtra:false,authenticated:false`)
+
+			wantAuditLog = []testutil.WantedAuditLog{
+				testutil.WantAuditLog("TokenCredentialRequest Unsupported UserInfo", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"reason":              "unsupported value in userInfo returned by authenticator",
+					"err":                 "UIDs are not supported",
+					"userInfoExtrasCount": float64(0),
+					"personalInfo": map[string]any{
+						"userInfoName": "test-user",
+						"userInfoUID":  "test-uid",
+					},
+				}),
+			}
 		})
 
 		it("CreateSucceedsWithAnUnauthenticatedStatusWhenWebhookReturnsAUserWithExtra", func() {
@@ -250,7 +311,24 @@ func TestCreate(t *testing.T) {
 			response, err := callCreate(storage, req)
 
 			requireSuccessfulResponseWithAuthenticationFailureMessage(t, err, response)
-			requireOneLogStatement(r, logger, `"success" userID:,hasExtra:true,authenticated:false`)
+
+			wantAuditLog = []testutil.WantedAuditLog{
+				testutil.WantAuditLog("TokenCredentialRequest Unsupported UserInfo", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"reason":              "unsupported value in userInfo returned by authenticator",
+					"err":                 "extras are not supported",
+					"userInfoExtrasCount": float64(1),
+					"personalInfo": map[string]any{
+						"userInfoName": "test-user",
+						"userInfoUID":  "",
+					},
+				}),
+			}
 		})
 
 		it("CreateFailsWhenGivenTheWrongInputType", func() {
@@ -262,7 +340,6 @@ func TestCreate(t *testing.T) {
 				&metav1.CreateOptions{})
 
 			requireAPIError(t, response, err, apierrors.IsBadRequest, "not a TokenCredentialRequest")
-			requireOneLogStatement(r, logger, `"failure" failureType:request validation,msg:not a TokenCredentialRequest`)
 		})
 
 		it("CreateFailsWhenTokenValueIsEmptyInRequest", func() {
@@ -273,7 +350,6 @@ func TestCreate(t *testing.T) {
 
 			requireAPIError(t, response, err, apierrors.IsInvalid,
 				`.pinniped.dev "request name" is invalid: spec.token.value: Required value: token must be supplied`)
-			requireOneLogStatement(r, logger, `"failure" failureType:request validation,msg:token must be supplied`)
 		})
 
 		it("CreateFailsWhenValidationFails", func() {
@@ -287,7 +363,6 @@ func TestCreate(t *testing.T) {
 				&metav1.CreateOptions{})
 			r.Nil(response)
 			r.EqualError(err, "some validation error")
-			requireOneLogStatement(r, logger, `"failure" failureType:validation webhook,msg:some validation error`)
 		})
 
 		it("CreateDoesNotAllowValidationFunctionToMutateRequest", func() {
@@ -314,10 +389,14 @@ func TestCreate(t *testing.T) {
 			r.NotEmpty(response)
 
 			wantAuditLog = []testutil.WantedAuditLog{
-				testutil.WantAuditLog("TokenCredentialRequest", map[string]any{
-					"auditID":       "fake-audit-id",
-					"authenticated": true,
-					"expires":       "2024-09-12T04:30:56Z", // this is frozenNow + 5 minutes in UTC
+				testutil.WantAuditLog("TokenCredentialRequest Authenticated User", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"issuedClientCertExpires": "2024-09-12T04:30:56Z", // this is frozenNow + 5 minutes in UTC
 					"personalInfo": map[string]any{
 						"username": "test-user",
 						"groups":   []any{},
@@ -357,10 +436,14 @@ func TestCreate(t *testing.T) {
 			r.Empty(validationFunctionSawTokenValue)
 
 			wantAuditLog = []testutil.WantedAuditLog{
-				testutil.WantAuditLog("TokenCredentialRequest", map[string]any{
-					"auditID":       "fake-audit-id",
-					"authenticated": true,
-					"expires":       "2024-09-12T04:30:56Z", // this is frozenNow + 5 minutes in UTC
+				testutil.WantAuditLog("TokenCredentialRequest Authenticated User", map[string]any{
+					"auditID": "fake-audit-id",
+					"authenticator": map[string]any{
+						"apiGroup": "fake-api-group.com",
+						"kind":     "FakeAuthenticatorKind",
+						"name":     "fake-authenticator-name",
+					},
+					"issuedClientCertExpires": "2024-09-12T04:30:56Z", // this is frozenNow + 5 minutes in UTC
 					"personalInfo": map[string]any{
 						"username": "test-user",
 						"groups":   []any{},
@@ -380,7 +463,6 @@ func TestCreate(t *testing.T) {
 
 			requireAPIError(t, response, err, apierrors.IsInvalid,
 				`.pinniped.dev "request name" is invalid: dryRun: Unsupported value: []string{"some dry run flag"}`)
-			requireOneLogStatement(r, logger, `"failure" failureType:request validation,msg:dryRun not supported`)
 		})
 
 		it("CreateFailsWhenNamespaceIsNotEmpty", func() {
@@ -391,18 +473,10 @@ func TestCreate(t *testing.T) {
 				&metav1.CreateOptions{})
 
 			requireAPIError(t, response, err, apierrors.IsBadRequest, `namespace is not allowed on TokenCredentialRequest: some-ns`)
-			requireOneLogStatement(r, logger, `"failure" failureType:request validation,msg:namespace is not allowed`)
 		})
 	}, spec.Sequential())
 }
 
-func requireOneLogStatement(r *require.Assertions, logger *testutil.TranscriptLogger, messageContains string) {
-	transcript := logger.Transcript()
-	r.Len(transcript, 1)
-	r.Equal("info", transcript[0].Level)
-	r.Contains(transcript[0].Message, messageContains)
-}
-
 func callCreate(storage *REST, obj runtime.Object) (runtime.Object, error) {
 	fakeReqContext := audit.WithAuditContext(context.Background())
 	audit.WithAuditID(fakeReqContext, "fake-audit-id")
@@ -421,7 +495,14 @@ func validCredentialRequest() *loginapi.TokenCredentialRequest {
 }
 
 func validCredentialRequestWithToken(token string) *loginapi.TokenCredentialRequest {
-	return credentialRequest(loginapi.TokenCredentialRequestSpec{Token: token})
+	return credentialRequest(loginapi.TokenCredentialRequestSpec{
+		Token: token,
+		Authenticator: corev1.TypedLocalObjectReference{
+			APIGroup: ptr.To("fake-api-group.com"),
+			Kind:     "FakeAuthenticatorKind",
+			Name:     "fake-authenticator-name",
+		},
+	})
 }
 
 func credentialRequest(spec loginapi.TokenCredentialRequestSpec) *loginapi.TokenCredentialRequest {