Merge pull request #1864 from vmware-tanzu/cli_use_cached_access_token

login oidc cmd checks access token expiry before doing token exchange

cmd/pinniped/cmd/login_oidc.go

@@ -1,4 +1,4 @@
-// Copyright 2020-2023 the Pinniped contributors. All Rights Reserved.
+// Copyright 2020-2024 the Pinniped contributors. All Rights Reserved.
 // SPDX-License-Identifier: Apache-2.0
 
 package cmd
@@ -241,12 +241,12 @@ func runOIDCLogin(cmd *cobra.Command, deps oidcLoginCommandDeps, flags oidcLogin
 	}
 
 	pLogger.Debug("Performing OIDC login", "issuer", flags.issuer, "client id", flags.clientID)
-	// Do the basic login to get an OIDC token.
+	// Do the basic login to get an OIDC token. Although this can return several tokens, we only need the ID token here.
 	token, err := deps.login(flags.issuer, flags.clientID, opts...)
 	if err != nil {
 		return fmt.Errorf("could not complete Pinniped login: %w", err)
 	}
-	cred := tokenCredential(token)
+	cred := tokenCredential(token.IDToken)
 
 	// If the concierge was configured, exchange the credential for a separate short-lived, cluster-specific credential.
 	if concierge != nil {
@@ -344,18 +344,18 @@ func makeClient(caBundlePaths []string, caBundleData []string) (*http.Client, er
 	return phttp.Default(pool), nil
 }
 
-func tokenCredential(token *oidctypes.Token) *clientauthv1beta1.ExecCredential {
+func tokenCredential(idToken *oidctypes.IDToken) *clientauthv1beta1.ExecCredential {
 	cred := clientauthv1beta1.ExecCredential{
 		TypeMeta: metav1.TypeMeta{
 			Kind:       "ExecCredential",
 			APIVersion: "client.authentication.k8s.io/v1beta1",
 		},
 		Status: &clientauthv1beta1.ExecCredentialStatus{
-			Token: token.IDToken.Token,
+			Token: idToken.Token,
 		},
 	}
-	if !token.IDToken.Expiry.IsZero() {
-		cred.Status.ExpirationTimestamp = &token.IDToken.Expiry
+	if !idToken.Expiry.IsZero() {
+		cred.Status.ExpirationTimestamp = &idToken.Expiry
 	}
 	return &cred
 }

cmd/pinniped/cmd/login_static.go

@@ -1,4 +1,4 @@
-// Copyright 2020-2023 the Pinniped contributors. All Rights Reserved.
+// Copyright 2020-2024 the Pinniped contributors. All Rights Reserved.
 // SPDX-License-Identifier: Apache-2.0
 
 package cmd
@@ -133,7 +133,7 @@ func runStaticLogin(cmd *cobra.Command, deps staticLoginDeps, flags staticLoginP
 			return fmt.Errorf("--token-env variable %q is empty", flags.staticTokenEnvName)
 		}
 	}
-	cred := tokenCredential(&oidctypes.Token{IDToken: &oidctypes.IDToken{Token: token}})
+	cred := tokenCredential(&oidctypes.IDToken{Token: token})
 
 	// Look up cached credentials based on a hash of all the CLI arguments, the current token value, and the cluster info.
 	cacheKey := struct {

internal/federationdomain/endpoints/auth/auth_handler_test.go

@@ -1,4 +1,4 @@
-// Copyright 2020-2023 the Pinniped contributors. All Rights Reserved.
+// Copyright 2020-2024 the Pinniped contributors. All Rights Reserved.
 // SPDX-License-Identifier: Apache-2.0
 
 package auth
@@ -366,10 +366,7 @@ func TestAuthorizationEndpoint(t *testing.T) { //nolint:gocyclo
 	sadCSRFGenerator := func() (csrftoken.CSRFToken, error) { return "", fmt.Errorf("some csrf generator error") }
 	sadPKCEGenerator := func() (pkce.Code, error) { return "", fmt.Errorf("some PKCE generator error") }
 	sadNonceGenerator := func() (nonce.Nonce, error) { return "", fmt.Errorf("some nonce generator error") }
-
-	// This is the PKCE challenge which is calculated as base64(sha256("test-pkce")). For example:
-	// $ echo -n test-pkce | shasum -a 256 | cut -d" " -f1 | xxd -r -p | base64 | cut -d"=" -f1
-	expectedUpstreamCodeChallenge := "VVaezYqum7reIhoavCHD1n2d-piN3r_mywoYj7fCR7g"
+	expectedUpstreamCodeChallenge := testutil.SHA256("test-pkce")
 
 	var stateEncoderHashKey = []byte("fake-hash-secret")
 	var stateEncoderBlockKey = []byte("0123456789ABCDEF") // block encryption requires 16/24/32 bytes for AES

pkg/oidcclient/login.go

@@ -1,4 +1,4 @@
-// Copyright 2020-2023 the Pinniped contributors. All Rights Reserved.
+// Copyright 2020-2024 the Pinniped contributors. All Rights Reserved.
 // SPDX-License-Identifier: Apache-2.0
 
 // Package oidcclient implements a CLI OIDC login flow.
@@ -44,10 +44,16 @@ import (
 
 const (
 	// minIDTokenValidity is the minimum amount of time that a cached ID token must be still be valid to be considered.
-	// This is non-zero to ensure that most of the time, your ID token won't expire in the middle of a multi-step k8s
+	// This is non-zero to ensure that most of the time, your ID token won't expire in the middle of a multistep k8s
 	// API operation.
 	minIDTokenValidity = 10 * time.Minute
 
+	// minAccessTokenValidity is the minimum amount of time that a cached access token must be still be valid
+	// to be considered.
+	// This is non-zero to ensure that most of the time, your access token won't expire before we submit it for
+	// RFC8693 token exchange.
+	minAccessTokenValidity = 10 * time.Second
+
 	// httpRequestTimeout is the timeout for operations that involve one (or a few) non-interactive HTTPS requests.
 	// Since these don't involve any user interaction, they should always be roughly as fast as network latency.
 	httpRequestTimeout = 60 * time.Second
@@ -328,22 +334,53 @@ func Login(issuer string, clientID string, opts ...Option) (*oidctypes.Token, er
 	}
 
 	// Do the basic login to get an access and ID token issued to our main client ID.
-	baseToken, err := h.baseLogin()
+	token, err := h.baseLogin()
 	if err != nil {
 		return nil, err
 	}
 
-	// If there is no requested audience, or the requested audience matches the one we got, we're done.
-	if h.requestedAudience == "" || (baseToken.IDToken != nil && h.requestedAudience == baseToken.IDToken.Claims["aud"]) {
-		return baseToken, err
+	// Perform the RFC8693 token exchange, if needed. Note that the new ID token returned by this exchange
+	// does not need to be cached because the new ID token is intended to be a very short-lived token.
+	if h.needRFC8693TokenExchange(token) {
+		token, err = h.tokenExchangeRFC8693(token)
+		if err != nil {
+			return nil, fmt.Errorf("failed to exchange token: %w", err)
+		}
 	}
 
-	// Perform the RFC8693 token exchange.
-	exchangedToken, err := h.tokenExchangeRFC8693(baseToken)
-	if err != nil {
-		return nil, fmt.Errorf("failed to exchange token: %w", err)
+	return token, nil
+}
+
+func (h *handlerState) needRFC8693TokenExchange(token *oidctypes.Token) bool {
+	// Need a new ID token if there is a requested audience value and any of the following are true...
+	return h.requestedAudience != "" &&
+		// we don't have an ID token
+		(token.IDToken == nil ||
+			// or, our current ID token has expired or is close to expiring
+			idTokenExpiredOrCloseToExpiring(token.IDToken) ||
+			// or, our current ID token has a different audience
+			(h.requestedAudience != token.IDToken.Claims["aud"]))
+}
+
+func (h *handlerState) tokenValidForNearFuture(token *oidctypes.Token) (bool, string) {
+	if token == nil {
+		return false, ""
 	}
-	return exchangedToken, nil
+	// If we plan to do an RFC8693 token exchange, then we need an access token that will still be valid when we do the
+	// exchange (which will happen momentarily). Otherwise, we need an ID token that will be valid for a little while
+	// (long enough for multistep k8s API operations).
+	if h.needRFC8693TokenExchange(token) {
+		return !accessTokenExpiredOrCloseToExpiring(token.AccessToken), "access_token"
+	}
+	return !idTokenExpiredOrCloseToExpiring(token.IDToken), "id_token"
+}
+
+func accessTokenExpiredOrCloseToExpiring(accessToken *oidctypes.AccessToken) bool {
+	return accessToken == nil || time.Until(accessToken.Expiry.Time) <= minAccessTokenValidity
+}
+
+func idTokenExpiredOrCloseToExpiring(idToken *oidctypes.IDToken) bool {
+	return idToken == nil || time.Until(idToken.Expiry.Time) <= minIDTokenValidity
 }
 
 func (h *handlerState) baseLogin() (*oidctypes.Token, error) {
@@ -360,10 +397,11 @@ func (h *handlerState) baseLogin() (*oidctypes.Token, error) {
 		UpstreamProviderName: h.upstreamIdentityProviderName,
 	}
 
-	// If the ID token is still valid for a bit, return it immediately and skip the rest of the flow.
+	// If the cached tokens include the token type that we need, and that token is still valid for a bit,
+	// return the cached tokens immediately and skip the rest of the flow.
 	cached := h.cache.GetToken(cacheKey)
-	if cached != nil && cached.IDToken != nil && time.Until(cached.IDToken.Expiry.Time) > minIDTokenValidity {
-		h.logger.V(plog.KlogLevelDebug).Info("Pinniped: Found unexpired cached token.")
+	if valid, whichTokenWasValid := h.tokenValidForNearFuture(cached); valid {
+		h.logger.V(plog.KlogLevelDebug).Info("Pinniped: Found unexpired cached token.", "type", whichTokenWasValid)
 		return cached, nil
 	}
 
@@ -378,13 +416,14 @@ func (h *handlerState) baseLogin() (*oidctypes.Token, error) {
 		if err != nil {
 			return nil, err
 		}
-		// If we got a fresh token, we can update the cache and return it. Otherwise we fall through to the full refresh flow.
+		// If we got a fresh token, update the cache and return it. Otherwise, fall through to the full login flow.
 		if freshToken != nil {
 			h.cache.PutToken(cacheKey, freshToken)
 			return freshToken, nil
 		}
 	}
 
+	// We couldn't refresh, so now we need to perform a fresh login attempt.
 	// Prepare the common options for the authorization URL. We don't have the redirect URL yet though.
 	authorizeOptions := []oauth2.AuthCodeOption{
 		oauth2.AccessTypeOffline,
@@ -833,7 +872,7 @@ func (h *handlerState) tokenExchangeRFC8693(baseToken *oidctypes.Token) (*oidcty
 }
 
 func (h *handlerState) handleRefresh(ctx context.Context, refreshToken *oidctypes.RefreshToken) (*oidctypes.Token, error) {
-	h.logger.V(plog.KlogLevelDebug).Info("Pinniped: Refreshing cached token.")
+	h.logger.V(plog.KlogLevelDebug).Info("Pinniped: Refreshing cached tokens.")
 	upstreamOIDCIdentityProvider := h.getProvider(h.oauth2Config, h.provider, h.httpClient)
 
 	refreshed, err := upstreamOIDCIdentityProvider.PerformRefresh(ctx, refreshToken.Token)

pkg/oidcclient/login_test.go

@@ -1,4 +1,4 @@
-// Copyright 2020-2023 the Pinniped contributors. All Rights Reserved.
+// Copyright 2020-2024 the Pinniped contributors. All Rights Reserved.
 // SPDX-License-Identifier: Apache-2.0
 
 package oidcclient
@@ -75,23 +75,18 @@ func newClientForServer(server *httptest.Server) *http.Client {
 }
 
 func TestLogin(t *testing.T) { //nolint:gocyclo
-	time1 := time.Date(2035, 10, 12, 13, 14, 15, 16, time.UTC)
-	time1Unix := int64(2075807775)
-	require.Equal(t, time1Unix, time1.Add(2*time.Minute).Unix())
+	distantFutureTime := time.Date(2065, 10, 12, 13, 14, 15, 16, time.UTC)
 
-	// This is the PKCE challenge which is calculated as base64(sha256("test-pkce")). For example:
-	// $ echo -n test-pkce | shasum -a 256 | cut -d" " -f1 | xxd -r -p | base64 | cut -d"=" -f1
-	// VVaezYqum7reIhoavCHD1n2d+piN3r/mywoYj7fCR7g
-	const testCodeChallenge = "VVaezYqum7reIhoavCHD1n2d-piN3r_mywoYj7fCR7g"
+	testCodeChallenge := testutil.SHA256("test-pkce")
 
 	testToken := oidctypes.Token{
-		AccessToken:  &oidctypes.AccessToken{Token: "test-access-token", Expiry: metav1.NewTime(time1.Add(1 * time.Minute))},
+		AccessToken:  &oidctypes.AccessToken{Token: "test-access-token", Expiry: metav1.NewTime(distantFutureTime.Add(1 * time.Minute))},
 		RefreshToken: &oidctypes.RefreshToken{Token: "test-refresh-token"},
-		IDToken:      &oidctypes.IDToken{Token: "test-id-token", Expiry: metav1.NewTime(time1.Add(2 * time.Minute))},
+		IDToken:      &oidctypes.IDToken{Token: "test-id-token", Expiry: metav1.NewTime(distantFutureTime.Add(2 * time.Minute))},
 	}
 
 	testExchangedToken := oidctypes.Token{
-		IDToken: &oidctypes.IDToken{Token: "test-id-token-with-requested-audience", Expiry: metav1.NewTime(time1.Add(3 * time.Minute))},
+		IDToken: &oidctypes.IDToken{Token: "test-id-token-with-requested-audience", Expiry: metav1.NewTime(distantFutureTime.Add(3 * time.Minute))},
 	}
 
 	// Start a test server that returns 500 errors.
@@ -216,6 +211,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 			})
 		}
 	}
+
 	tokenHandler := func(w http.ResponseWriter, r *http.Request) {
 		if r.Method != http.MethodPost {
 			http.Error(w, "unexpected method", http.StatusMethodNotAllowed)
@@ -434,7 +430,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 			wantErr:  `issuer is not a valid URL: parse "%": invalid URL escape "%"`,
 		},
 		{
-			name:     "session cache hit but token expired",
+			name:     "without request audience, session cache hit but ID token expired",
 			issuer:   errorServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -443,7 +439,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
 						IDToken: &oidctypes.IDToken{
 							Token:  "test-id-token",
-							Expiry: metav1.NewTime(time.Now()), // less than Now() + minIDTokenValidity
+							Expiry: metav1.NewTime(time.Now().Add(9 * time.Minute)), // less than Now() + minIDTokenValidity
 						},
 					}}
 					t.Cleanup(func() {
@@ -458,11 +454,11 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return WithSessionCache(cache)(h)
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + errorServer.URL + "\""},
-			wantErr:  "could not perform OIDC discovery for \"" + errorServer.URL + "\": 500 Internal Server Error: some discovery error\n",
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + errorServer.URL + `"`},
+			wantErr:  `could not perform OIDC discovery for "` + errorServer.URL + `": 500 Internal Server Error: some discovery error` + "\n",
 		},
 		{
-			name:     "session cache hit with valid token",
+			name:     "without request audience, session cache hit with valid ID token",
 			issuer:   "test-issuer",
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -477,10 +473,11 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 						}}, cache.sawGetKeys)
 						require.Empty(t, cache.sawPutTokens)
 					})
-					return WithSessionCache(cache)(h)
+					require.NoError(t, WithSessionCache(cache)(h))
+					return nil
 				}
 			},
-			wantLogs:  []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\""},
+			wantLogs:  []string{`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="id_token"`},
 			wantToken: &testToken,
 		},
 		{
@@ -492,7 +489,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:   errorServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + errorServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + errorServer.URL + `"`},
 			wantErr:  fmt.Sprintf("could not perform OIDC discovery for %q: 500 Internal Server Error: some discovery error\n", errorServer.URL),
 		},
 		{
@@ -504,11 +501,11 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:   brokenResponseModeServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + brokenResponseModeServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + brokenResponseModeServer.URL + `"`},
 			wantErr:  fmt.Sprintf("could not decode response_modes_supported in OIDC discovery from %q: json: cannot unmarshal string into Go struct field .response_modes_supported of type []string", brokenResponseModeServer.URL),
 		},
 		{
-			name:     "session cache hit with refreshable token",
+			name:     "without request audience, session cache hit with expired ID token which is refreshable",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -532,7 +529,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
 						IDToken: &oidctypes.IDToken{
 							Token:  "expired-test-id-token",
-							Expiry: metav1.Now(), // less than Now() + minIDTokenValidity
+							Expiry: metav1.NewTime(time.Now().Add(9 * time.Minute)), // less than Now() + minIDTokenValidity
 						},
 						RefreshToken: &oidctypes.RefreshToken{Token: "test-refresh-token"},
 					}}
@@ -552,8 +549,10 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Refreshing cached token.\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+				`"level"=4 "msg"="Pinniped: Refreshing cached tokens."`,
+			},
 			wantToken: &testToken,
 		},
 		{
@@ -581,7 +580,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
 						IDToken: &oidctypes.IDToken{
 							Token:  "expired-test-id-token",
-							Expiry: metav1.Now(), // less than Now() + minIDTokenValidity
+							Expiry: metav1.NewTime(time.Now().Add(9 * time.Minute)), // less than Now() + minIDTokenValidity
 						},
 						RefreshToken: &oidctypes.RefreshToken{Token: "test-refresh-token-returning-invalid-id-token"},
 					}}
@@ -590,12 +589,13 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 						require.Empty(t, cache.sawPutTokens)
 					})
 					h.cache = cache
-
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Refreshing cached token.\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+				`"level"=4 "msg"="Pinniped: Refreshing cached tokens."`,
+			},
 			wantErr: "some validation error",
 		},
 		{
@@ -609,7 +609,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
 						IDToken: &oidctypes.IDToken{
 							Token:  "expired-test-id-token",
-							Expiry: metav1.Now(), // less than Now() + minIDTokenValidity
+							Expiry: metav1.NewTime(time.Now().Add(9 * time.Minute)), // less than Now() + minIDTokenValidity
 						},
 						RefreshToken: &oidctypes.RefreshToken{Token: "test-refresh-token"},
 					}}
@@ -626,7 +626,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 			},
 			wantLogs: []string{
 				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
-				`"level"=4 "msg"="Pinniped: Refreshing cached token."`,
+				`"level"=4 "msg"="Pinniped: Refreshing cached tokens."`,
 				`"level"=4 "msg"="Pinniped: Refresh failed."  "error"="oauth2: cannot fetch token: 400 Bad Request\nResponse: expected client_id 'test-client-id'\n"`,
 				`"msg"="could not open callback listener" "error"="some listen error"`,
 			},
@@ -804,7 +804,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:   successServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^" +
 				regexp.QuoteMeta("Log in by visiting this link:\n\n") +
 				regexp.QuoteMeta("    https://127.0.0.1:") +
@@ -835,7 +835,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:   successServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^" +
 				regexp.QuoteMeta("Log in by visiting this link:\n\n") +
 				regexp.QuoteMeta("    https://127.0.0.1:") +
@@ -906,7 +906,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:   successServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^" +
 				regexp.QuoteMeta("Log in by visiting this link:\n\n") +
 				regexp.QuoteMeta("    https://127.0.0.1:") +
@@ -978,7 +978,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:   formPostSuccessServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + formPostSuccessServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + formPostSuccessServer.URL + `"`},
 			wantStdErr: "^" +
 				regexp.QuoteMeta("Log in by visiting this link:\n\n") +
 				regexp.QuoteMeta("    https://127.0.0.1:") +
@@ -1053,7 +1053,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:   successServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^" +
 				regexp.QuoteMeta("Log in by visiting this link:\n\n") +
 				regexp.QuoteMeta("    https://127.0.0.1:") +
@@ -1081,7 +1081,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    "error prompting for username: some prompt error",
 		},
@@ -1096,7 +1096,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    "error prompting for password: some prompt error",
 		},
@@ -1135,12 +1135,11 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 						}
 					})
 					require.NoError(t, WithClient(client)(h))
-
 					return nil
 				}
 			},
 			issuer:   successServer.URL,
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantErr:  `discovered authorize URL from issuer is not a valid URL: parse "%": invalid URL escape "%"`,
 		},
 		{
@@ -1152,7 +1151,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr: `authorization response error: Get "https://` + successServer.Listener.Addr().String() +
 				`/authorize?access_type=offline&client_id=test-client-id&code_challenge=` + testCodeChallenge +
@@ -1169,7 +1168,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    `error getting authorization: expected to be redirected, but response status was 502 Bad Gateway`,
 		},
@@ -1187,7 +1186,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    `login failed with code "access_denied": optional-error-description`,
 		},
@@ -1205,7 +1204,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    `error getting authorization: redirected to the wrong location: http://other-server.example.com/callback?code=foo&state=test-state`,
 		},
@@ -1223,7 +1222,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    `login failed with code "access_denied"`,
 		},
@@ -1239,7 +1238,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    `missing or invalid state parameter in authorization response: http://127.0.0.1:0/callback?code=foo&state=wrong-state`,
 		},
@@ -1267,7 +1266,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantErr:    "could not complete authorization code exchange: some authcode exchange or token validation error",
 		},
@@ -1366,7 +1365,7 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			issuer:     successServer.URL,
-			wantLogs:   []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs:   []string{`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantToken:  &testToken,
 		},
@@ -1469,9 +1468,9 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 			},
 			issuer: successServer.URL,
 			wantLogs: []string{
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Read username from environment variable\"  \"name\"=\"PINNIPED_USERNAME\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Read password from environment variable\"  \"name\"=\"PINNIPED_PASSWORD\"",
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+				`"level"=4 "msg"="Pinniped: Read username from environment variable"  "name"="PINNIPED_USERNAME"`,
+				`"level"=4 "msg"="Pinniped: Read password from environment variable"  "name"="PINNIPED_PASSWORD"`,
 			},
 			wantToken: &testToken,
 		},
@@ -1578,15 +1577,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 			},
 			issuer: successServer.URL,
 			wantLogs: []string{
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Read username from environment variable\"  \"name\"=\"PINNIPED_USERNAME\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Read password from environment variable\"  \"name\"=\"PINNIPED_PASSWORD\"",
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+				`"level"=4 "msg"="Pinniped: Read username from environment variable"  "name"="PINNIPED_USERNAME"`,
+				`"level"=4 "msg"="Pinniped: Read password from environment variable"  "name"="PINNIPED_PASSWORD"`,
 			},
 			wantStdErr: "^\nLog in to some-upstream-name\n\n$",
 			wantToken:  &testToken,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but discovery fails",
+			name:     "with requested audience, session cache hit with valid access token, but discovery fails",
 			clientID: "test-client-id",
 			issuer:   errorServer.URL,
 			opt: func(t *testing.T) Option {
@@ -1607,13 +1606,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"cluster-1234\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + errorServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="cluster-1234"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + errorServer.URL + `"`,
+			},
 			wantErr: fmt.Sprintf("failed to exchange token: could not perform OIDC discovery for %q: 500 Internal Server Error: some discovery error\n", errorServer.URL),
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token URL is insecure",
+			name:     "with requested audience, session cache hit with valid access token, but token URL is insecure",
 			issuer:   insecureTokenURLServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1634,13 +1635,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"cluster-1234\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + insecureTokenURLServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="cluster-1234"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + insecureTokenURLServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: discovered token URL from issuer must be an https URL, but had scheme "http" instead`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token URL is invalid",
+			name:     "with requested audience, session cache hit with valid access token, but token URL is invalid",
 			issuer:   brokenTokenURLServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1661,13 +1664,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"cluster-1234\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + brokenTokenURLServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="cluster-1234"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + brokenTokenURLServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: discovered token URL from issuer is not a valid URL: parse "%": invalid URL escape "%"`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request fails",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request fails",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1688,13 +1693,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-invalid-http-response\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-invalid-http-response"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: fmt.Sprintf(`failed to exchange token: Post "%s/token": failed to parse Location header "%%": parse "%%": invalid URL escape "%%"`, successServer.URL),
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request returns non-200",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request returns non-200",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1715,13 +1722,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-http-400\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-http-400"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: unexpected HTTP response status 400`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request returns invalid content-type header",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request returns invalid content-type header",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1742,13 +1751,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-invalid-content-type\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-invalid-content-type"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: failed to decode content-type header: mime: invalid media parameter`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request returns wrong content-type",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request returns wrong content-type",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1769,13 +1780,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-wrong-content-type\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-wrong-content-type"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: unexpected HTTP response content type "invalid"`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request returns invalid JSON",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request returns invalid JSON",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1796,13 +1809,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-invalid-json\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-invalid-json"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: failed to decode response: unexpected EOF`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request returns invalid token_type",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request returns invalid token_type",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1823,13 +1838,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-invalid-tokentype\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-invalid-tokentype"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: got unexpected token_type "invalid"`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request returns invalid issued_token_type",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request returns invalid issued_token_type",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1850,13 +1867,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-invalid-issuedtokentype\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-invalid-issuedtokentype"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: got unexpected issued_token_type "invalid"`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, but token exchange request returns invalid JWT",
+			name:     "with requested audience, session cache hit with valid access token, but token exchange request returns invalid JWT",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1877,13 +1896,15 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience-produce-invalid-jwt\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience-produce-invalid-jwt"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantErr: `failed to exchange token: received invalid JWT: oidc: malformed jwt: oidc: malformed jwt, expected 3 parts got 1`,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid token, and token exchange request succeeds",
+			name:     "with requested audience, session cache hit with valid access token, ID token has wrong audience, and token exchange request succeeds",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1910,13 +1931,142 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 					return nil
 				}
 			},
-			wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\""},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
 			wantToken: &testExchangedToken,
 		},
 		{
-			name:     "with requested audience, session cache hit with valid refresh token, and token exchange request succeeds",
+			name:     "with requested audience, session cache hit with valid access token, and valid ID token already has the requested audience, returns cached tokens without any exchange or refresh",
+			issuer:   successServer.URL,
+			clientID: "test-client-id",
+			opt: func(t *testing.T) Option {
+				return func(h *handlerState) error {
+					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
+						AccessToken: testToken.AccessToken,
+						IDToken: &oidctypes.IDToken{
+							Token:  testToken.IDToken.Token,
+							Expiry: testToken.IDToken.Expiry,
+							Claims: map[string]interface{}{"aud": "request-this-test-audience"},
+						},
+						RefreshToken: testToken.RefreshToken,
+					}}
+					t.Cleanup(func() {
+						require.Equal(t, []SessionCacheKey{{
+							Issuer:      successServer.URL,
+							ClientID:    "test-client-id",
+							Scopes:      []string{"test-scope"},
+							RedirectURI: "http://localhost:0/callback",
+						}}, cache.sawGetKeys)
+						require.Empty(t, cache.sawPutTokens)
+					})
+					require.NoError(t, WithClient(newClientForServer(successServer))(h))
+					require.NoError(t, WithSessionCache(cache)(h))
+					require.NoError(t, WithRequestAudience("request-this-test-audience")(h))
+
+					h.validateIDToken = func(ctx context.Context, provider *oidc.Provider, audience string, token string) (*oidc.IDToken, error) {
+						require.FailNow(t, "should not have performed a token exchange because the cached ID token already had the requested audience")
+						return nil, nil
+					}
+					return nil
+				}
+			},
+			wantLogs: []string{`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="id_token"`},
+			wantToken: &oidctypes.Token{ // the same tokens that were pulled from from the cache
+				AccessToken: testToken.AccessToken,
+				IDToken: &oidctypes.IDToken{
+					Token:  testToken.IDToken.Token,
+					Expiry: testToken.IDToken.Expiry,
+					Claims: map[string]interface{}{"aud": "request-this-test-audience"},
+				},
+				RefreshToken: testToken.RefreshToken,
+			},
+		},
+		{
+			name:     "with requested audience, session cache hit with valid access token, ID token already has the requested audience, but ID token is expired",
+			issuer:   successServer.URL,
+			clientID: "test-client-id",
+			opt: func(t *testing.T) Option {
+				return func(h *handlerState) error {
+					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
+						AccessToken: testToken.AccessToken,
+						IDToken: &oidctypes.IDToken{
+							Token:  testToken.IDToken.Token,
+							Expiry: metav1.NewTime(time.Now().Add(9 * time.Minute)), // less than Now() + minIDTokenValidity
+							Claims: map[string]interface{}{"aud": "request-this-test-audience"},
+						},
+						RefreshToken: testToken.RefreshToken,
+					}}
+					t.Cleanup(func() {
+						require.Equal(t, []SessionCacheKey{{
+							Issuer:      successServer.URL,
+							ClientID:    "test-client-id",
+							Scopes:      []string{"test-scope"},
+							RedirectURI: "http://localhost:0/callback",
+						}}, cache.sawGetKeys)
+						require.Empty(t, cache.sawPutTokens)
+					})
+					require.NoError(t, WithClient(newClientForServer(successServer))(h))
+					require.NoError(t, WithSessionCache(cache)(h))
+					require.NoError(t, WithRequestAudience("request-this-test-audience")(h))
+
+					h.validateIDToken = func(ctx context.Context, provider *oidc.Provider, audience string, token string) (*oidc.IDToken, error) {
+						require.Equal(t, "request-this-test-audience", audience)
+						require.Equal(t, "test-id-token-with-requested-audience", token)
+						return &oidc.IDToken{Expiry: testExchangedToken.IDToken.Expiry.Time}, nil
+					}
+					return nil
+				}
+			},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="request-this-test-audience"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
+			wantToken: &testExchangedToken,
+		},
+		{
+			name:     "with requested audience, session cache hit with valid access token, but no ID token",
+			issuer:   successServer.URL,
+			clientID: "test-client-id",
+			opt: func(t *testing.T) Option {
+				return func(h *handlerState) error {
+					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
+						AccessToken:  testToken.AccessToken,
+						RefreshToken: testToken.RefreshToken,
+					}}
+					t.Cleanup(func() {
+						require.Equal(t, []SessionCacheKey{{
+							Issuer:      successServer.URL,
+							ClientID:    "test-client-id",
+							Scopes:      []string{"test-scope"},
+							RedirectURI: "http://localhost:0/callback",
+						}}, cache.sawGetKeys)
+						require.Empty(t, cache.sawPutTokens)
+					})
+					require.NoError(t, WithClient(newClientForServer(successServer))(h))
+					require.NoError(t, WithSessionCache(cache)(h))
+					require.NoError(t, WithRequestAudience("request-this-test-audience")(h))
+
+					h.validateIDToken = func(ctx context.Context, provider *oidc.Provider, audience string, token string) (*oidc.IDToken, error) {
+						require.Equal(t, "request-this-test-audience", audience)
+						require.Equal(t, "test-id-token-with-requested-audience", token)
+						return &oidc.IDToken{Expiry: testExchangedToken.IDToken.Expiry.Time}, nil
+					}
+					return nil
+				}
+			},
+			wantLogs: []string{
+				`"level"=4 "msg"="Pinniped: Found unexpired cached token."  "type"="access_token"`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="request-this-test-audience"`,
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+			},
+			wantToken: &testExchangedToken,
+		},
+		{
+			name:     "with requested audience, session cache hit with expired access token and valid refresh token, and token exchange request succeeds",
 			issuer:   successServer.URL,
 			clientID: "test-client-id",
 			opt: func(t *testing.T) Option {
@@ -1925,8 +2075,12 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 
 					cache := &mockSessionCache{t: t, getReturnsToken: &oidctypes.Token{
 						IDToken: &oidctypes.IDToken{
-							Token:  "expired-test-id-token",
-							Expiry: metav1.Now(), // less than Now() + minIDTokenValidity
+							Token:  "not-yet-expired-test-id-token",
+							Expiry: metav1.NewTime(distantFutureTime),
+						},
+						AccessToken: &oidctypes.AccessToken{
+							Token:  "expired-test-access-token",
+							Expiry: metav1.NewTime(time.Now().Add(9 * time.Second)), // less than Now() + minAccessTokenValidity
 						},
 						RefreshToken: &oidctypes.RefreshToken{Token: "test-refresh-token"},
 					}}
@@ -1969,9 +2123,9 @@ func TestLogin(t *testing.T) { //nolint:gocyclo
 				}
 			},
 			wantLogs: []string{
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\"  \"issuer\"=\"" + successServer.URL + "\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Refreshing cached token.\"",
-				"\"level\"=4 \"msg\"=\"Pinniped: Performing RFC8693 token exchange\"  \"requestedAudience\"=\"test-audience\"",
+				`"level"=4 "msg"="Pinniped: Performing OIDC discovery"  "issuer"="` + successServer.URL + `"`,
+				`"level"=4 "msg"="Pinniped: Refreshing cached tokens."`,
+				`"level"=4 "msg"="Pinniped: Performing RFC8693 token exchange"  "requestedAudience"="test-audience"`,
 			},
 			wantToken: &testExchangedToken,
 		},

test/integration/supervisor_warnings_test.go

@@ -1,4 +1,4 @@
-// Copyright 2022-2023 the Pinniped contributors. All Rights Reserved.
+// Copyright 2022-2024 the Pinniped contributors. All Rights Reserved.
 // SPDX-License-Identifier: Apache-2.0
 package integration
 
@@ -209,12 +209,14 @@ func TestSupervisorWarnings_Browser(t *testing.T) {
 		err = os.Remove(credentialCachePath)
 		require.NoError(t, err)
 
-		// wait for the existing tokens to expire, triggering the refresh flow.
-		ctx2, cancel2 := context.WithTimeout(ctx, 1*time.Minute)
-		defer cancel2()
+		// The cached access token is valid for 2 minutes, and can be used to perform the token exchange again
+		// during that time. Remove it to force the refresh flow to happen on the next kubectl invocation,
+		// without needing to wait for the access token to expire first.
+		token.AccessToken = nil
+		cache.PutToken(sessionCacheKey, token)
 
 		// 	Run kubectl, which should work without any prompting for authentication.
-		kubectlCmd2 := exec.CommandContext(ctx2, "kubectl", "get", "namespace", "--kubeconfig", kubeconfigPath)
+		kubectlCmd2 := exec.CommandContext(ctx, "kubectl", "get", "namespace", "--kubeconfig", kubeconfigPath)
 		kubectlCmd2.Env = append(os.Environ(), env.ProxyEnv()...)
 		startTime2 := time.Now()
 		var kubectlStdoutPipe2 io.ReadCloser
@@ -253,7 +255,7 @@ func TestSupervisorWarnings_Browser(t *testing.T) {
 		expectedUsername, password := testlib.CreateFreshADTestUser(t, env)
 
 		sAMAccountName := expectedUsername + "@" + env.SupervisorUpstreamActiveDirectory.Domain
-		setupClusterForEndToEndActiveDirectoryTest(t, sAMAccountName, env)
+		createdProvider := setupClusterForEndToEndActiveDirectoryTest(t, sAMAccountName, env)
 		testlib.WaitForFederationDomainStatusPhase(ctx, t, downstream.Name, configv1alpha1.FederationDomainPhaseReady)
 
 		// Use a specific session cache for this test.
@@ -309,6 +311,24 @@ func TestSupervisorWarnings_Browser(t *testing.T) {
 
 		t.Logf("first kubectl command took %s", time.Since(start).String())
 
+		cache := filesession.New(sessionCachePath, filesession.WithErrorReporter(func(err error) {
+			require.NoError(t, err)
+		}))
+
+		// construct the cache key
+		downstreamScopes := []string{"offline_access", "openid", "pinniped:request-audience", "groups"}
+		sort.Strings(downstreamScopes)
+		sessionCacheKey := oidcclient.SessionCacheKey{
+			Issuer:               downstream.Spec.Issuer,
+			ClientID:             "pinniped-cli",
+			Scopes:               downstreamScopes,
+			RedirectURI:          "http://localhost:0/callback",
+			UpstreamProviderName: createdProvider.Name,
+		}
+		// use it to get the cache entry
+		token := cache.GetToken(sessionCacheKey)
+		require.NotNil(t, token)
+
 		// create an active directory group, and add our user to it.
 		groupName := testlib.CreateFreshADTestGroup(t, env)
 		testlib.AddTestUserToGroup(t, env, groupName, expectedUsername)
@@ -317,11 +337,14 @@ func TestSupervisorWarnings_Browser(t *testing.T) {
 		err = os.Remove(credentialCachePath)
 		require.NoError(t, err)
 
-		ctx2, cancel2 := context.WithTimeout(ctx, 1*time.Minute)
-		defer cancel2()
+		// The cached access token is valid for 2 minutes, and can be used to perform the token exchange again
+		// during that time. Remove it to force the refresh flow to happen on the next kubectl invocation,
+		// without needing to wait for the access token to expire first.
+		token.AccessToken = nil
+		cache.PutToken(sessionCacheKey, token)
 
 		// Run kubectl, which should work without any prompting for authentication.
-		kubectlCmd2 := exec.CommandContext(ctx2, "kubectl", "get", "namespace", "--kubeconfig", kubeconfigPath)
+		kubectlCmd2 := exec.CommandContext(ctx, "kubectl", "get", "namespace", "--kubeconfig", kubeconfigPath)
 		kubectlCmd2.Env = append(os.Environ(), env.ProxyEnv()...)
 		startTime2 := time.Now()
 		var kubectlStdoutPipe2 io.ReadCloser
@@ -520,12 +543,14 @@ func TestSupervisorWarnings_Browser(t *testing.T) {
 		err = os.Remove(credentialCachePath)
 		require.NoError(t, err)
 
-		// wait for the existing tokens to expire, triggering the refresh flow.
-		ctx2, cancel2 := context.WithTimeout(ctx, 1*time.Minute)
-		defer cancel2()
+		// The cached access token is valid for 2 minutes, and can be used to perform the token exchange again
+		// during that time. Remove it to force the refresh flow to happen on the next kubectl invocation,
+		// without needing to wait for the access token to expire first.
+		token.AccessToken = nil
+		cache.PutToken(sessionCacheKey, token)
 
 		// 	Run kubectl, which should work without any prompting for authentication.
-		kubectlCmd2 := exec.CommandContext(ctx2, "kubectl", "get", "namespace", "--kubeconfig", kubeconfigPath)
+		kubectlCmd2 := exec.CommandContext(ctx, "kubectl", "get", "namespace", "--kubeconfig", kubeconfigPath)
 		kubectlCmd2.Env = append(os.Environ(), env.ProxyEnv()...)
 		startTime2 := time.Now()
 		var kubectlStdoutPipe2 io.ReadCloser