log outbound correlation data

pkg/api/correlation.go

@@ -1,12 +1,22 @@
 package api
 
 import (
+	"context"
+	"net/http"
 	"time"
+
+	"github.com/Azure/ARO-RP/pkg/util/uuid"
 )
 
 // Copyright (c) Microsoft Corporation.
 // Licensed under the Apache License 2.0.
 
+type contextKey int
+
+const (
+	contextKeyCorrelationData contextKey = iota
+)
+
 // CorrelationData represents any data, used for metrics or tracing.
 // More on these values:
 // https://github.com/Azure/azure-resource-manager-rpc/blob/master/v1.0/common-api-details.md
@@ -17,6 +27,9 @@ type CorrelationData struct {
 	// ClientRequestID contains value of x-ms-client-request-id
 	ClientRequestID string `json:"clientRequestId,omitempty"`
 
+	// OperationID contains the unique ID generated for each operation that the ARO-RP performs
+	OperationID string `json:"operationID,omitempty"`
+
 	// RequestID contains value of x-ms-request-id
 	RequestID string `json:"requestID,omitempty"`
 
@@ -26,3 +39,31 @@ type CorrelationData struct {
 	// RequestTime is the time that the request was received
 	RequestTime time.Time `json:"requestTime,omitempty"`
 }
+
+func ContextWithCorrelationData(ctx context.Context, correlationData *CorrelationData) context.Context {
+	return context.WithValue(ctx, contextKeyCorrelationData, correlationData)
+}
+
+func GetCorrelationDataFromCtx(ctx context.Context) *CorrelationData {
+	correlationData, ok := ctx.Value(contextKeyCorrelationData).(*CorrelationData)
+	if !ok {
+		return nil
+	}
+	return correlationData
+}
+
+func CreateCorrelationDataFromReq(req *http.Request) *CorrelationData {
+	if req == nil {
+		return nil
+	}
+
+	h := req.Header
+	dg := uuid.DefaultGenerator
+
+	return &CorrelationData{
+		ClientRequestID: h.Get("X-Ms-Client-Request-Id"),
+		CorrelationID:   h.Get("X-Ms-Correlation-Request-Id"),
+		RequestID:       dg.Generate(),
+		OperationID:     dg.Generate(),
+	}
+}

pkg/deploy/generator/scripts/rpVMSS.sh

@@ -163,6 +163,18 @@ cat >/etc/fluentbit/fluentbit.conf <<'EOF'
 	Match journald
 	Rule $LOGKIND ifxaudit ifxaudit false
 
+[FILTER]
+	Name rewrite_tag
+	Match journald
+	Rule $LOGKIND outboundRequests outboundRequests false
+
+[FILTER]
+	Name modify
+	Match  outboundRequests
+	Remove CLIENT_PRINCIPAL_NAME
+	Remove FILE
+	Remove COMPONENT
+
 [OUTPUT]
 	Name forward
 	Match *

pkg/frontend/clustermanager_putorpatch.go

@@ -55,7 +55,7 @@ func (f *frontend) putOrPatchClusterManagerConfiguration(w http.ResponseWriter,
 
 func (f *frontend) _putOrPatchSyncSet(ctx context.Context, log *logrus.Entry, r *http.Request, header *http.Header, converter api.SyncSetConverter, staticValidator api.ClusterManagerStaticValidator) ([]byte, error) {
 	body := r.Context().Value(middleware.ContextKeyBody).([]byte)
-	correlationData := r.Context().Value(middleware.ContextKeyCorrelationData).(*api.CorrelationData)
+	correlationData := api.GetCorrelationDataFromCtx(r.Context())
 	systemData, _ := r.Context().Value(middleware.ContextKeySystemData).(*api.SystemData) // don't panic
 	resType, resName, resGroupName := chi.URLParam(r, "resourceType"), chi.URLParam(r, "resourceName"), chi.URLParam(r, "resourceGroupName")
 	ocmResourceType, ocmResourceName := chi.URLParam(r, "ocmResourceType"), chi.URLParam(r, "ocmResourceName")
@@ -127,7 +127,7 @@ func (f *frontend) _putOrPatchSyncSet(ctx context.Context, log *logrus.Entry, r
 
 func (f *frontend) _putOrPatchMachinePool(ctx context.Context, log *logrus.Entry, r *http.Request, header *http.Header, converter api.MachinePoolConverter, staticValidator api.ClusterManagerStaticValidator) ([]byte, error) {
 	body := r.Context().Value(middleware.ContextKeyBody).([]byte)
-	correlationData := r.Context().Value(middleware.ContextKeyCorrelationData).(*api.CorrelationData)
+	correlationData := api.GetCorrelationDataFromCtx(r.Context())
 	systemData, _ := r.Context().Value(middleware.ContextKeySystemData).(*api.SystemData) // don't panic
 	resType, resName, resGroupName := chi.URLParam(r, "resourceType"), chi.URLParam(r, "resourceName"), chi.URLParam(r, "resourceGroupName")
 	ocmResourceType, ocmResourceName := chi.URLParam(r, "ocmResourceType"), chi.URLParam(r, "ocmResourceName")
@@ -200,7 +200,7 @@ func (f *frontend) _putOrPatchMachinePool(ctx context.Context, log *logrus.Entry
 
 func (f *frontend) _putOrPatchSyncIdentityProvider(ctx context.Context, log *logrus.Entry, r *http.Request, header *http.Header, converter api.SyncIdentityProviderConverter, staticValidator api.ClusterManagerStaticValidator) ([]byte, error) {
 	body := r.Context().Value(middleware.ContextKeyBody).([]byte)
-	correlationData := r.Context().Value(middleware.ContextKeyCorrelationData).(*api.CorrelationData)
+	correlationData := api.GetCorrelationDataFromCtx(r.Context())
 	systemData, _ := r.Context().Value(middleware.ContextKeySystemData).(*api.SystemData) // don't panic
 	resType, resName, resGroupName := chi.URLParam(r, "resourceType"), chi.URLParam(r, "resourceName"), chi.URLParam(r, "resourceGroupName")
 	ocmResourceType, ocmResourceName := chi.URLParam(r, "ocmResourceType"), chi.URLParam(r, "ocmResourceName")
@@ -273,7 +273,7 @@ func (f *frontend) _putOrPatchSyncIdentityProvider(ctx context.Context, log *log
 
 func (f *frontend) _putOrPatchSecret(ctx context.Context, log *logrus.Entry, r *http.Request, header *http.Header, converter api.SecretConverter, staticValidator api.ClusterManagerStaticValidator) ([]byte, error) {
 	body := r.Context().Value(middleware.ContextKeyBody).([]byte)
-	correlationData := r.Context().Value(middleware.ContextKeyCorrelationData).(*api.CorrelationData)
+	correlationData := api.GetCorrelationDataFromCtx(r.Context())
 	systemData, _ := r.Context().Value(middleware.ContextKeySystemData).(*api.SystemData) // don't panic
 	resType, resName, resGroupName := chi.URLParam(r, "resourceType"), chi.URLParam(r, "resourceName"), chi.URLParam(r, "resourceGroupName")
 	ocmResourceType, ocmResourceName := chi.URLParam(r, "ocmResourceType"), chi.URLParam(r, "ocmResourceName")

pkg/frontend/middleware/log.go

@@ -17,7 +17,6 @@ import (
 	"github.com/Azure/ARO-RP/pkg/api/admin"
 	utillog "github.com/Azure/ARO-RP/pkg/util/log"
 	"github.com/Azure/ARO-RP/pkg/util/log/audit"
-	"github.com/Azure/ARO-RP/pkg/util/uuid"
 )
 
 type logResponseWriter struct {
@@ -65,12 +64,8 @@ func (l LogMiddleware) Log(h http.Handler) http.Handler {
 		r.Body = &logReadCloser{ReadCloser: r.Body}
 		w = &logResponseWriter{ResponseWriter: w, statusCode: http.StatusOK}
 
-		correlationData := &api.CorrelationData{
-			ClientRequestID: r.Header.Get("X-Ms-Client-Request-Id"),
-			CorrelationID:   r.Header.Get("X-Ms-Correlation-Request-Id"),
-			RequestID:       uuid.DefaultGenerator.Generate(),
-			RequestTime:     t,
-		}
+		correlationData := api.CreateCorrelationDataFromReq(r)
+		correlationData.RequestTime = t
 
 		if r.URL.Query().Get(api.APIVersionKey) == admin.APIVersion || isAdminOp(r) {
 			correlationData.ClientPrincipalName = r.Header.Get("X-Ms-Client-Principal-Name")
@@ -88,7 +83,7 @@ func (l LogMiddleware) Log(h http.Handler) http.Handler {
 
 		ctx := r.Context()
 		ctx = context.WithValue(ctx, ContextKeyLog, log)
-		ctx = context.WithValue(ctx, ContextKeyCorrelationData, correlationData)
+		ctx = api.ContextWithCorrelationData(ctx, correlationData)
 
 		r = r.WithContext(ctx)
 

pkg/frontend/middleware/middleware.go

@@ -9,6 +9,5 @@ const (
 	ContextKeyLog contextKey = iota
 	ContextKeyOriginalPath
 	ContextKeyBody
-	ContextKeyCorrelationData
 	ContextKeySystemData
 )

pkg/frontend/openshiftcluster_delete.go

@@ -36,7 +36,7 @@ func (f *frontend) deleteOpenShiftCluster(w http.ResponseWriter, r *http.Request
 }
 
 func (f *frontend) _deleteOpenShiftCluster(ctx context.Context, r *http.Request, header *http.Header, doc *api.OpenShiftClusterDocument) error {
-	correlationData := r.Context().Value(middleware.ContextKeyCorrelationData).(*api.CorrelationData)
+	correlationData := api.GetCorrelationDataFromCtx(r.Context())
 
 	_, err := f.validateSubscriptionState(ctx, doc.Key, api.SubscriptionStateRegistered, api.SubscriptionStateWarned, api.SubscriptionStateSuspended)
 	if err != nil {

pkg/frontend/openshiftcluster_putorpatch.go

@@ -33,7 +33,7 @@ func (f *frontend) putOrPatchOpenShiftCluster(w http.ResponseWriter, r *http.Req
 	var b []byte
 
 	body := r.Context().Value(middleware.ContextKeyBody).([]byte)
-	correlationData := r.Context().Value(middleware.ContextKeyCorrelationData).(*api.CorrelationData)
+	correlationData := api.GetCorrelationDataFromCtx(r.Context())
 	systemData, _ := r.Context().Value(middleware.ContextKeySystemData).(*api.SystemData) // don't panic
 	originalPath := r.Context().Value(middleware.ContextKeyOriginalPath).(string)
 	referer := r.Header.Get("Referer")

pkg/util/azureclient/applens/applens_client_options.go

@@ -11,6 +11,8 @@ import (
 
 	"github.com/Azure/azure-sdk-for-go/sdk/azcore"
 	"github.com/Azure/azure-sdk-for-go/sdk/azcore/policy"
+
+	"github.com/Azure/ARO-RP/pkg/util/azureclient"
 )
 
 const (
@@ -23,6 +25,19 @@ type ClientOptions struct {
 }
 
 func NewClientOptions(certPool *x509.CertPool) *ClientOptions {
+	httpTransport := &http.Transport{
+		TLSNextProto: make(map[string]func(authority string, c *tls.Conn) http.RoundTripper),
+		TLSClientConfig: &tls.Config{
+			RootCAs: certPool,
+		},
+	}
+
+	customRoundTripper := azureclient.NewCustomRoundTripper(httpTransport)
+
+	httpClient := &http.Client{
+		Transport: customRoundTripper,
+	}
+
 	return &ClientOptions{
 		azcore.ClientOptions{
 			Retry: policy.RetryOptions{
@@ -39,14 +54,7 @@ func NewClientOptions(certPool *x509.CertPool) *ClientOptions {
 				ApplicationID: userAgent,
 				Disabled:      false,
 			},
-			Transport: &http.Client{
-				Transport: &http.Transport{
-					TLSNextProto: make(map[string]func(authority string, c *tls.Conn) http.RoundTripper),
-					TLSClientConfig: &tls.Config{
-						RootCAs: certPool,
-					},
-				},
-			},
+			Transport: httpClient,
 		},
 	}
 }

pkg/util/azureclient/authz/remotepdp/client.go

@@ -12,6 +12,8 @@ import (
 	"github.com/Azure/azure-sdk-for-go/sdk/azcore"
 	"github.com/Azure/azure-sdk-for-go/sdk/azcore/policy"
 	"github.com/Azure/azure-sdk-for-go/sdk/azcore/runtime"
+
+	"github.com/Azure/ARO-RP/pkg/util/azureclient"
 )
 
 // this asserts that &remotePDPClient{} would always implement RemotePDPClient
@@ -35,14 +37,21 @@ type remotePDPClient struct {
 func NewRemotePDPClient(endpoint, scope string, cred azcore.TokenCredential) *remotePDPClient {
 	authPolicy := runtime.NewBearerTokenPolicy(cred, []string{scope}, nil)
 
+	customRoundTripper := azureclient.NewCustomRoundTripper(http.DefaultTransport)
+	clientOptions := &azcore.ClientOptions{
+		Transport: &http.Client{
+			Transport: customRoundTripper,
+		},
+	}
+
 	pipeline := runtime.NewPipeline(
 		modulename,
 		version,
 		runtime.PipelineOptions{
 			PerCall:  []policy.Policy{},
 			PerRetry: []policy.Policy{authPolicy},
 		},
-		nil,
+		clientOptions,
 	)
 
 	return &remotePDPClient{endpoint, pipeline}

pkg/util/azureclient/decorators.go

@@ -0,0 +1,38 @@
+package azureclient
+
+// Copyright (c) Microsoft Corporation.
+// Licensed under the Apache License 2.0.
+
+import (
+	"net/http"
+
+	"github.com/Azure/go-autorest/autorest"
+)
+
+func DecorateSenderWithLogging(sender autorest.Sender) autorest.Sender {
+	loggingDecorator := LoggingDecorator()
+	return autorest.DecorateSender(sender, loggingDecorator, autorest.DoCloseIfError())
+}
+
+// LoggingDecorator returns a function which is used to wrap and modify
+// the behaviour of an autorest.Sender.
+// Azure Clients will have the sender wrapped by that function
+// in order to intercept http calls using our custom RoundTripper (through the adapter).
+func LoggingDecorator() autorest.SendDecorator {
+	return func(s autorest.Sender) autorest.Sender {
+		rt := NewCustomRoundTripper(
+			&roundTripperAdapter{Sender: s},
+		)
+		return autorest.SenderFunc(rt.RoundTrip)
+	}
+}
+
+// roundTripperAdapter converts from autorest.Sender (internal field)
+// to http.RoundTripper (external method).
+type roundTripperAdapter struct {
+	Sender autorest.Sender
+}
+
+func (rta *roundTripperAdapter) RoundTrip(req *http.Request) (*http.Response, error) {
+	return rta.Sender.Do(req)
+}

pkg/util/azureclient/keyvault/base.go

@@ -8,6 +8,8 @@ import (
 
 	azkeyvault "github.com/Azure/azure-sdk-for-go/services/keyvault/v7.0/keyvault"
 	"github.com/Azure/go-autorest/autorest"
+
+	"github.com/Azure/ARO-RP/pkg/util/azureclient"
 )
 
 // BaseClient is a minimal interface for azure BaseClient
@@ -32,6 +34,7 @@ var _ BaseClient = &baseClient{}
 func New(authorizer autorest.Authorizer) BaseClient {
 	client := azkeyvault.New()
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &baseClient{
 		BaseClient: client,

pkg/util/azureclient/mgmt/authorization/denyassignment.go

@@ -25,6 +25,7 @@ var _ DenyAssignmentClient = &denyAssignmentClient{}
 func NewDenyAssignmentsClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) DenyAssignmentClient {
 	client := mgmtauthorization.NewDenyAssignmentsClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &denyAssignmentClient{
 		DenyAssignmentsClient: client,

pkg/util/azureclient/mgmt/authorization/permissions.go

@@ -25,6 +25,7 @@ var _ PermissionsClient = &permissionsClient{}
 func NewPermissionsClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) PermissionsClient {
 	client := mgmtauthorization.NewPermissionsClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &permissionsClient{
 		PermissionsClient: client,

pkg/util/azureclient/mgmt/authorization/roleassignments.go

@@ -29,6 +29,7 @@ var _ RoleAssignmentsClient = &roleAssignmentsClient{}
 func NewRoleAssignmentsClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) RoleAssignmentsClient {
 	client := mgmtauthorization.NewRoleAssignmentsClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &roleAssignmentsClient{
 		RoleAssignmentsClient: client,

pkg/util/azureclient/mgmt/authorization/roledefinitions.go

@@ -28,6 +28,7 @@ var _ RoleDefinitionsClient = &roleDefinitionsClient{}
 func NewRoleDefinitionsClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) RoleDefinitionsClient {
 	client := mgmtauthorization.NewRoleDefinitionsClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &roleDefinitionsClient{
 		RoleDefinitionsClient: client,

pkg/util/azureclient/mgmt/compute/diskencryptionsets.go

@@ -27,6 +27,7 @@ var _ DiskEncryptionSetsClient = &diskEncryptionSetsClient{}
 func NewDiskEncryptionSetsClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) DiskEncryptionSetsClient {
 	client := mgmtcompute.NewDiskEncryptionSetsClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &diskEncryptionSetsClient{
 		DiskEncryptionSetsClient: client,

pkg/util/azureclient/mgmt/compute/disks.go

@@ -28,6 +28,7 @@ var _ DisksClient = &disksClient{}
 func NewDisksClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) DisksClient {
 	client := mgmtcompute.NewDisksClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &disksClient{
 		DisksClient: client,

pkg/util/azureclient/mgmt/compute/resourceskus.go

@@ -25,6 +25,7 @@ var _ ResourceSkusClient = &resourceSkusClient{}
 func NewResourceSkusClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) ResourceSkusClient {
 	client := mgmtcompute.NewResourceSkusClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &resourceSkusClient{
 		ResourceSkusClient: client,

pkg/util/azureclient/mgmt/compute/usage.go

@@ -25,6 +25,7 @@ var _ UsageClient = &usageClient{}
 func NewUsageClient(environment *azureclient.AROEnvironment, tenantID string, authorizer autorest.Authorizer) UsageClient {
 	client := mgmtcompute.NewUsageClientWithBaseURI(environment.ResourceManagerEndpoint, tenantID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &usageClient{
 		UsageClient: client,

pkg/util/azureclient/mgmt/compute/virtualmachines.go

@@ -28,6 +28,7 @@ var _ VirtualMachinesClient = &virtualMachinesClient{}
 func NewVirtualMachinesClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) VirtualMachinesClient {
 	client := mgmtcompute.NewVirtualMachinesClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &virtualMachinesClient{
 		VirtualMachinesClient: client,

pkg/util/azureclient/mgmt/compute/virtualmachinescalesetvms.go

@@ -30,6 +30,7 @@ func NewVirtualMachineScaleSetVMsClient(environment *azureclient.AROEnvironment,
 	client := mgmtcompute.NewVirtualMachineScaleSetVMsClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
 	client.PollingDuration = time.Hour
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &virtualMachineScaleSetVMsClient{
 		VirtualMachineScaleSetVMsClient: client,

pkg/util/azureclient/mgmt/compute/virtualmachinesscalesets.go

@@ -24,6 +24,7 @@ var _ VirtualMachineScaleSetsClient = &virtualMachineScaleSetsClient{}
 func NewVirtualMachineScaleSetsClient(environment *azureclient.AROEnvironment, subscriptionID string, authorizer autorest.Authorizer) VirtualMachineScaleSetsClient {
 	client := mgmtcompute.NewVirtualMachineScaleSetsClientWithBaseURI(environment.ResourceManagerEndpoint, subscriptionID)
 	client.Authorizer = authorizer
+	client.Sender = azureclient.DecorateSenderWithLogging(client.Sender)
 
 	return &virtualMachineScaleSetsClient{
 		VirtualMachineScaleSetsClient: client,