APIGOV-33018 - optionally log request and response bodies for IdP api calls

pkg/agent/handler/credential_test.go

@@ -1031,6 +1031,7 @@ func createIDPConfig(s oauth.MockIDPServer) *config.IDPConfiguration {
 		AuthMethod:       config.ClientSecretBasic,
 		AuthResponseType: oauth.AuthResponseToken,
 		ExtraProperties:  config.ExtraProperties{"key": "value"},
+		LoggerOptions:    &config.IDPLoggerOptions{},
 	}
 }
 
@@ -1069,9 +1070,9 @@ func TestExternalCredentialOnPending(t *testing.T) {
 			}
 
 			p := &mockExternalCredProv{
-				t:             t,
+				t:              t,
 				expectedStatus: expectedStatus,
-				provisionErr:  tc.provisionErr,
+				provisionErr:   tc.provisionErr,
 			}
 
 			c := &credClient{

pkg/agent/idplifecycle_test.go

@@ -19,8 +19,8 @@ import (
 )
 
 const (
-	testEnvName = "test-env"
-	testIDPName = "test-idp"
+	testEnvName     = "test-env"
+	testIDPName     = "test-idp"
 	existingIDPName = "existing-idp"
 )
 
@@ -75,6 +75,7 @@ func makeIDPConfig(metadataURL string) *config.IDPConfiguration {
 		ClientScopes:     "read",
 		AuthMethod:       config.ClientSecretBasic,
 		AuthResponseType: oauth.AuthResponseToken,
+		LoggerOptions:    &config.IDPLoggerOptions{},
 	}
 }
 

pkg/agent/provisioning_test.go

@@ -84,6 +84,7 @@ func TestNewCredentialRequestBuilder(t *testing.T) {
 					AuthMethod:       config.ClientSecretBasic,
 					AuthResponseType: "token",
 					ExtraProperties:  config.ExtraProperties{"key": "value"},
+					LoggerOptions:    &config.IDPLoggerOptions{},
 				}
 
 				p, _ := oauth.NewProvider(cfg, config.NewTLSConfig(), "", 30*time.Second)

pkg/api/client.go

@@ -31,6 +31,11 @@ const (
 	responseBufferSize = 2048
 )
 
+type RequestOptions struct {
+	LogReqBody bool
+	LogResBody bool
+}
+
 // Request - the request object used when communicating to an API
 type Request struct {
 	Method      string
@@ -39,6 +44,7 @@ type Request struct {
 	Headers     map[string]string
 	Body        []byte
 	FormData    map[string]string
+	Options     RequestOptions
 }
 
 // Response - the response object given back when communicating to an API
@@ -311,6 +317,7 @@ func (c *httpClient) Send(request Request) (*Response, error) {
 	// Logging for the HTTP request
 	statusCode := 0
 	receivedData := int64(0)
+	responseBody := []byte{}
 	defer func() {
 		duration := time.Since(startTime)
 		targetURL := req.URL.String()
@@ -336,6 +343,14 @@ func (c *httpClient) Send(request Request) (*Response, error) {
 			logger = logger.WithField("received(bytes)", receivedData)
 		}
 
+		if request.Options.LogReqBody && len(request.Body) > 0 {
+			logger = logger.WithField("requestBody", string(request.Body))
+		}
+
+		if request.Options.LogResBody && len(responseBody) > 0 {
+			logger = logger.WithField("responseBody", string(responseBody))
+		}
+
 		if err != nil {
 			logger.WithError(err).
 				Trace("request failed")
@@ -365,5 +380,9 @@ func (c *httpClient) Send(request Request) (*Response, error) {
 	receivedData = res.ContentLength
 	parseResponse, err := c.prepareAPIResponse(res, timer)
 
+	if responseBody != nil {
+		responseBody = parseResponse.Body
+	}
+
 	return parseResponse, err
 }

pkg/apic/provisioning/idp/provisioner_test.go

@@ -32,9 +32,10 @@ func TestProvisioner(t *testing.T) {
 			ClientSecret:         "test",
 			UseRegistrationToken: true,
 		},
-		GrantType:   oauth.GrantTypeClientCredentials,
-		AuthMethod:  config.ClientSecretBasic,
-		MetadataURL: s.GetMetadataURL(),
+		GrantType:     oauth.GrantTypeClientCredentials,
+		AuthMethod:    config.ClientSecretBasic,
+		MetadataURL:   s.GetMetadataURL(),
+		LoggerOptions: &config.IDPLoggerOptions{},
 	}
 
 	s.SetMetadataResponseCode(http.StatusOK)

pkg/authz/oauth/idpregistry_test.go

@@ -63,11 +63,12 @@ func TestRegisterProviderWithMetadata(t *testing.T) {
 
 			reg := NewIdpRegistry()
 			idpCfg := &config.IDPConfiguration{
-				Name:        "test-idp",
-				MetadataURL: idpServer.GetMetadataURL(),
-				AuthConfig:  &config.IDPAuthConfiguration{Type: "client", ClientID: "id", ClientSecret: "secret"},
-				GrantType:   GrantTypeClientCredentials,
-				AuthMethod:  config.ClientSecretBasic,
+				Name:          "test-idp",
+				MetadataURL:   idpServer.GetMetadataURL(),
+				AuthConfig:    &config.IDPAuthConfiguration{Type: "client", ClientID: "id", ClientSecret: "secret"},
+				GrantType:     GrantTypeClientCredentials,
+				AuthMethod:    config.ClientSecretBasic,
+				LoggerOptions: &config.IDPLoggerOptions{},
 			}
 
 			err := reg.RegisterProviderWithMetadata(context.Background(), idpCfg, tc.metadata, config.NewTLSConfig(), "", 30*time.Second)

pkg/authz/oauth/oktaprovider_test.go

@@ -163,8 +163,9 @@ func oktaPolicyPutMustIncludeClientHandler(clientID string) http.HandlerFunc {
 
 func newIDPCredential(tsURL, group, policy string) *corecfg.IDPConfiguration {
 	credentialObj := &corecfg.IDPConfiguration{
-		MetadataURL: tsURL + oauthMetadataEndpoint,
-		AuthConfig:  &corecfg.IDPAuthConfiguration{AccessToken: accessToken},
+		MetadataURL:   tsURL + oauthMetadataEndpoint,
+		AuthConfig:    &corecfg.IDPAuthConfiguration{AccessToken: accessToken},
+		LoggerOptions: &corecfg.IDPLoggerOptions{},
 	}
 	if strings.TrimSpace(group) != "" || strings.TrimSpace(policy) != "" {
 		credentialObj.Okta = &corecfg.OktaIDPConfiguration{Group: group, Policy: policy}
@@ -325,9 +326,10 @@ func TestOktaPostProcessClientUnreg(t *testing.T) {
 			defer ts.Close()
 
 			credentialObj := &corecfg.IDPConfiguration{
-				MetadataURL: ts.URL + oauthMetadataEndpoint,
-				Okta:        &corecfg.OktaIDPConfiguration{Group: tc.oktaGroup},
-				AuthConfig:  &corecfg.IDPAuthConfiguration{AccessToken: accessToken},
+				MetadataURL:   ts.URL + oauthMetadataEndpoint,
+				Okta:          &corecfg.OktaIDPConfiguration{Group: tc.oktaGroup},
+				AuthConfig:    &corecfg.IDPAuthConfiguration{AccessToken: accessToken},
+				LoggerOptions: &corecfg.IDPLoggerOptions{},
 			}
 			err := oktaProvider.postProcessClientUnregister("app123", credentialObj, apiClient)
 			if tc.wantErr {
@@ -355,8 +357,9 @@ func TestOktaPostProcessClientRegUsesIDPAccessToken(t *testing.T) {
 	defer ts.Close()
 
 	credentialObj := &corecfg.IDPConfiguration{
-		MetadataURL: ts.URL + oauthMetadataEndpoint,
-		AuthConfig:  &corecfg.IDPAuthConfiguration{AccessToken: accessToken},
+		MetadataURL:   ts.URL + oauthMetadataEndpoint,
+		AuthConfig:    &corecfg.IDPAuthConfiguration{AccessToken: accessToken},
+		LoggerOptions: &corecfg.IDPLoggerOptions{},
 	}
 
 	apiClient := coreapi.NewClient(nil, "")

pkg/authz/oauth/provider.go

@@ -44,17 +44,18 @@ type Provider interface {
 }
 
 type provider struct {
-	logger             log.FieldLogger
-	cfg                corecfg.IDPConfig
-	metadataURL        string
-	extraProperties    map[string]interface{}
-	requestHeaders     map[string]string
-	queryParameters    map[string]string
-	apiClient          coreapi.Client
-	authServerMetadata *AuthorizationServerMetadata
-	authClient         AuthClient
-	idpType            typedIDP
-	idpResourceName    *string
+	logger                log.FieldLogger
+	cfg                   corecfg.IDPConfig
+	metadataURL           string
+	extraProperties       map[string]interface{}
+	requestHeaders        map[string]string
+	queryParameters       map[string]string
+	apiClient             coreapi.Client
+	authServerMetadata    *AuthorizationServerMetadata
+	authClient            AuthClient
+	idpType               typedIDP
+	idpResourceName       *string
+	logRequestAndResponse bool
 }
 
 type typedIDP interface {
@@ -103,16 +104,17 @@ func NewProvider(idp corecfg.IDPConfig, tlsCfg corecfg.TLSConfig, proxyURL strin
 
 	idpResourceName := new(string)
 	p := &provider{
-		logger:             logger,
-		metadataURL:        idp.GetMetadataURL(),
-		cfg:                idp,
-		extraProperties:    extraProps,
-		requestHeaders:     idp.GetRequestHeaders(),
-		queryParameters:    idp.GetQueryParams(),
-		apiClient:          apiClient,
-		idpType:            idpType,
-		authServerMetadata: pOpts.authServerMetadata,
-		idpResourceName:    idpResourceName,
+		logger:                logger,
+		metadataURL:           idp.GetMetadataURL(),
+		cfg:                   idp,
+		extraProperties:       extraProps,
+		requestHeaders:        idp.GetRequestHeaders(),
+		queryParameters:       idp.GetQueryParams(),
+		apiClient:             apiClient,
+		idpType:               idpType,
+		authServerMetadata:    pOpts.authServerMetadata,
+		idpResourceName:       idpResourceName,
+		logRequestAndResponse: idp.GetLoggingConfig().LogRequestResponse(),
 	}
 
 	if p.authServerMetadata == nil {
@@ -154,13 +156,17 @@ func NewProvider(idp corecfg.IDPConfig, tlsCfg corecfg.TLSConfig, proxyURL strin
 	return p, nil
 }
 
-func FetchMetadata(apiClient coreapi.Client, metadataURL string) (*AuthorizationServerMetadata, error) {
+func FetchMetadata(apiClient coreapi.Client, metadataURL string, logReqAndRes bool) (*AuthorizationServerMetadata, error) {
 	if apiClient == nil || metadataURL == "" {
 		return nil, errors.New("unexpected arguments")
 	}
 	request := coreapi.Request{
 		Method: coreapi.GET,
 		URL:    metadataURL,
+		Options: coreapi.RequestOptions{
+			LogReqBody: logReqAndRes,
+			LogResBody: logReqAndRes,
+		},
 	}
 
 	response, err := apiClient.Send(request)
@@ -178,7 +184,7 @@ func FetchMetadata(apiClient coreapi.Client, metadataURL string) (*Authorization
 }
 
 func (p *provider) fetchMetadata() (*AuthorizationServerMetadata, error) {
-	return FetchMetadata(p.apiClient, p.metadataURL)
+	return FetchMetadata(p.apiClient, p.metadataURL, p.logRequestAndResponse)
 }
 
 func (p *provider) createAuthClient() (AuthClient, error) {
@@ -374,6 +380,8 @@ func (p *provider) prepareHeaders(authPrefix, token string) map[string]string {
 
 // RegisterClient - register the OAuth client with IDP
 func (p *provider) RegisterClient(clientReq ClientMetadata) (ClientMetadata, error) {
+	logger := p.logger.WithField(logProvider, p.cfg.GetIDPName())
+
 	authPrefix := p.idpType.getAuthorizationHeaderPrefix()
 	err := p.enrichClientReq(clientReq)
 	if err != nil {
@@ -385,6 +393,19 @@ func (p *provider) RegisterClient(clientReq ClientMetadata) (ClientMetadata, err
 		return nil, err
 	}
 
+	logger = logger.
+		WithField("clientName", clientReq.GetClientName()).
+		WithField("grantType", clientReq.GetGrantTypes()).
+		WithField("tokenAuthMethod", clientReq.GetTokenEndpointAuthMethod())
+
+	if len(clientReq.GetScopes()) > 0 {
+		logger = logger.WithField("requestScopes", clientReq.GetScopes())
+	}
+
+	if len(clientReq.GetRedirectURIs()) > 0 {
+		logger = logger.WithField("requestRedirectURIs", clientReq.GetRedirectURIs())
+	}
+
 	token, err := p.getClientToken()
 	if err != nil {
 		return nil, err
@@ -396,8 +417,13 @@ func (p *provider) RegisterClient(clientReq ClientMetadata) (ClientMetadata, err
 		QueryParams: p.queryParameters,
 		Headers:     p.prepareHeaders(authPrefix, token),
 		Body:        clientBuffer,
+		Options: coreapi.RequestOptions{
+			LogReqBody: p.logRequestAndResponse,
+			LogResBody: p.logRequestAndResponse,
+		},
 	}
 
+	logger.Debug("requesting client")
 	response, err := p.apiClient.Send(request)
 	if err != nil {
 		return nil, err
@@ -414,15 +440,19 @@ func (p *provider) RegisterClient(clientReq ClientMetadata) (ClientMetadata, err
 			return nil, err
 		}
 
-		p.logger.
-			WithField(logProvider, p.cfg.GetIDPName()).
-			WithField("clientName", clientReq.GetClientName()).
-			WithField(logClientID, clientReq.GetClientID()).
-			WithField("grantType", clientReq.GetGrantTypes()).
-			WithField("tokenAuthMethod", clientReq.GetTokenEndpointAuthMethod()).
-			WithField("responseType", clientReq.GetResponseTypes()).
-			WithField("redirectURIs", clientReq.GetRedirectURIs()).
-			Info("registered client")
+		if len(clientRes.GetResponseTypes()) > 0 {
+			logger = logger.WithField("responseTypes", clientRes.GetResponseTypes())
+		}
+
+		if len(clientRes.GetScopes()) > 0 {
+			logger = logger.WithField("responseScopes", clientRes.GetScopes())
+		}
+
+		if len(clientRes.GetRedirectURIs()) > 0 {
+			logger = logger.WithField("responseRedirectURIs", clientRes.GetRedirectURIs())
+		}
+
+		logger.WithField(logClientID, clientRes.GetClientID()).Info("registered client")
 		return clientRes, err
 	}
 
@@ -659,6 +689,10 @@ func (p *provider) tryUnregister(unregisterURL, clientID, authPrefix, accessToke
 		URL:         unregisterURL,
 		QueryParams: queryParams,
 		Headers:     p.prepareHeaders(authPrefix, accessToken),
+		Options: coreapi.RequestOptions{
+			LogReqBody: p.logRequestAndResponse,
+			LogResBody: p.logRequestAndResponse,
+		},
 	}
 
 	response, err := p.apiClient.Send(request)

pkg/authz/oauth/provider_test.go

@@ -191,6 +191,7 @@ func runProviderTestCase(t *testing.T, tc providerTestCase) {
 		ExtraProperties: config.ExtraProperties{"key": "value"},
 		RequestHeaders:  tc.headers,
 		QueryParams:     tc.queryParams,
+		LoggerOptions:   &config.IDPLoggerOptions{},
 	}
 
 	s.SetMetadataResponseCode(tc.metadataResponseCode)
@@ -306,6 +307,7 @@ func TestNewProviderValidatesExtraProperties(t *testing.T) {
 					Type:        config.AccessToken,
 					AccessToken: testToken,
 				},
+				LoggerOptions: &config.IDPLoggerOptions{},
 			}
 
 			provider, err := NewProvider(idpCfg, config.NewTLSConfig(), "", 10*time.Second)
@@ -366,6 +368,7 @@ func TestNewProviderOktaValidatesConfiguredGroupAndPolicyExist(t *testing.T) {
 			Type:        config.AccessToken,
 			AccessToken: token,
 		},
+		LoggerOptions: &config.IDPLoggerOptions{},
 	}
 
 	p, err := NewProvider(idpCfg, config.NewTLSConfig(), "", 10*time.Second)
@@ -400,6 +403,7 @@ func TestNewProviderOktaFailsFastWhenConfiguredGroupMissing(t *testing.T) {
 			Type:        config.AccessToken,
 			AccessToken: token,
 		},
+		LoggerOptions: &config.IDPLoggerOptions{},
 	}
 
 	p, err := NewProvider(idpCfg, config.NewTLSConfig(), "", 10*time.Second)
@@ -490,6 +494,7 @@ func TestRegisterClientRollBack(t *testing.T) {
 					Type:        config.AccessToken,
 					AccessToken: testToken,
 				},
+				LoggerOptions: &config.IDPLoggerOptions{},
 			}
 
 			pIntf, err := NewProvider(idpCfg, config.NewTLSConfig(), "", 10*time.Second)
@@ -537,6 +542,7 @@ func TestUnregisterClientDeleteHookFails(t *testing.T) {
 			Type:        config.AccessToken,
 			AccessToken: testToken,
 		},
+		LoggerOptions: &config.IDPLoggerOptions{},
 	}
 
 	pIntf, err := NewProvider(idpCfg, config.NewTLSConfig(), "", 10*time.Second)
@@ -580,6 +586,7 @@ func TestUnregisterClientCleanupAndDeleteFail(t *testing.T) {
 			Type:        config.AccessToken,
 			AccessToken: testToken,
 		},
+		LoggerOptions: &config.IDPLoggerOptions{},
 	}
 
 	pIntf, err := NewProvider(idpCfg, config.NewTLSConfig(), "", 10*time.Second)