Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

make all logging consistent across the controllers #1812

Merged
merged 1 commit into from
Dec 7, 2021
Merged

make all logging consistent across the controllers #1812

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 0 additions & 11 deletions api/v1beta1/azurecluster_webhook.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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).
Expand All @@ -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)
CecileRobertMichon marked this conversation as resolved.
Show resolved Hide resolved

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)

Expand Down Expand Up @@ -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
}
6 changes: 3 additions & 3 deletions api/v1beta1/azuremachine_default.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"
)
Expand Down Expand Up @@ -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()
Expand Down
12 changes: 1 addition & 11 deletions api/v1beta1/azuremachine_webhook.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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).
Expand All @@ -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)
}
Expand All @@ -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)

Expand Down Expand Up @@ -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()
}
9 changes: 1 addition & 8 deletions api/v1beta1/azuremachinetemplate_webhook.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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).
Expand All @@ -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 {
Expand All @@ -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)

Expand Down Expand Up @@ -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()
}
4 changes: 1 addition & 3 deletions azure/defaults.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand Down
28 changes: 12 additions & 16 deletions azure/scope/cluster.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -47,7 +45,6 @@ import (
type ClusterScopeParams struct {
AzureClients
Client client.Client
Logger logr.Logger
Cluster *clusterv1.Cluster
AzureCluster *infrav1.AzureCluster
}
Expand All @@ -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 {
Expand All @@ -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,
Expand All @@ -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

Expand Down Expand Up @@ -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
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is there any practical difference in how Go treats these two constructs, or is this just for style? (I prefer the var style to which you changed it.)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

They are subtly different: https://play.golang.org/p/Yd6jei06m9y. One is an empty slice, the other is nil.

for _, subnet := range s.AzureCluster.Spec.NetworkSpec.Subnets {
if subnet.RouteTable.Name != "" {
routetables = append(routetables, azure.RouteTableSpec{Name: subnet.RouteTable.Name, Subnet: subnet})
Expand All @@ -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() {
Expand All @@ -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,
Expand Down
33 changes: 17 additions & 16 deletions azure/scope/machine.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -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
Expand All @@ -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 {
Expand All @@ -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,
Expand All @@ -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

Expand Down Expand Up @@ -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
}
Expand Down Expand Up @@ -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")
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

General question on the approach: All logs are now written through the span logger which also creates spans for the functions they are called in. This means we have already added spans to functions which previously didn't have one, and in future, we'll be adding more if we want to add logs. Will this create a flurry of spans and make it harder to visualize the flow?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Creating the spans and adding them to the traces in my opinion actually makes it easier to understand what is happening. If someone would like to filter spans, they are able to in the visualization or in the span data. Without producing the spans, the data would then be lost. For example, in Jaeger, I can just not expand items in the tree below a given level if I want. However, if I need to dig deeper I can. If we omit deeper span information, there is no option to dig deeper.

Additionally, exporters would likely be configured to do stochastic tracing only selecting a percentage of traces or a subset based on some criteria.

Overall, I'd bias toward over instrumentation and giving folks the ability to reduce based on export criteria.

wdyt?

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:
Expand Down Expand Up @@ -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")
}
Expand All @@ -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))
}

Expand Down
Loading