From ab94b97f4a43f80e3509368aaab57a631a48cb79 Mon Sep 17 00:00:00 2001 From: Margo Crawford Date: Fri, 30 Apr 2021 12:10:04 -0700 Subject: [PATCH] Change login.go to use logr.logger --- cmd/pinniped/cmd/login_oidc.go | 2 +- pkg/oidcclient/login.go | 16 ++--- pkg/oidcclient/login_test.go | 109 ++++++++++++++++----------------- 3 files changed, 64 insertions(+), 63 deletions(-) diff --git a/cmd/pinniped/cmd/login_oidc.go b/cmd/pinniped/cmd/login_oidc.go index d52b71d8..4c1620be 100644 --- a/cmd/pinniped/cmd/login_oidc.go +++ b/cmd/pinniped/cmd/login_oidc.go @@ -134,7 +134,7 @@ func runOIDCLogin(cmd *cobra.Command, deps oidcLoginCommandDeps, flags oidcLogin // Initialize the login handler. opts := []oidcclient.Option{ oidcclient.WithContext(cmd.Context()), - oidcclient.WithLogger(*pLogger), + oidcclient.WithLogger(klogr.New()), oidcclient.WithScopes(flags.scopes), oidcclient.WithSessionCache(sessionCache), } diff --git a/pkg/oidcclient/login.go b/pkg/oidcclient/login.go index d606dec7..142b6779 100644 --- a/pkg/oidcclient/login.go +++ b/pkg/oidcclient/login.go @@ -17,6 +17,7 @@ import ( "time" "github.com/coreos/go-oidc/v3/oidc" + "github.com/go-logr/logr" "github.com/pkg/browser" "golang.org/x/oauth2" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -24,7 +25,6 @@ import ( "go.pinniped.dev/internal/httputil/httperr" "go.pinniped.dev/internal/httputil/securityheader" "go.pinniped.dev/internal/oidc/provider" - "go.pinniped.dev/internal/plog" "go.pinniped.dev/internal/upstreamoidc" "go.pinniped.dev/pkg/oidcclient/nonce" "go.pinniped.dev/pkg/oidcclient/oidctypes" @@ -45,12 +45,14 @@ const ( // overallTimeout is the overall time that a login is allowed to take. This includes several user interactions, so // we set this to be relatively long. overallTimeout = 90 * time.Minute + + debugLogLevel = 4 ) type handlerState struct { // Basic parameters. ctx context.Context - logger plog.PLogger + logger logr.Logger issuer string clientID string scopes []string @@ -101,7 +103,7 @@ func WithContext(ctx context.Context) Option { // WithLogger specifies a PLogger to use with the login. // If not specified this will default to a new logger. -func WithLogger(logger plog.PLogger) Option { +func WithLogger(logger logr.Logger) Option { return func(h *handlerState) error { h.logger = logger return nil @@ -271,7 +273,7 @@ func (h *handlerState) baseLogin() (*oidctypes.Token, error) { // If the ID token is still valid for a bit, return it 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.Debug("Found unexpired cached token.") + h.logger.V(debugLogLevel).Info("Pinniped: Found unexpired cached token.") return cached, nil } @@ -339,7 +341,7 @@ func (h *handlerState) initOIDCDiscovery() error { return nil } - h.logger.Debug("Performing OIDC discovery", "issuer", h.issuer) + h.logger.V(debugLogLevel).Info("Pinniped: Performing OIDC discovery", "issuer", h.issuer) var err error h.provider, err = oidc.NewProvider(h.ctx, h.issuer) if err != nil { @@ -356,7 +358,7 @@ func (h *handlerState) initOIDCDiscovery() error { } func (h *handlerState) tokenExchangeRFC8693(baseToken *oidctypes.Token) (*oidctypes.Token, error) { - h.logger.Debug("Performing RFC8693 token exchange", "requestedAudience", h.requestedAudience) + h.logger.V(debugLogLevel).Info("Pinniped: Performing RFC8693 token exchange", "requestedAudience", h.requestedAudience) // Perform OIDC discovery. This may have already been performed if there was not a cached base token. if err := h.initOIDCDiscovery(); err != nil { return nil, err @@ -427,7 +429,7 @@ func (h *handlerState) tokenExchangeRFC8693(baseToken *oidctypes.Token) (*oidcty } func (h *handlerState) handleRefresh(ctx context.Context, refreshToken *oidctypes.RefreshToken) (*oidctypes.Token, error) { - h.logger.Debug("Refreshing cached token.") + h.logger.V(debugLogLevel).Info("Pinniped: Refreshing cached token.") refreshSource := h.oauth2Config.TokenSource(ctx, &oauth2.Token{RefreshToken: refreshToken.Token}) refreshed, err := refreshSource.Token() diff --git a/pkg/oidcclient/login_test.go b/pkg/oidcclient/login_test.go index 89d25e84..c3ac6609 100644 --- a/pkg/oidcclient/login_test.go +++ b/pkg/oidcclient/login_test.go @@ -13,6 +13,8 @@ import ( "testing" "time" + "github.com/go-logr/stdr" + "github.com/coreos/go-oidc/v3/oidc" "github.com/golang/mock/gomock" "github.com/stretchr/testify/assert" @@ -24,7 +26,6 @@ import ( "go.pinniped.dev/internal/httputil/httperr" "go.pinniped.dev/internal/mocks/mockupstreamoidcidentityprovider" "go.pinniped.dev/internal/oidc/provider" - "go.pinniped.dev/internal/plog" "go.pinniped.dev/internal/testutil" "go.pinniped.dev/internal/testutil/testlogger" "go.pinniped.dev/pkg/oidcclient/nonce" @@ -273,7 +274,7 @@ func TestLogin(t *testing.T) { return WithSessionCache(cache)(h) } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"test-issuer\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"test-issuer\""}, wantErr: `could not perform OIDC discovery for "test-issuer": Get "test-issuer/.well-known/openid-configuration": unsupported protocol scheme ""`, }, { @@ -295,7 +296,7 @@ func TestLogin(t *testing.T) { return WithSessionCache(cache)(h) } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Found unexpired cached token.\""}, wantToken: &testToken, }, { @@ -304,7 +305,7 @@ func TestLogin(t *testing.T) { return func(h *handlerState) error { return nil } }, issuer: errorServer.URL, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: 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), }, { @@ -344,8 +345,8 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Refreshing cached token.\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\"", + "\"level\"=4 \"msg\"=\"Pinniped: Refreshing cached token.\""}, wantToken: &testToken, }, { @@ -378,8 +379,8 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Refreshing cached token.\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\"", + "\"level\"=4 \"msg\"=\"Pinniped: Refreshing cached token.\""}, wantErr: "some validation error", }, { @@ -406,8 +407,8 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Refreshing cached token.\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\"", + "\"level\"=4 \"msg\"=\"Pinniped: Refreshing cached token.\""}, // Expect this to fall through to the authorization code flow, so it fails here. wantErr: "could not open callback listener: listen tcp: address invalid-listen-address: missing port in address", }, @@ -420,7 +421,7 @@ func TestLogin(t *testing.T) { } }, issuer: successServer.URL, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, wantErr: "could not open callback listener: listen tcp: address invalid-listen-address: missing port in address", }, { @@ -431,7 +432,7 @@ func TestLogin(t *testing.T) { }) }, issuer: successServer.URL, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, wantErr: "could not open browser: some browser open error", }, { @@ -449,7 +450,7 @@ func TestLogin(t *testing.T) { } }, issuer: successServer.URL, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, wantErr: "timed out waiting for token callback: context canceled", }, { @@ -466,7 +467,7 @@ func TestLogin(t *testing.T) { } }, issuer: successServer.URL, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, wantErr: "error handling callback: some callback error", }, { @@ -527,7 +528,7 @@ func TestLogin(t *testing.T) { } }, issuer: successServer.URL, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + wantLogs: []string{"\"level\"=4 \"msg\"=\"Pinniped: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, wantToken: &testToken, }, { @@ -551,9 +552,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"cluster-1234\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + errorServer.URL + "\""}, + 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 + "\""}, wantErr: fmt.Sprintf("failed to exchange token: could not perform OIDC discovery for %q: 500 Internal Server Error: some discovery error\n", errorServer.URL), }, { @@ -577,9 +578,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"cluster-1234\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + brokenTokenURLServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: could not build RFC8693 request: parse "%": invalid URL escape "%"`, }, { @@ -603,9 +604,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-invalid-http-response\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: fmt.Sprintf(`failed to exchange token: Post "%s/token": failed to parse Location header "%%": parse "%%": invalid URL escape "%%"`, successServer.URL), }, { @@ -629,9 +630,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-http-400\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: unexpected HTTP response status 400`, }, { @@ -655,9 +656,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-invalid-content-type\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: failed to decode content-type header: mime: invalid media parameter`, }, { @@ -681,9 +682,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-wrong-content-type\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: unexpected HTTP response content type "invalid"`, }, { @@ -707,9 +708,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-invalid-json\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: failed to decode response: unexpected EOF`, }, { @@ -733,9 +734,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-invalid-tokentype\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: got unexpected token_type "invalid"`, }, { @@ -759,9 +760,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-invalid-issuedtokentype\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: got unexpected issued_token_type "invalid"`, }, { @@ -785,9 +786,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience-produce-invalid-jwt\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantErr: `failed to exchange token: received invalid JWT: oidc: malformed jwt: square/go-jose: compact JWS format must have three parts`, }, { @@ -817,9 +818,9 @@ func TestLogin(t *testing.T) { return nil } }, - wantLogs: []string{"\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Found unexpired cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\""}, + 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 + "\""}, wantToken: &testExchangedToken, }, { @@ -868,9 +869,9 @@ func TestLogin(t *testing.T) { } }, wantLogs: []string{ - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing OIDC discovery\" \"issuer\"=\"" + successServer.URL + "\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Refreshing cached token.\"", - "\"level\"=0 \"msg\"=\"Pinniped Test Prefix: Performing RFC8693 token exchange\" \"requestedAudience\"=\"test-audience\"", + "\"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\"", }, wantToken: &testExchangedToken, }, @@ -878,18 +879,16 @@ func TestLogin(t *testing.T) { for _, tt := range tests { tt := tt t.Run(tt.name, func(t *testing.T) { - err := plog.ValidateAndSetLogLevelGlobally(plog.LevelDebug) - require.NoError(t, err) testLogger := testlogger.New(t) - pLogger := plog.New("Pinniped Test Prefix: ") klog.SetLogger(testLogger) + stdr.SetVerbosity(debugLogLevel) // set stdr's global log level to debug so the test logger will send output. tok, err := Login(tt.issuer, tt.clientID, WithContext(context.Background()), WithListenPort(0), WithScopes([]string{"test-scope"}), tt.opt(t), - WithLogger(pLogger), + WithLogger(testLogger), ) require.Equal(t, tt.wantLogs, testLogger.Lines()) if tt.wantErr != "" {