Merge pull request #1812 from devigned/mc-logs

make all logging consistent across the controllers

api/v1beta1/azurecluster_webhook.go

@@ -23,13 +23,9 @@ import (
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/apimachinery/pkg/util/validation/field"
 	ctrl "sigs.k8s.io/controller-runtime"
-	logf "sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/webhook"
 )
 
-// log is for logging in this package.
-var clusterlog = logf.Log.WithName("azurecluster-resource")
-
 // SetupWebhookWithManager sets up and registers the webhook with the manager.
 func (c *AzureCluster) SetupWebhookWithManager(mgr ctrl.Manager) error {
 	return ctrl.NewWebhookManagedBy(mgr).
@@ -45,21 +41,16 @@ var _ webhook.Defaulter = &AzureCluster{}
 
 // Default implements webhook.Defaulter so a webhook will be registered for the type.
 func (c *AzureCluster) Default() {
-	clusterlog.Info("default", "name", c.Name)
-
 	c.setDefaults()
 }
 
 // ValidateCreate implements webhook.Validator so a webhook will be registered for the type.
 func (c *AzureCluster) ValidateCreate() error {
-	clusterlog.Info("validate create", "name", c.Name)
-
 	return c.validateCluster(nil)
 }
 
 // ValidateUpdate implements webhook.Validator so a webhook will be registered for the type.
 func (c *AzureCluster) ValidateUpdate(oldRaw runtime.Object) error {
-	clusterlog.Info("validate update", "name", c.Name)
 	var allErrs field.ErrorList
 	old := oldRaw.(*AzureCluster)
 
@@ -132,7 +123,5 @@ func (c *AzureCluster) ValidateUpdate(oldRaw runtime.Object) error {
 
 // ValidateDelete implements webhook.Validator so a webhook will be registered for the type.
 func (c *AzureCluster) ValidateDelete() error {
-	clusterlog.Info("validate delete", "name", c.Name)
-
 	return nil
 }

api/v1beta1/azuremachine_default.go

@@ -19,9 +19,9 @@ package v1beta1
 import (
 	"encoding/base64"
 
-	"github.com/go-logr/logr"
 	"golang.org/x/crypto/ssh"
 	"k8s.io/apimachinery/pkg/util/uuid"
+	ctrl "sigs.k8s.io/controller-runtime"
 
 	utilSSH "sigs.k8s.io/cluster-api-provider-azure/util/ssh"
 )
@@ -85,10 +85,10 @@ func (s *AzureMachineSpec) SetIdentityDefaults() {
 }
 
 // SetDefaults sets to the defaults for the AzureMachineSpec.
-func (s *AzureMachineSpec) SetDefaults(log logr.Logger) {
+func (s *AzureMachineSpec) SetDefaults() {
 	err := s.SetDefaultSSHPublicKey()
 	if err != nil {
-		log.Error(err, "SetDefaultSshPublicKey failed")
+		ctrl.Log.WithName("SetDefault").Error(err, "SetDefaultSshPublicKey failed")
 	}
 	s.SetDefaultCachingType()
 	s.SetDataDisksDefaults()

api/v1beta1/azuremachine_webhook.go

@@ -23,13 +23,9 @@ import (
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/apimachinery/pkg/util/validation/field"
 	ctrl "sigs.k8s.io/controller-runtime"
-	logf "sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/webhook"
 )
 
-// log is for logging in this package.
-var machinelog = logf.Log.WithName("azuremachine-resource")
-
 // SetupWebhookWithManager sets up and registers the webhook with the manager.
 func (m *AzureMachine) SetupWebhookWithManager(mgr ctrl.Manager) error {
 	return ctrl.NewWebhookManagedBy(mgr).
@@ -44,8 +40,6 @@ var _ webhook.Validator = &AzureMachine{}
 
 // ValidateCreate implements webhook.Validator so a webhook will be registered for the type.
 func (m *AzureMachine) ValidateCreate() error {
-	machinelog.Info("validate create", "name", m.Name)
-
 	if allErrs := ValidateAzureMachineSpec(m.Spec); len(allErrs) > 0 {
 		return apierrors.NewInvalid(GroupVersion.WithKind("AzureMachine").GroupKind(), m.Name, allErrs)
 	}
@@ -55,7 +49,6 @@ func (m *AzureMachine) ValidateCreate() error {
 
 // ValidateUpdate implements webhook.Validator so a webhook will be registered for the type.
 func (m *AzureMachine) ValidateUpdate(oldRaw runtime.Object) error {
-	machinelog.Info("validate update", "name", m.Name)
 	var allErrs field.ErrorList
 	old := oldRaw.(*AzureMachine)
 
@@ -151,13 +144,10 @@ func (m *AzureMachine) ValidateUpdate(oldRaw runtime.Object) error {
 
 // ValidateDelete implements webhook.Validator so a webhook will be registered for the type.
 func (m *AzureMachine) ValidateDelete() error {
-	machinelog.Info("validate delete", "name", m.Name)
-
 	return nil
 }
 
 // Default implements webhookutil.defaulter so a webhook will be registered for the type.
 func (m *AzureMachine) Default() {
-	machinelog.Info("default", "name", m.Name)
-	m.Spec.SetDefaults(machinelog)
+	m.Spec.SetDefaults()
 }

api/v1beta1/azuremachinetemplate_webhook.go

@@ -23,16 +23,12 @@ import (
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/apimachinery/pkg/util/validation/field"
 	ctrl "sigs.k8s.io/controller-runtime"
-	logf "sigs.k8s.io/controller-runtime/pkg/log"
 	"sigs.k8s.io/controller-runtime/pkg/webhook"
 )
 
 // AzureMachineTemplateImmutableMsg ...
 const AzureMachineTemplateImmutableMsg = "AzureMachineTemplate spec.template.spec field is immutable. Please create new resource instead. ref doc: https://cluster-api.sigs.k8s.io/tasks/change-machine-template.html"
 
-// log is for logging in this package.
-var machinetemplatelog = logf.Log.WithName("azuremachinetemplate-resource")
-
 // SetupWebhookWithManager sets up and registers the webhook with the manager.
 func (r *AzureMachineTemplate) SetupWebhookWithManager(mgr ctrl.Manager) error {
 	return ctrl.NewWebhookManagedBy(mgr).
@@ -48,7 +44,6 @@ var _ webhook.Validator = &AzureMachineTemplate{}
 
 // ValidateCreate implements webhook.Validator so a webhook will be registered for the type.
 func (r *AzureMachineTemplate) ValidateCreate() error {
-	machinetemplatelog.Info("validate create", "name", r.Name)
 	spec := r.Spec.Template.Spec
 
 	if allErrs := ValidateAzureMachineSpec(spec); len(allErrs) > 0 {
@@ -59,7 +54,6 @@ func (r *AzureMachineTemplate) ValidateCreate() error {
 
 // ValidateUpdate implements webhook.Validator so a webhook will be registered for the type.
 func (r *AzureMachineTemplate) ValidateUpdate(oldRaw runtime.Object) error {
-	machinetemplatelog.Info("validate update", "name", r.Name)
 	var allErrs field.ErrorList
 	old := oldRaw.(*AzureMachineTemplate)
 
@@ -98,6 +92,5 @@ func (r *AzureMachineTemplate) ValidateDelete() error {
 
 // Default implements webhookutil.defaulter so a webhook will be registered for the type.
 func (r *AzureMachineTemplate) Default() {
-	machinetemplatelog.Info("default", "name", r.Name)
-	r.Spec.Template.Spec.SetDefaults(machinetemplatelog)
+	r.Spec.Template.Spec.SetDefaults()
 }

azure/defaults.go

@@ -20,12 +20,10 @@ import (
 	"fmt"
 	"net/http"
 
-	"github.com/Azure/go-autorest/autorest/azure"
-
 	"github.com/Azure/go-autorest/autorest"
+	"github.com/Azure/go-autorest/autorest/azure"
 	"github.com/blang/semver"
 	"github.com/pkg/errors"
-
 	infrav1 "sigs.k8s.io/cluster-api-provider-azure/api/v1beta1"
 	"sigs.k8s.io/cluster-api-provider-azure/util/tele"
 	"sigs.k8s.io/cluster-api-provider-azure/version"

azure/scope/cluster.go

@@ -26,9 +26,7 @@ import (
 
 	"github.com/Azure/go-autorest/autorest"
 	"github.com/Azure/go-autorest/autorest/to"
-	"github.com/go-logr/logr"
 	"github.com/pkg/errors"
-	"k8s.io/klog/v2/klogr"
 	"k8s.io/utils/net"
 	clusterv1 "sigs.k8s.io/cluster-api/api/v1beta1"
 	"sigs.k8s.io/cluster-api/util/conditions"
@@ -47,7 +45,6 @@ import (
 type ClusterScopeParams struct {
 	AzureClients
 	Client       client.Client
-	Logger       logr.Logger
 	Cluster      *clusterv1.Cluster
 	AzureCluster *infrav1.AzureCluster
 }
@@ -65,10 +62,6 @@ func NewClusterScope(ctx context.Context, params ClusterScopeParams) (*ClusterSc
 		return nil, errors.New("failed to generate new scope from nil AzureCluster")
 	}
 
-	if params.Logger == nil {
-		params.Logger = klogr.New()
-	}
-
 	if params.AzureCluster.Spec.IdentityRef == nil {
 		err := params.AzureClients.setCredentials(params.AzureCluster.Spec.SubscriptionID, params.AzureCluster.Spec.AzureEnvironment)
 		if err != nil {
@@ -91,7 +84,6 @@ func NewClusterScope(ctx context.Context, params ClusterScopeParams) (*ClusterSc
 	}
 
 	return &ClusterScope{
-		Logger:       params.Logger,
 		Client:       params.Client,
 		AzureClients: params.AzureClients,
 		Cluster:      params.Cluster,
@@ -102,7 +94,6 @@ func NewClusterScope(ctx context.Context, params ClusterScopeParams) (*ClusterSc
 
 // ClusterScope defines the basic context for an actuator to operate upon.
 type ClusterScope struct {
-	logr.Logger
 	Client      client.Client
 	patchHelper *patch.Helper
 
@@ -219,7 +210,7 @@ func (s *ClusterScope) LBSpecs() []azure.LBSpec {
 
 // RouteTableSpecs returns the node route table.
 func (s *ClusterScope) RouteTableSpecs() []azure.RouteTableSpec {
-	routetables := []azure.RouteTableSpec{}
+	var routetables []azure.RouteTableSpec
 	for _, subnet := range s.AzureCluster.Spec.NetworkSpec.Subnets {
 		if subnet.RouteTable.Name != "" {
 			routetables = append(routetables, azure.RouteTableSpec{Name: subnet.RouteTable.Name, Subnet: subnet})
@@ -231,7 +222,7 @@ func (s *ClusterScope) RouteTableSpecs() []azure.RouteTableSpec {
 
 // NatGatewaySpecs returns the node nat gateway.
 func (s *ClusterScope) NatGatewaySpecs() []azure.NatGatewaySpec {
-	natGateways := []azure.NatGatewaySpec{}
+	var natGateways []azure.NatGatewaySpec
 
 	// We ignore the control plane nat gateway, as we will always use a LB to enable egress on the control plane.
 	for _, subnet := range s.NodeSubnets() {
@@ -251,20 +242,25 @@ func (s *ClusterScope) NatGatewaySpecs() []azure.NatGatewaySpec {
 
 // NSGSpecs returns the security group specs.
 func (s *ClusterScope) NSGSpecs() []azure.NSGSpec {
-	nsgspecs := []azure.NSGSpec{}
-	for _, subnet := range s.AzureCluster.Spec.NetworkSpec.Subnets {
-		nsgspecs = append(nsgspecs, azure.NSGSpec{
+	nsgspecs := make([]azure.NSGSpec, len(s.AzureCluster.Spec.NetworkSpec.Subnets))
+	for i, subnet := range s.AzureCluster.Spec.NetworkSpec.Subnets {
+		nsgspecs[i] = azure.NSGSpec{
 			Name:          subnet.SecurityGroup.Name,
 			SecurityRules: subnet.SecurityGroup.SecurityRules,
-		})
+		}
 	}
 
 	return nsgspecs
 }
 
 // SubnetSpecs returns the subnets specs.
 func (s *ClusterScope) SubnetSpecs() []azure.SubnetSpec {
-	subnetSpecs := []azure.SubnetSpec{}
+	numberOfSubnets := len(s.AzureCluster.Spec.NetworkSpec.Subnets)
+	if s.AzureCluster.Spec.BastionSpec.AzureBastion != nil {
+		numberOfSubnets++
+	}
+
+	subnetSpecs := make([]azure.SubnetSpec, 0, numberOfSubnets)
 	for _, subnet := range s.AzureCluster.Spec.NetworkSpec.Subnets {
 		subnetSpec := azure.SubnetSpec{
 			Name:              subnet.Name,

azure/scope/machine.go

@@ -24,11 +24,9 @@ import (
 	"time"
 
 	"github.com/Azure/go-autorest/autorest/to"
-	"github.com/go-logr/logr"
 	"github.com/pkg/errors"
 	corev1 "k8s.io/api/core/v1"
 	"k8s.io/apimachinery/pkg/types"
-	"k8s.io/klog/v2/klogr"
 	clusterv1 "sigs.k8s.io/cluster-api/api/v1beta1"
 	"sigs.k8s.io/cluster-api/controllers/noderefutil"
 	capierrors "sigs.k8s.io/cluster-api/errors"
@@ -49,7 +47,6 @@ import (
 // MachineScopeParams defines the input parameters used to create a new MachineScope.
 type MachineScopeParams struct {
 	Client       client.Client
-	Logger       logr.Logger
 	ClusterScope azure.ClusterScoper
 	Machine      *clusterv1.Machine
 	AzureMachine *infrav1.AzureMachine
@@ -68,9 +65,6 @@ func NewMachineScope(params MachineScopeParams) (*MachineScope, error) {
 	if params.AzureMachine == nil {
 		return nil, errors.New("azure machine is required when creating a MachineScope")
 	}
-	if params.Logger == nil {
-		params.Logger = klogr.New()
-	}
 
 	helper, err := patch.NewHelper(params.AzureMachine, params.Client)
 	if err != nil {
@@ -81,7 +75,6 @@ func NewMachineScope(params MachineScopeParams) (*MachineScope, error) {
 		client:        params.Client,
 		Machine:       params.Machine,
 		AzureMachine:  params.AzureMachine,
-		Logger:        params.Logger,
 		patchHelper:   helper,
 		ClusterScoper: params.ClusterScope,
 		cache:         params.Cache,
@@ -90,7 +83,6 @@ func NewMachineScope(params MachineScopeParams) (*MachineScope, error) {
 
 // MachineScope defines a scope defined around a machine and its cluster.
 type MachineScope struct {
-	logr.Logger
 	client      client.Client
 	patchHelper *patch.Helper
 
@@ -121,7 +113,7 @@ func (m *MachineScope) InitMachineCache(ctx context.Context) error {
 			return err
 		}
 
-		m.cache.VMImage, err = m.GetVMImage()
+		m.cache.VMImage, err = m.GetVMImage(ctx)
 		if err != nil {
 			return err
 		}
@@ -442,18 +434,21 @@ func (m *MachineScope) SetFailureReason(v capierrors.MachineStatusError) {
 }
 
 // SetBootstrapConditions sets the AzureMachine BootstrapSucceeded condition based on the extension provisioning states.
-func (m *MachineScope) SetBootstrapConditions(provisioningState string, extensionName string) error {
+func (m *MachineScope) SetBootstrapConditions(ctx context.Context, provisioningState string, extensionName string) error {
+	_, log, done := tele.StartSpanWithLogger(ctx, "scope.MachineScope.SetBootstrapConditions")
+	defer done()
+
 	switch infrav1.ProvisioningState(provisioningState) {
 	case infrav1.Succeeded:
-		m.V(4).Info("extension provisioning state is succeeded", "vm extension", extensionName, "virtual machine", m.Name())
+		log.V(4).Info("extension provisioning state is succeeded", "vm extension", extensionName, "virtual machine", m.Name())
 		conditions.MarkTrue(m.AzureMachine, infrav1.BootstrapSucceededCondition)
 		return nil
 	case infrav1.Creating:
-		m.V(4).Info("extension provisioning state is creating", "vm extension", extensionName, "virtual machine", m.Name())
+		log.V(4).Info("extension provisioning state is creating", "vm extension", extensionName, "virtual machine", m.Name())
 		conditions.MarkFalse(m.AzureMachine, infrav1.BootstrapSucceededCondition, infrav1.BootstrapInProgressReason, clusterv1.ConditionSeverityInfo, "")
 		return azure.WithTransientError(errors.New("extension is still in provisioning state. This likely means that bootstrapping has not yet completed on the VM"), 30*time.Second)
 	case infrav1.Failed:
-		m.V(4).Info("extension provisioning state is failed", "vm extension", extensionName, "virtual machine", m.Name())
+		log.V(4).Info("extension provisioning state is failed", "vm extension", extensionName, "virtual machine", m.Name())
 		conditions.MarkFalse(m.AzureMachine, infrav1.BootstrapSucceededCondition, infrav1.BootstrapFailedReason, clusterv1.ConditionSeverityError, "")
 		return azure.WithTerminalError(errors.New("extension state failed. This likely means the Kubernetes node bootstrapping process failed or timed out. Check VM boot diagnostics logs to learn more"))
 	default:
@@ -542,6 +537,9 @@ func (m *MachineScope) AdditionalTags() infrav1.Tags {
 
 // GetBootstrapData returns the bootstrap data from the secret in the Machine's bootstrap.dataSecretName.
 func (m *MachineScope) GetBootstrapData(ctx context.Context) (string, error) {
+	ctx, _, done := tele.StartSpanWithLogger(ctx, "scope.MachineScope.GetBootstrapData")
+	defer done()
+
 	if m.Machine.Spec.Bootstrap.DataSecretName == nil {
 		return "", errors.New("error retrieving bootstrap data: linked Machine's bootstrap.dataSecretName is nil")
 	}
@@ -559,19 +557,22 @@ func (m *MachineScope) GetBootstrapData(ctx context.Context) (string, error) {
 }
 
 // GetVMImage returns the image from the machine configuration, or a default one.
-func (m *MachineScope) GetVMImage() (*infrav1.Image, error) {
+func (m *MachineScope) GetVMImage(ctx context.Context) (*infrav1.Image, error) {
+	_, log, done := tele.StartSpanWithLogger(ctx, "scope.MachineScope.GetVMImage")
+	defer done()
+
 	// Use custom Marketplace image, Image ID or a Shared Image Gallery image if provided
 	if m.AzureMachine.Spec.Image != nil {
 		return m.AzureMachine.Spec.Image, nil
 	}
 
 	if m.AzureMachine.Spec.OSDisk.OSType == azure.WindowsOS {
 		runtime := m.AzureMachine.Annotations["runtime"]
-		m.Info("No image specified for machine, using default Windows Image", "machine", m.AzureMachine.GetName(), "runtime", runtime)
+		log.Info("No image specified for machine, using default Windows Image", "machine", m.AzureMachine.GetName(), "runtime", runtime)
 		return azure.GetDefaultWindowsImage(to.String(m.Machine.Spec.Version), runtime)
 	}
 
-	m.Info("No image specified for machine, using default Linux Image", "machine", m.AzureMachine.GetName())
+	log.Info("No image specified for machine, using default Linux Image", "machine", m.AzureMachine.GetName())
 	return azure.GetDefaultUbuntuImage(to.String(m.Machine.Spec.Version))
 }