Repository: istio-ecosystem/authservice
Pull request #251 (2024-04-17 09:42:25)

Cache well-known responses to avoid making too much calls to the IdP
While working on https://github.com/istio-ecosystem/authservice/pull/250, I saw that authservice was calling many times the well-known endpoint for a single OIDC session. This is because we call it when initializing the OIDC handlers, and that is done per request to the Envoy ext-authz filter, and a single OIDC session may involve several requests, given the redirects, making several unnecessary calls to the IdP.

This PR caches the seen well-known requests, and returns them from the cache for subsequent requests. The well-known endpoints are usually stable and it is very rare that they change, so it should be fine to just cache them by default.

istio-testing: [APPROVALNOTIFIER] This PR is **APPROVED**

This pull-request has been approved by: *<a href="https://github.com/istio-ecosystem/authservice/pull/251#" title="Author self-approved">nacx</a>*

The full list of commands accepted by this bot can be found [here](https://go.k8s.io/bot-commands?repo=istio-ecosystem%2Fauthservice).

The pull request process is described [here](https://git.k8s.io/community/contributors/guide/owners.md#the-code-review-process)

<details >
Needs approval from an approver in each of these files:

- ~~[OWNERS](https://github.com/istio-ecosystem/authservice/blob/main/OWNERS)~~ [nacx]

Approvers can indicate their approval by writing `/approve` in a comment
Approvers can cancel approval by writing `/approve cancel` in a comment
</details>
<!-- META={"approvers":[]} -->

Patch:
diff --git a/internal/authz/oidc.go b/internal/authz/oidc.go
index b27f560..d77ba90 100644
--- a/internal/authz/oidc.go
+++ b/internal/authz/oidc.go
@@ -70,7 +70,7 @@ type oidcHandler struct {
 func NewOIDCHandler(cfg *oidcv1.OIDCConfig, tlsPool internal.TLSConfigPool, jwks oidc.JWKSProvider,
 	sessions oidc.SessionStoreFactory, clock oidc.Clock, sessionGen oidc.SessionGenerator) (Handler, error) {
 
-	client, err := getHTTPClient(cfg, tlsPool)
+	client, err := inthttp.NewHTTPClient(cfg, tlsPool, internal.Logger(internal.IDP))
 	if err != nil {
 		return nil, err
 	}
@@ -91,23 +91,6 @@ func NewOIDCHandler(cfg *oidcv1.OIDCConfig, tlsPool internal.TLSConfigPool, jwks
 	}, nil
 }
 
-func getHTTPClient(cfg *oidcv1.OIDCConfig, tlsPool internal.TLSConfigPool) (*http.Client, error) {
-	transport := http.DefaultTransport.(*http.Transport).Clone()
-
-	var err error
-	if transport.TLSClientConfig, err = tlsPool.LoadTLSConfig(cfg); err != nil {
-		return nil, err
-	}
-
-	if cfg.ProxyUri != "" {
-		// config validation ensures that the proxy uri is valid
-		proxyURL, _ := url.Parse(cfg.ProxyUri)
-		transport.Proxy = http.ProxyURL(proxyURL)
-	}
-
-	return &http.Client{Transport: transport}, nil
-}
-
 // Process a CheckRequest and populate a CheckResponse according to the mockHandler configuration.
 func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp *envoy.CheckResponse) error {
 	log := o.log.Context(ctx)
@@ -143,7 +126,8 @@ func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp
 				return nil
 			}
 		}
-		log.Info("logout complete. Redirecting to logout redirect uri")
+		log.Info("logout complete. Redirecting to logout redirect uri",
+			"uri", o.config.GetLogout().GetRedirectUri())
 		deny := newDenyResponse()
 		// add IDP logout location
 		setRedirect(deny, o.config.GetLogout().GetRedirectUri())
@@ -156,7 +140,7 @@ func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp
 	// If the request does not have a session_id cookie,
 	// then generate a session id, put it in a header, and redirect for login.
 	if sessionID == "" {
-		log.Info("no session cookie detected. Generating new session and sending user to re-authenticate.")
+		log.Info("no session cookie detected. Generating new session and sending user to re-authenticate")
 		o.redirectToIDP(ctx, log, resp, req.GetAttributes().GetRequest().GetHttp(), "")
 		return nil
 	}
@@ -185,7 +169,7 @@ func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp
 	// If the user has a session_id cookie but there are no required tokens in the
 	// session store associated with it, then redirect for login.
 	if tokenResponse == nil {
-		log.Info("required tokens are not present. Sending user to re-authenticate.")
+		log.Info("required tokens are not present. Sending user to re-authenticate")
 		o.redirectToIDP(ctx, log, resp, req.GetAttributes().GetRequest().GetHttp(), sessionID)
 		return nil
 	}
@@ -193,14 +177,14 @@ func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp
 	// If both ID & Access token are still unexpired,
 	// then allow the request to proceed (no need to intervene).
 	log.Debug("checking tokens expiration")
-	expired, err := o.areRequiredTokensExpired(tokenResponse)
+	expired, err := o.areRequiredTokensExpired(log, tokenResponse)
 	if err != nil {
 		log.Error("error checking token expiration", err)
 		setDenyResponse(resp, newDenyResponse(), codes.Internal)
 		return nil
 	}
 	if !expired {
-		log.Info("tokens not expired. Allowing request to proceed.")
+		log.Info("tokens not expired. Allowing request to proceed")
 		o.allowResponse(resp, tokenResponse)
 		return nil
 	}
@@ -210,7 +194,7 @@ func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp
 	// If there is no refresh token,
 	// then direct the request to the identity provider for authentication
 	if tokenResponse.RefreshToken == "" {
-		log.Info("a token was expired, but session did not contain a refresh token. Sending user to re-authenticate.")
+		log.Info("a token was expired, but session did not contain a refresh token. Sending user to re-authenticate")
 		o.redirectToIDP(ctx, log, resp, req.GetAttributes().GetRequest().GetHttp(), sessionID)
 		return nil
 	}
@@ -221,7 +205,7 @@ func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp
 	log.Debug("attempting token refresh")
 	refreshedTokens := o.refreshToken(ctx, log, tokenResponse, tokenResponse.RefreshToken, sessionID)
 	if refreshedTokens == nil {
-		log.Info("token refresh failed. Sending user to re-authenticate.")
+		log.Info("token refresh failed. Sending user to re-authenticate")
 		o.redirectToIDP(ctx, log, resp, req.GetAttributes().GetRequest().GetHttp(), sessionID)
 		return nil
 	}
@@ -231,7 +215,7 @@ func (o *oidcHandler) Process(ctx context.Context, req *envoy.CheckRequest, resp
 		return nil
 	}
 
-	log.Info("token refresh successful. Allowing request to proceed.")
+	log.Info("token refresh successful. Allowing request to proceed")
 	o.allowResponse(resp, refreshedTokens)
 	return nil
 }
@@ -327,7 +311,7 @@ func (o *oidcHandler) retrieveTokens(ctx context.Context, log telemetry.Logger,
 	}
 
 	if stateFromStore == nil {
-		log.Info("missing state, nonce, and original url requested by user in the store. Cannot redirect.")
+		log.Info("missing state, nonce, and original url requested by user in the store. Cannot redirect")
 		deny := newDenyResponse()
 		deny.Body = "Oops, your session has expired. Please try again."
 		deny.Status = &typev3.HttpStatus{Code: typev3.StatusCode_BadRequest}
@@ -760,17 +744,24 @@ func encodeHeaderValue(preamble string, value string) string {
 }
 
 // areRequiredTokensExpired checks if the required tokens are expired.
-func (o *oidcHandler) areRequiredTokensExpired(tokens *oidc.TokenResponse) (bool, error) {
+func (o *oidcHandler) areRequiredTokensExpired(log telemetry.Logger, tokens *oidc.TokenResponse) (bool, error) {
 	idToken, err := tokens.ParseIDToken()
 	if err != nil {
 		return false, fmt.Errorf("parsing id token: %w", err)
 	}
 
-	if idToken.Expiration().Before(o.clock.Now()) {
+	now := o.clock.Now()
+	if idToken.Expiration().Before(now) {
+		log.Info("id token is expired", "exp", idToken.Expiration(), "expired_for", now.Sub(idToken.Expiration()))
 		return true, nil
 	}
-	if o.config.GetAccessToken() != nil && tokens.AccessToken != "" && !tokens.AccessTokenExpiresAt.IsZero() {
-		return tokens.AccessTokenExpiresAt.Before(o.clock.Now()), nil
+	if o.config.GetAccessToken() != nil &&
+		tokens.AccessToken != "" &&
+		!tokens.AccessTokenExpiresAt.IsZero() &&
+		tokens.AccessTokenExpiresAt.Before(now) {
+		log.Info("access token is expired", "exp", tokens.AccessTokenExpiresAt,
+			"expired_for", now.Sub(tokens.AccessTokenExpiresAt))
+		return true, nil
 	}
 	return false, nil
 }
diff --git a/internal/http/http.go b/internal/http/http.go
index 647b404..fbec176 100644
--- a/internal/http/http.go
+++ b/internal/http/http.go
@@ -16,7 +16,14 @@ package http
 
 import (
 	"encoding/base64"
+	"net/http"
+	"net/url"
 	"strings"
+
+	"github.com/tetratelabs/telemetry"
+
+	oidcv1 "github.com/istio-ecosystem/authservice/config/gen/go/v1/oidc"
+	"github.com/istio-ecosystem/authservice/internal"
 )
 
 // GetPathQueryFragment splits the given path into path, query, and fragment.
@@ -80,6 +87,36 @@ func EncodeCookieHeader(name string, value string, directives []string) string {
 	return b.String()
 }
 
+// BasicAuthHeader returns the value of the Authorization header for the given id and secret.
 func BasicAuthHeader(id string, secret string) string {
 	return "Basic " + base64.StdEncoding.EncodeToString([]byte(id+":"+secret))
 }
+
+// NewHTTPClient creates a new HTTP client with the given OIDC configuration and TLS pool.
+// If a logger is provided, it will log the requests and responses at debug level.
+func NewHTTPClient(cfg *oidcv1.OIDCConfig, tlsPool internal.TLSConfigPool, log telemetry.Logger) (*http.Client, error) {
+	transport := http.DefaultTransport.(*http.Transport).Clone()
+
+	var err error
+	if transport.TLSClientConfig, err = tlsPool.LoadTLSConfig(cfg); err != nil {
+		return nil, err
+	}
+
+	if cfg.ProxyUri != "" {
+		// config validation ensures that the proxy uri is valid
+		proxyURL, _ := url.Parse(cfg.ProxyUri)
+		transport.Proxy = http.ProxyURL(proxyURL)
+	}
+
+	if log != nil && log.Level() >= telemetry.LevelDebug {
+		return &http.Client{
+			Transport: &LoggingRoundTripper{
+				Log:      log,
+				Delegate: transport,
+			},
+		}, nil
+
+	}
+
+	return &http.Client{Transport: transport}, nil
+}
diff --git a/internal/http/logging.go b/internal/http/logging.go
new file mode 100644
index 0000000..aceaa4f
--- /dev/null
+++ b/internal/http/logging.go
@@ -0,0 +1,51 @@
+// Copyright 2024 Tetrate
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+// Copyright (c) Tetrate, Inc 2024 All Rights Reserved.
+
+package http
+
+import (
+	"net/http"
+	"net/http/httputil"
+
+	"github.com/tetratelabs/telemetry"
+)
+
+// LoggingRoundTripper is a http.RoundTripper that logs requests and responses.
+type LoggingRoundTripper struct {
+	Log      telemetry.Logger
+	Delegate http.RoundTripper
+}
+
+// RoundTrip logs all the requests and responses using the configured settings.
+func (l LoggingRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
+	if l.Log.Level() < telemetry.LevelDebug {
+		return l.Delegate.RoundTrip(req)
+	}
+
+	if dump, derr := httputil.DumpRequest(req, true); derr == nil {
+		l.Log.Debug("request", "data", string(dump))
+	}
+
+	res, err := l.Delegate.RoundTrip(req)
+
+	if err == nil {
+		if dump, derr := httputil.DumpResponse(res, true); derr == nil {
+			l.Log.Debug("response", "data", string(dump))
+		}
+	}
+
+	return res, err
+}
diff --git a/internal/logging.go b/internal/logging.go
index 28f9926..5c18870 100644
--- a/internal/logging.go
+++ b/internal/logging.go
@@ -32,6 +32,7 @@ const (
 	Config   = "config"
 	Default  = "default"
 	Health   = "health"
+	IDP      = "idp"
 	JWKS     = "jwks"
 	Requests = "requests"
 	Server   = "server"
@@ -45,6 +46,7 @@ var scopes = map[string]string{
 	Config:   "Configuration messages",
 	Default:  "Default",
 	Health:   "Health server messages",
+	IDP:      "Identity provider requests/responses",
 	JWKS:     "JWKS update and parse messages",
 	Requests: "Logs all requests and responses received by the server",
 	Server:   "Server request handling messages",
@@ -158,14 +160,15 @@ func setLogLevels(log telemetry.Logger, logLevelMap map[string]telemetry.Level)
 		for _, logger := range scope.List() {
 			logger.SetLevel(level)
 		}
-	} else {
-		for k, l := range logLevelMap {
-			logger, ok := scope.Find(k)
-			if ok {
-				logger.SetLevel(l)
-			} else {
-				log.Info("invalid logger", "logger", k)
-			}
+		delete(logLevelMap, "all")
+	}
+
+	for k, l := range logLevelMap {
+		logger, ok := scope.Find(k)
+		if ok {
+			logger.SetLevel(l)
+		} else {
+			log.Info("invalid logger", "logger", k)
 		}
 	}
 }
diff --git a/internal/oidc/discovery.go b/internal/oidc/discovery.go
index 71f0682..8ea03e0 100644
--- a/internal/oidc/discovery.go
+++ b/internal/oidc/discovery.go
@@ -40,8 +40,20 @@ type WellKnownConfig struct {
 	TokenRevocationEndpoint  string   `json:"token_revocation_endpoint"`
 }
 
+var (
+	// wellKnownConfigs is a map of issuer URL to the OIDC well-known configuration
+	// It is used to cache well-known configurations as they usually don't change. URLs are usually stable, and the only
+	// things that are subject to change are the signing keys, but those are already watched periodically by the JWKS fetcher.
+	wellKnownConfigs = make(map[string]WellKnownConfig)
+)
+
 // GetWellKnownConfig retrieves the OIDC well-known configuration from the given issuer URL.
 func GetWellKnownConfig(client *http.Client, url string) (WellKnownConfig, error) {
+	cfg, ok := wellKnownConfigs[url]
+	if ok {
+		return cfg, nil
+	}
+
 	// Make a GET request to the well-known configuration endpoint
 	response, err := client.Get(url)
 	if err != nil {
@@ -55,10 +67,10 @@ func GetWellKnownConfig(client *http.Client, url string) (WellKnownConfig, error
 	}
 
 	// Decode the JSON response into the OIDCConfig struct
-	var cfg WellKnownConfig
 	if err = json.NewDecoder(response.Body).Decode(&cfg); err != nil {
 		return WellKnownConfig{}, err
 	}
 
+	wellKnownConfigs[url] = cfg
 	return cfg, nil
 }
diff --git a/internal/oidc/jwks.go b/internal/oidc/jwks.go
index d79b69f..5e9eaac 100644
--- a/internal/oidc/jwks.go
+++ b/internal/oidc/jwks.go
@@ -18,7 +18,6 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"net/http"
 	"time"
 
 	"github.com/lestrrat-go/httprc"
@@ -29,6 +28,7 @@ import (
 	configv1 "github.com/istio-ecosystem/authservice/config/gen/go/v1"
 	oidcv1 "github.com/istio-ecosystem/authservice/config/gen/go/v1/oidc"
 	"github.com/istio-ecosystem/authservice/internal"
+	inthttp "github.com/istio-ecosystem/authservice/internal/http"
 )
 
 var (
@@ -102,14 +102,11 @@ func (j *DefaultJWKSProvider) fetchDynamic(ctx context.Context, config *oidcv1.O
 	jwksConfig := config.GetJwksFetcher()
 
 	if !j.cache.IsRegistered(jwksConfig.JwksUri) {
-		transport := http.DefaultTransport.(*http.Transport).Clone()
-
-		var err error
-		if transport.TLSClientConfig, err = j.tlsPool.LoadTLSConfig(config); err != nil {
-			return nil, fmt.Errorf("error loading TLS config: %w", err)
+		client, err := inthttp.NewHTTPClient(config, j.tlsPool, internal.Logger(internal.IDP))
+		if err != nil {
+			return nil, err
 		}
 
-		client := &http.Client{Transport: transport}
 		refreshInterval := time.Duration(jwksConfig.PeriodicFetchIntervalSec) * time.Second
 		if refreshInterval == 0 {
 			refreshInterval = DefaultFetchInterval
diff --git a/internal/oidc/memory.go b/internal/oidc/memory.go
index d9b8756..b362350 100644
--- a/internal/oidc/memory.go
+++ b/internal/oidc/memory.go
@@ -70,6 +70,7 @@ func (m *memoryStore) GetTokenResponse(ctx context.Context, sessionID string) (*
 		return nil, nil
 	}
 
+	log.Debug("token response", "token_response", s.tokenResponse)
 	s.accessed = m.clock.Now()
 	return s.tokenResponse, nil
 }
@@ -96,6 +97,7 @@ func (m *memoryStore) GetAuthorizationState(ctx context.Context, sessionID strin
 		return nil, nil
 	}
 
+	log.Debug("authorization state", "state", s.authorizationState)
 	s.accessed = m.clock.Now()
 	return s.authorizationState, nil
 }
diff --git a/internal/oidc/redis.go b/internal/oidc/redis.go
index ce8c816..6033631 100644
--- a/internal/oidc/redis.go
+++ b/internal/oidc/redis.go
@@ -152,6 +152,8 @@ func (r *redisStore) GetTokenResponse(ctx context.Context, sessionID string) (*T
 		return nil, err
 	}
 
+	log.Debug("token response", "token_response", tokenResponse)
+
 	return tokenResponse, nil
 }
 
@@ -199,6 +201,8 @@ func (r *redisStore) GetAuthorizationState(ctx context.Context, sessionID string
 		return nil, err
 	}
 
+	log.Debug("authorization state", "state", state.AuthorizationState())
+
 	return state.AuthorizationState(), nil
 }
 


Test patch:
diff --git a/e2e/istio/istio_test.go b/e2e/istio/istio_test.go
index 04a3c2b..97c8165 100644
--- a/e2e/istio/istio_test.go
+++ b/e2e/istio/istio_test.go
@@ -39,7 +39,7 @@ func (i *IstioSuite) TestIstioEnforcement() {
 			// Initialize the test OIDC client that will keep track of the state of the OIDC login process
 			// Initialize it for each test to not reuse the session between them
 			client, err := e2e.NewOIDCTestClient(
-				e2e.WithLoggingOptions(i.T().Log, true),
+				e2e.WithLoggingOptions(i.T().Log),
 				e2e.WithCustomCA(testCAFile),
 				// Map the keycloak cluster DNS name to the local address where the service is exposed
 				e2e.WithCustomAddressMappings(map[string]string{
diff --git a/e2e/keycloak/keycloak_test.go b/e2e/keycloak/keycloak_test.go
index 1f28443..ab5bd4b 100644
--- a/e2e/keycloak/keycloak_test.go
+++ b/e2e/keycloak/keycloak_test.go
@@ -51,7 +51,7 @@ var (
 func TestOIDCUsesTheConfiguredProxy(t *testing.T) {
 	client, err := e2e.NewOIDCTestClient(
 		e2e.WithCustomCA(testCAFile),
-		e2e.WithLoggingOptions(t.Log, true),
+		e2e.WithLoggingOptions(t.Log),
 		e2e.WithCustomAddressMappings(customAddressMappings),
 	)
 	require.NoError(t, err)
@@ -82,7 +82,7 @@ func TestOIDC(t *testing.T) {
 	// Initialize the test OIDC client that will keep track of the state of the OIDC login process
 	client, err := e2e.NewOIDCTestClient(
 		e2e.WithCustomCA(testCAFile),
-		e2e.WithLoggingOptions(t.Log, true),
+		e2e.WithLoggingOptions(t.Log),
 		e2e.WithCustomAddressMappings(customAddressMappings),
 	)
 	require.NoError(t, err)
@@ -109,7 +109,7 @@ func TestOIDCRefreshTokens(t *testing.T) {
 	// Initialize the test OIDC client that will keep track of the state of the OIDC login process
 	client, err := e2e.NewOIDCTestClient(
 		e2e.WithCustomCA(testCAFile),
-		e2e.WithLoggingOptions(t.Log, true),
+		e2e.WithLoggingOptions(t.Log),
 		e2e.WithCustomAddressMappings(customAddressMappings),
 	)
 	require.NoError(t, err)
@@ -163,7 +163,7 @@ func TestOIDCLogout(t *testing.T) {
 	// Initialize the test OIDC client that will keep track of the state of the OIDC login process
 	client, err := e2e.NewOIDCTestClient(
 		e2e.WithCustomCA(testCAFile),
-		e2e.WithLoggingOptions(t.Log, true),
+		e2e.WithLoggingOptions(t.Log),
 		e2e.WithBaseURL(idpBaseURLHost),
 		e2e.WithCustomAddressMappings(customAddressMappings),
 	)
diff --git a/e2e/legacy/legacy_test.go b/e2e/legacy/legacy_test.go
index 42a7d1d..d13c08a 100644
--- a/e2e/legacy/legacy_test.go
+++ b/e2e/legacy/legacy_test.go
@@ -51,7 +51,7 @@ func TestOIDC(t *testing.T) {
 	// Initialize the test OIDC client that will keep track of the state of the OIDC login process
 	client, err := e2e.NewOIDCTestClient(
 		e2e.WithCustomCA(testCAFile),
-		e2e.WithLoggingOptions(t.Log, true),
+		e2e.WithLoggingOptions(t.Log),
 		e2e.WithCustomAddressMappings(customAddressMappings),
 	)
 	require.NoError(t, err)
@@ -78,7 +78,7 @@ func TestOIDCRefreshTokens(t *testing.T) {
 	// Initialize the test OIDC client that will keep track of the state of the OIDC login process
 	client, err := e2e.NewOIDCTestClient(
 		e2e.WithCustomCA(testCAFile),
-		e2e.WithLoggingOptions(t.Log, true),
+		e2e.WithLoggingOptions(t.Log),
 		e2e.WithCustomAddressMappings(customAddressMappings),
 	)
 	require.NoError(t, err)
@@ -131,7 +131,7 @@ func TestOIDCLogout(t *testing.T) {
 	// Initialize the test OIDC client that will keep track of the state of the OIDC login process
 	client, err := e2e.NewOIDCTestClient(
 		e2e.WithCustomCA(testCAFile),
-		e2e.WithLoggingOptions(t.Log, true),
+		e2e.WithLoggingOptions(t.Log),
 		e2e.WithBaseURL(idpBaseURLHost),
 		e2e.WithCustomAddressMappings(customAddressMappings),
 	)
diff --git a/e2e/testclient.go b/e2e/testclient.go
index 950d3c4..7b2509e 100644
--- a/e2e/testclient.go
+++ b/e2e/testclient.go
@@ -22,38 +22,17 @@ import (
 	"io"
 	"net"
 	"net/http"
-	"net/http/httputil"
 	"net/url"
 	"os"
+	"slices"
 	"strings"
 
+	"github.com/tetratelabs/telemetry"
+	"github.com/tetratelabs/telemetry/function"
 	"golang.org/x/net/html"
-)
-
-// LoggingRoundTripper is a http.RoundTripper that logs requests and responses.
-type LoggingRoundTripper struct {
-	LogFunc  func(...any)
-	LogBody  bool
-	Delegate http.RoundTripper
-}
-
-// RoundTrip logs all the requests and responses using the configured settings.
-func (l LoggingRoundTripper) RoundTrip(req *http.Request) (*http.Response, error) {
-	if l.LogFunc != nil {
-		if dump, derr := httputil.DumpRequest(req, l.LogBody); derr == nil {
-			l.LogFunc(string(dump))
-		}
-	}
 
-	res, err := l.Delegate.RoundTrip(req)
-	if err == nil && l.LogFunc != nil {
-		if dump, derr := httputil.DumpResponse(res, l.LogBody); derr == nil {
-			l.LogFunc(string(dump))
-		}
-	}
-
-	return res, err
-}
+	inthttp "github.com/istio-ecosystem/authservice/internal/http"
+)
 
 // CookieTracker is a http.RoundTripper that tracks cookies received from the server.
 type CookieTracker struct {
@@ -91,7 +70,6 @@ type OIDCTestClient struct {
 	customCA     *x509.CertPool   // Custom TLS configuration, if needed
 	mappings     *AddressMappings // Custom address mappings
 	logFunc      func(...any)     // Logging function to log all requests and responses
-	logBody      bool             // Whether to log the request and response bodies
 }
 
 // Option is a functional option for configuring the OIDCTestClient.
@@ -113,10 +91,9 @@ func WithCustomCA(caCert string) Option {
 }
 
 // WithLoggingOptions configures the OIDCTestClient to log requests and responses.
-func WithLoggingOptions(logFunc func(...any), logBody bool) Option {
+func WithLoggingOptions(logFunc func(...any)) Option {
 	return func(o *OIDCTestClient) error {
 		o.logFunc = logFunc
-		o.logBody = logBody
 		return nil
 	}
 }
@@ -171,7 +148,7 @@ func WithBaseURL(idpBaseURL string) Option {
 func NewOIDCTestClient(opts ...Option) (*OIDCTestClient, error) {
 	var (
 		defaultTransport = http.DefaultTransport.(*http.Transport).Clone()
-		logging          = &LoggingRoundTripper{Delegate: defaultTransport}
+		logging          = &inthttp.LoggingRoundTripper{Delegate: defaultTransport}
 		cookieTracker    = &CookieTracker{Cookies: make(map[string]*http.Cookie), Delegate: logging}
 		client           = &OIDCTestClient{http: &http.Client{Transport: cookieTracker}}
 	)
@@ -182,8 +159,11 @@ func NewOIDCTestClient(opts ...Option) (*OIDCTestClient, error) {
 		}
 	}
 
-	logging.LogFunc = client.logFunc
-	logging.LogBody = client.logBody
+	logging.Log = function.NewLogger(func(_ telemetry.Level, msg string, _ error, values function.Values) {
+		args := append([]any{msg}, slices.Concat(values.FromMethod, values.FromContext, values.FromLogger)...)
+		client.logFunc(args...)
+	})
+	logging.Log.SetLevel(telemetry.LevelDebug)
 
 	defaultTransport.TLSClientConfig = &tls.Config{RootCAs: client.customCA}
 	if client.mappings != nil {
diff --git a/internal/authz/oidc_test.go b/internal/authz/oidc_test.go
index 1956e68..c54a4e1 100644
--- a/internal/authz/oidc_test.go
+++ b/internal/authz/oidc_test.go
@@ -1370,7 +1370,7 @@ func TestAreTokensExpired(t *testing.T) {
 				tokResp.AccessTokenExpiresAt = tt.accessTokenExpiration
 			}
 
-			got, err := h.(*oidcHandler).areRequiredTokensExpired(tokResp)
+			got, err := h.(*oidcHandler).areRequiredTokensExpired(h.(*oidcHandler).log, tokResp)
 			require.NoError(t, err)
 			require.Equal(t, tt.want, got)
 		})
@@ -1396,6 +1396,7 @@ func TestLoadWellKnownConfigMissingLogoutRedirectURI(t *testing.T) {
 	t.Cleanup(idpServer.Stop)
 
 	cfg := proto.Clone(dynamicOIDCConfig).(*oidcv1.OIDCConfig)
+	cfg.ConfigurationUri = "http://missing-logout/.well-known/openid-configuration"
 	require.ErrorIs(t, loadWellKnownConfig(idpServer.newHTTPClient(), cfg), ErrMissingLogoutRedirectURI)
 }
 
@@ -1403,6 +1404,7 @@ func TestLoadWellKnownConfigError(t *testing.T) {
 	clock := oidc.Clock{}
 	tlsPool := internal.NewTLSConfigPool(context.Background())
 	cfg := proto.Clone(dynamicOIDCConfig).(*oidcv1.OIDCConfig)
+	cfg.ConfigurationUri = "http://stopped-server/.well-known/openid-configuration"
 	sessions := &mockSessionStoreFactory{store: oidc.NewMemoryStore(&clock, time.Hour, time.Hour)}
 	_, err := NewOIDCHandler(cfg, tlsPool, oidc.NewJWKSProvider(newConfigFor(basicOIDCConfig), tlsPool),
 		sessions, clock, oidc.NewStaticGenerator(newSessionID, newNonce, newState))
diff --git a/internal/http/http_test.go b/internal/http/http_test.go
index 2a79502..4e2c6fe 100644
--- a/internal/http/http_test.go
+++ b/internal/http/http_test.go
@@ -15,10 +15,17 @@
 package http
 
 import (
+	"context"
 	"encoding/base64"
+	"net/http"
 	"testing"
 
 	"github.com/stretchr/testify/require"
+	"github.com/tetratelabs/telemetry"
+	"google.golang.org/protobuf/types/known/structpb"
+
+	oidcv1 "github.com/istio-ecosystem/authservice/config/gen/go/v1/oidc"
+	"github.com/istio-ecosystem/authservice/internal"
 )
 
 func TestGetPathQueryFragment(t *testing.T) {
@@ -132,3 +139,53 @@ func TestBasicAuthHeader(t *testing.T) {
 		})
 	}
 }
+
+func TestNewHTTPClient(t *testing.T) {
+	t.Run("proxy-skip-verify", func(t *testing.T) {
+		cfg := &oidcv1.OIDCConfig{
+			ProxyUri:           "http://localhost:8080",
+			SkipVerifyPeerCert: &structpb.Value{Kind: &structpb.Value_BoolValue{BoolValue: true}},
+		}
+		pool := internal.NewTLSConfigPool(context.Background())
+
+		client, err := NewHTTPClient(cfg, pool, nil)
+		require.NoError(t, err)
+		require.IsType(t, &http.Transport{}, client.Transport)
+		require.NotNil(t, client.Transport.(*http.Transport).Proxy)
+		require.True(t, client.Transport.(*http.Transport).TLSClientConfig.InsecureSkipVerify)
+	})
+
+	t.Run("invalid-tls", func(t *testing.T) {
+		cfg := &oidcv1.OIDCConfig{
+			TrustedCaConfig: &oidcv1.OIDCConfig_TrustedCertificateAuthorityFile{
+				TrustedCertificateAuthorityFile: "unexisting",
+			},
+		}
+		pool := internal.NewTLSConfigPool(context.Background())
+
+		_, err := NewHTTPClient(cfg, pool, nil)
+		require.Error(t, err)
+	})
+
+	t.Run("disabled-logger", func(t *testing.T) {
+		cfg := &oidcv1.OIDCConfig{}
+		pool := internal.NewTLSConfigPool(context.Background())
+		log := telemetry.NoopLogger()
+		log.SetLevel(telemetry.LevelInfo)
+
+		client, err := NewHTTPClient(cfg, pool, log)
+		require.NoError(t, err)
+		require.IsType(t, &http.Transport{}, client.Transport)
+	})
+
+	t.Run("enabled-logger", func(t *testing.T) {
+		cfg := &oidcv1.OIDCConfig{}
+		pool := internal.NewTLSConfigPool(context.Background())
+		log := telemetry.NoopLogger()
+		log.SetLevel(telemetry.LevelDebug)
+
+		client, err := NewHTTPClient(cfg, pool, log)
+		require.NoError(t, err)
+		require.IsType(t, &LoggingRoundTripper{}, client.Transport)
+	})
+}
diff --git a/internal/http/logging_test.go b/internal/http/logging_test.go
new file mode 100644
index 0000000..8a3c9d6
--- /dev/null
+++ b/internal/http/logging_test.go
@@ -0,0 +1,101 @@
+// Copyright 2024 Tetrate
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+// Copyright (c) Tetrate, Inc 2024 All Rights Reserved.
+
+package http
+
+import (
+	"bufio"
+	"net/http"
+	"strings"
+	"testing"
+
+	"github.com/stretchr/testify/require"
+	"github.com/tetratelabs/telemetry"
+	"github.com/tetratelabs/telemetry/function"
+)
+
+const (
+	request  = "POST / HTTP/1.1\r\nHost: example.com\r\n\r\nreq body"
+	response = "HTTP/1.1 200 OK\r\nConnection: close\r\n\r\nresp body"
+)
+
+func TestLoggingRoundTripper(t *testing.T) {
+	var (
+		rt  = &recordedRoundTrip{logs: make([]logEntry, 0)}
+		lrt = LoggingRoundTripper{
+			Log: function.NewLogger(rt.log),
+			Delegate: roundTripperFunc(func(req *http.Request) (*http.Response, error) {
+				return http.ReadResponse(bufio.NewReader(strings.NewReader(response)), req)
+			}),
+		}
+	)
+
+	tests := []struct {
+		name  string
+		level telemetry.Level
+		want  []logEntry
+	}{
+		{"no-debug", telemetry.LevelInfo, []logEntry{}},
+		{"debug", telemetry.LevelDebug, []logEntry{
+			{
+				level:  telemetry.LevelDebug,
+				msg:    "request",
+				values: []any{"data", request},
+			},
+			{
+				level:  telemetry.LevelDebug,
+				msg:    "response",
+				values: []any{"data", response},
+			},
+		}},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			lrt.Log.SetLevel(tt.level)
+			req, err := http.NewRequest("POST", "http://example.com", strings.NewReader("req body"))
+			require.NoError(t, err)
+
+			_, err = lrt.RoundTrip(req)
+			require.NoError(t, err)
+			require.Equal(t, tt.want, rt.logs)
+		})
+	}
+}
+
+type roundTripperFunc func(req *http.Request) (*http.Response, error)
+
+func (fn roundTripperFunc) RoundTrip(req *http.Request) (*http.Response, error) {
+	return fn(req)
+}
+
+type recordedRoundTrip struct {
+	logs []logEntry
+}
+
+type logEntry struct {
+	level  telemetry.Level
+	msg    string
+	values []any
+}
+
+func (r *recordedRoundTrip) log(level telemetry.Level, msg string, _ error, values function.Values) {
+	r.logs = append(r.logs, logEntry{
+		level:  level,
+		msg:    msg,
+		values: values.FromMethod,
+	})
+}
diff --git a/internal/logging_test.go b/internal/logging_test.go
index 5a15d97..8d2b788 100644
--- a/internal/logging_test.go
+++ b/internal/logging_test.go
@@ -59,7 +59,7 @@ func TestLoggingSetup(t *testing.T) {
 		{"l1:debug", telemetry.LevelDebug, telemetry.LevelInfo, false},
 		{"l1:debug,l2:debug", telemetry.LevelDebug, telemetry.LevelDebug, false},
 		{"invalid:debug,l2:error", telemetry.LevelInfo, telemetry.LevelError, false},
-		{"all:none,l1:debug", telemetry.LevelNone, telemetry.LevelNone, false},
+		{"all:none,l1:debug", telemetry.LevelDebug, telemetry.LevelNone, false},
 		{"", telemetry.LevelInfo, telemetry.LevelInfo, false},
 		{",", telemetry.LevelInfo, telemetry.LevelInfo, true},
 		{":", telemetry.LevelInfo, telemetry.LevelInfo, true},
diff --git a/internal/oidc/discovery_test.go b/internal/oidc/discovery_test.go
index c966578..10bc981 100644
--- a/internal/oidc/discovery_test.go
+++ b/internal/oidc/discovery_test.go
@@ -53,7 +53,7 @@ func TestWellKnownConfig(t *testing.T) {
 		{"ok", "http://example.com/.well-known/openid-configuration", validWellKnownJSON, false, validWellKnown},
 		{"not-found", "http://example.com/not-found", validWellKnownJSON, true, WellKnownConfig{}},
 		{"invalid-url", "invalid", validWellKnownJSON, true, WellKnownConfig{}},
-		{"invalid-json", "http://example.com/.well-known/openid-configuration", invalidWellKnownJSON, true, WellKnownConfig{}},
+		{"invalid-json", "http://example2.com/.well-known/openid-configuration", invalidWellKnownJSON, true, WellKnownConfig{}},
 	}
 
 	for _, tt := range tests {
@@ -74,6 +74,25 @@ func TestWellKnownConfig(t *testing.T) {
 	}
 }
 
+func TestWellKnownConfigCache(t *testing.T) {
+	s := newServer()
+	s.wellKnownConfig = validWellKnownJSON
+	s.Start()
+	c := s.newHTTPClient()
+
+	got, err := GetWellKnownConfig(c, "http://example.com/.well-known/openid-configuration")
+	require.NoError(t, err)
+	require.Equal(t, validWellKnown, got)
+
+	// Stop the server and run the well-known request again.
+	// It should succeed and return the cached value.
+	s.Stop()
+
+	got, err = GetWellKnownConfig(c, "http://example.com/.well-known/openid-configuration")
+	require.NoError(t, err)
+	require.Equal(t, validWellKnown, got)
+}
+
 type idpServer struct {
 	server          *http.Server
 	listener        *bufconn.Listener