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

Logging as a dependency (with context) #714

Merged
merged 1 commit into from
Apr 16, 2019
Merged

Logging as a dependency (with context) #714

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
5 changes: 3 additions & 2 deletions cmd/manager/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -71,12 +71,13 @@ func main() {
// Initialize cluster actuator.
clusterActuator := cluster.NewActuator(cluster.ActuatorParams{
Client: cs.ClusterV1alpha1(),
LoggingContext: "[cluster actuator]",
LoggingContext: "[cluster-actuator]",
})

// Initialize machine actuator.
machineActuator := machine.NewActuator(machine.ActuatorParams{
Client: cs.ClusterV1alpha1(),
Client: cs.ClusterV1alpha1(),
LoggingContext: "[machine-actuator]",
})

// Register our cluster deployer (the interface is in clusterctl and we define the Deployer interface on the actuator)
Expand Down
3 changes: 2 additions & 1 deletion pkg/cloud/aws/actuators/BUILD.bazel
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,10 +18,11 @@ go_library(
"//vendor/github.com/aws/aws-sdk-go/service/ec2/ec2iface:go_default_library",
"//vendor/github.com/aws/aws-sdk-go/service/elb:go_default_library",
"//vendor/github.com/aws/aws-sdk-go/service/elb/elbiface:go_default_library",
"//vendor/github.com/go-logr/logr:go_default_library",
"//vendor/github.com/pkg/errors:go_default_library",
"//vendor/k8s.io/apimachinery/pkg/apis/meta/v1:go_default_library",
"//vendor/k8s.io/apimachinery/pkg/runtime:go_default_library",
"//vendor/k8s.io/klog:go_default_library",
"//vendor/k8s.io/klog/klogr:go_default_library",
"//vendor/sigs.k8s.io/cluster-api/pkg/apis/cluster/v1alpha1:go_default_library",
"//vendor/sigs.k8s.io/cluster-api/pkg/client/clientset_generated/clientset/typed/cluster/v1alpha1:go_default_library",
"//vendor/sigs.k8s.io/yaml:go_default_library",
Expand Down
1 change: 0 additions & 1 deletion pkg/cloud/aws/actuators/cluster/BUILD.bazel
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,6 @@ go_library(
"//pkg/deployer:go_default_library",
"//vendor/github.com/go-logr/logr:go_default_library",
"//vendor/github.com/pkg/errors:go_default_library",
"//vendor/k8s.io/klog:go_default_library",
"//vendor/k8s.io/klog/klogr:go_default_library",
"//vendor/sigs.k8s.io/cluster-api/pkg/apis/cluster/v1alpha1:go_default_library",
"//vendor/sigs.k8s.io/cluster-api/pkg/client/clientset_generated/clientset/typed/cluster/v1alpha1:go_default_library",
Expand Down
15 changes: 9 additions & 6 deletions pkg/cloud/aws/actuators/cluster/actuator.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,6 @@ package cluster
import (
"github.com/go-logr/logr"
"github.com/pkg/errors"
"k8s.io/klog"
"k8s.io/klog/klogr"
"sigs.k8s.io/cluster-api-provider-aws/pkg/cloud/aws/actuators"
"sigs.k8s.io/cluster-api-provider-aws/pkg/cloud/aws/services/certificates"
Expand Down Expand Up @@ -59,9 +58,9 @@ func NewActuator(params ActuatorParams) *Actuator {

// Reconcile reconciles a cluster and is invoked by the Cluster Controller
func (a *Actuator) Reconcile(cluster *clusterv1.Cluster) error {
klog.Infof("Reconciling cluster %v", cluster.Name)
a.log.Info("Reconciling Cluster", "cluster-name", cluster.Name, "cluster-namespace", cluster.Namespace)

scope, err := actuators.NewScope(actuators.ScopeParams{Cluster: cluster, Client: a.client})
scope, err := actuators.NewScope(actuators.ScopeParams{Cluster: cluster, Client: a.client, Logger: a.log})
if err != nil {
return errors.Errorf("failed to create scope: %+v", err)
}
Expand Down Expand Up @@ -94,9 +93,13 @@ func (a *Actuator) Reconcile(cluster *clusterv1.Cluster) error {

// Delete deletes a cluster and is invoked by the Cluster Controller
func (a *Actuator) Delete(cluster *clusterv1.Cluster) error {
klog.Infof("Deleting cluster %v.", cluster.Name)
a.log.Info("Deleting cluster", "cluster-name", cluster.Name, "cluster-namespace", cluster.Namespace)

scope, err := actuators.NewScope(actuators.ScopeParams{Cluster: cluster, Client: a.client})
scope, err := actuators.NewScope(actuators.ScopeParams{
Cluster: cluster,
Client: a.client,
Logger: a.log,
})
if err != nil {
return errors.Errorf("failed to create scope: %+v", err)
}
Expand All @@ -115,7 +118,7 @@ func (a *Actuator) Delete(cluster *clusterv1.Cluster) error {
}

if err := ec2svc.DeleteNetwork(); err != nil {
klog.Errorf("Error deleting cluster %v: %v.", cluster.Name, err)
a.log.Error(err, "Error deleting cluster", "cluster-name", cluster.Name, "cluster-namespace", cluster.Namespace)
Copy link
Member

Choose a reason for hiding this comment

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

Could this use the scoped logger?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

yes it could

return &controllerError.RequeueAfterError{
RequeueAfter: 5 * 1000 * 1000 * 1000,
}
Expand Down
3 changes: 2 additions & 1 deletion pkg/cloud/aws/actuators/machine/BUILD.bazel
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -20,13 +20,14 @@ go_library(
"//pkg/deployer:go_default_library",
"//pkg/tokens:go_default_library",
"//vendor/github.com/aws/aws-sdk-go/aws:go_default_library",
"//vendor/github.com/go-logr/logr:go_default_library",
"//vendor/github.com/pkg/errors:go_default_library",
"//vendor/k8s.io/api/core/v1:go_default_library",
"//vendor/k8s.io/apimachinery/pkg/apis/meta/v1:go_default_library",
"//vendor/k8s.io/client-go/kubernetes/typed/core/v1:go_default_library",
"//vendor/k8s.io/client-go/tools/clientcmd:go_default_library",
"//vendor/k8s.io/client-go/tools/clientcmd/api:go_default_library",
"//vendor/k8s.io/klog:go_default_library",
"//vendor/k8s.io/klog/klogr:go_default_library",
"//vendor/sigs.k8s.io/cluster-api/pkg/apis/cluster/v1alpha1:go_default_library",
"//vendor/sigs.k8s.io/cluster-api/pkg/client/clientset_generated/clientset/typed/cluster/v1alpha1:go_default_library",
"//vendor/sigs.k8s.io/cluster-api/pkg/controller/error:go_default_library",
Expand Down
48 changes: 27 additions & 21 deletions pkg/cloud/aws/actuators/machine/actuator.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -24,14 +24,15 @@ import (
"time"

"github.com/aws/aws-sdk-go/aws"
"github.com/go-logr/logr"
"github.com/pkg/errors"
apicorev1 "k8s.io/api/core/v1"
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
v1 "k8s.io/apimachinery/pkg/apis/meta/v1"
corev1 "k8s.io/client-go/kubernetes/typed/core/v1"
"k8s.io/client-go/tools/clientcmd"
clientcmdapi "k8s.io/client-go/tools/clientcmd/api"
"k8s.io/klog"
"k8s.io/klog/klogr"
"sigs.k8s.io/cluster-api-provider-aws/pkg/apis/awsprovider/v1alpha1"
"sigs.k8s.io/cluster-api-provider-aws/pkg/cloud/aws/actuators"
"sigs.k8s.io/cluster-api-provider-aws/pkg/cloud/aws/services/awserrors"
Expand All @@ -58,18 +59,21 @@ type Actuator struct {
*deployer.Deployer

client client.ClusterV1alpha1Interface
log logr.Logger
}

// ActuatorParams holds parameter information for Actuator.
type ActuatorParams struct {
Client client.ClusterV1alpha1Interface
Client client.ClusterV1alpha1Interface
LoggingContext string
}

// NewActuator returns an actuator.
func NewActuator(params ActuatorParams) *Actuator {
return &Actuator{
Deployer: deployer.New(deployer.Params{ScopeGetter: actuators.DefaultScopeGetter}),
client: params.Client,
log: klogr.New().WithName(params.LoggingContext),
}
}

Expand Down Expand Up @@ -99,6 +103,7 @@ func (a *Actuator) isNodeJoin(scope *actuators.MachineScope, controlPlaneMachine
Machine: cm,
Cluster: scope.Cluster,
Client: a.client,
Logger: a.log,
})

if err != nil {
Expand All @@ -112,7 +117,7 @@ func (a *Actuator) isNodeJoin(scope *actuators.MachineScope, controlPlaneMachine
return false, errors.Wrapf(err, "failed to verify existence of machine %q", m.Name())
}

klog.V(2).Infof("Machine %q should join the controlplane: %t", scope.Machine.Name, ok)
a.log.V(2).Info("Machine joining control plane", "machine-name", scope.Machine.Name, "machine-namespace", scope.Machine.Name, "should-join-control-plane", ok)
Copy link
Member

Choose a reason for hiding this comment

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

Same here, could this use the scoped logger?

return ok, nil
}

Expand All @@ -127,9 +132,9 @@ func (a *Actuator) Create(ctx context.Context, cluster *clusterv1.Cluster, machi
if cluster == nil {
return errors.Errorf("missing cluster for machine %s/%s", machine.Namespace, machine.Name)
}
klog.Infof("Creating machine %v for cluster %v", machine.Name, cluster.Name)
a.log.Info("Creating machine in cluster", "machine-name", machine.Name, "machine-namespace", machine.Namespace, "cluster-name", cluster.Name)

scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client})
scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client, Logger: a.log})
if err != nil {
return errors.Errorf("failed to create scope: %+v", err)
}
Expand Down Expand Up @@ -171,7 +176,7 @@ func (a *Actuator) Create(ctx context.Context, cluster *clusterv1.Cluster, machi
i, err := ec2svc.CreateOrGetMachine(scope, bootstrapToken, kubeConfig)
if err != nil {
if awserrors.IsFailedDependency(errors.Cause(err)) {
klog.Errorf("network not ready to launch instances yet: %+v", err)
a.log.Error(err, "network not ready to launch instances yet")
return &controllerError.RequeueAfterError{
RequeueAfter: time.Minute,
}
Expand All @@ -192,7 +197,7 @@ func (a *Actuator) Create(ctx context.Context, cluster *clusterv1.Cluster, machi
if err := a.reconcileLBAttachment(scope, machine, i); err != nil {
return errors.Errorf("failed to reconcile LB attachment: %+v", err)
}

a.log.Info("Create completed", "machine-name", machine.Name)
return nil
}

Expand Down Expand Up @@ -236,9 +241,9 @@ func (a *Actuator) Delete(ctx context.Context, cluster *clusterv1.Cluster, machi
if cluster == nil {
return errors.Errorf("missing cluster for machine %s/%s", machine.Namespace, machine.Name)
}
klog.Infof("Deleting machine %v for cluster %v.", machine.Name, cluster.Name)
a.log.Info("Deleting machine in cluster", "machine-name", machine.Name, "machine-namespace", machine.Namespace, "cluster-name", cluster.Name)

scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client})
scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client, Logger: a.log})
if err != nil {
return errors.Errorf("failed to create scope: %+v", err)
}
Expand All @@ -258,7 +263,7 @@ func (a *Actuator) Delete(ctx context.Context, cluster *clusterv1.Cluster, machi
return errors.Errorf("failed to query instance by tags: %+v", err)
} else if instance == nil {
// The machine hasn't been created yet
klog.V(3).Info("Instance is nil and therefore does not exist")
a.log.V(3).Info("Instance is nil and therefore does not exist")
return nil
}
}
Expand All @@ -269,15 +274,15 @@ func (a *Actuator) Delete(ctx context.Context, cluster *clusterv1.Cluster, machi
// https://docs.aws.amazon.com/AWSEC2/latest/UserGuide/ec2-instance-lifecycle.html
switch instance.State {
case v1alpha1.InstanceStateShuttingDown, v1alpha1.InstanceStateTerminated:
klog.Infof("instance %q is shutting down or already terminated", machine.Name)
a.log.Info("Machine instance is shutting down or already terminated", "machine-name", machine.Name, "machine-namespace", machine.Namespace)
return nil
default:
if err := ec2svc.TerminateInstance(instance.ID); err != nil {
return errors.Errorf("failed to terminate instance: %+v", err)
}
}

klog.Info("shutdown signal was sent. Shutting down machine.")
a.log.Info("Shutdown signal was sent. Shutting down machine.")
return nil
}

Expand Down Expand Up @@ -337,9 +342,9 @@ func (a *Actuator) Update(ctx context.Context, cluster *clusterv1.Cluster, machi
return errors.Errorf("missing cluster for machine %s/%s", machine.Namespace, machine.Name)
}

klog.Infof("Updating machine %v for cluster %v.", machine.Name, cluster.Name)
a.log.Info("Updating machine in cluster", "machine-name", machine.Name, "machine-namespace", machine.Namespace, "cluster-name", cluster.Name)

scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client})
scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client, Logger: a.log})
if err != nil {
return errors.Errorf("failed to create scope: %+v", err)
}
Expand Down Expand Up @@ -388,9 +393,9 @@ func (a *Actuator) Exists(ctx context.Context, cluster *clusterv1.Cluster, machi
return false, errors.Errorf("missing cluster for machine %s/%s", machine.Namespace, machine.Name)
}

klog.Infof("Checking if machine %v for cluster %v exists", machine.Name, cluster.Name)
a.log.Info("Checking if machine exists in cluster", "machine-name", machine.Name, "machine-namespace", machine.Namespace, "cluster-name", cluster.Name)

scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client})
scope, err := actuators.NewMachineScope(actuators.MachineScopeParams{Machine: machine, Cluster: cluster, Client: a.client, Logger: a.log})
if err != nil {
return false, errors.Errorf("failed to create scope: %+v", err)
}
Expand All @@ -413,13 +418,13 @@ func (a *Actuator) Exists(ctx context.Context, cluster *clusterv1.Cluster, machi
return false, nil
}

klog.Infof("Found instance for machine %q: %v", machine.Name, instance)
a.log.Info("Found instance for machine", "machine-name", machine.Name, "machine-namespace", machine.Namespace, "instance", instance)

switch instance.State {
case v1alpha1.InstanceStateRunning:
klog.Infof("Machine %v is running", *scope.MachineStatus.InstanceID)
a.log.Info("Machine instance is running", "instance-id", *scope.MachineStatus.InstanceID)
case v1alpha1.InstanceStatePending:
klog.Infof("Machine %v is pending", *scope.MachineStatus.InstanceID)
a.log.Info("Machine instance is pending", "instance-id", *scope.MachineStatus.InstanceID)
default:
return false, nil
}
Expand All @@ -442,12 +447,13 @@ func (a *Actuator) Exists(ctx context.Context, cluster *clusterv1.Cluster, machi
if machine.Status.NodeRef == nil {
nodeRef, err := a.getNodeReference(scope)
if err != nil {
klog.Warningf("Failed to set nodeRef: %v", err)
// non critical error
a.log.Info("Failed to set nodeRef", "error", err)
return true, nil
}

scope.Machine.Status.NodeRef = nodeRef
klog.Infof("Setting machine %q nodeRef to %q", scope.Name(), nodeRef.Name)
a.log.Info("Setting machine's nodeRef", "machine-name", scope.Name(), "machine-namespace", scope.Namespace(), "nodeRef", nodeRef.Name)
}

return true, nil
Expand Down
39 changes: 23 additions & 16 deletions pkg/cloud/aws/actuators/machine_scope.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,10 +17,12 @@ limitations under the License.
package actuators

import (
"fmt"

"github.com/go-logr/logr"
"github.com/pkg/errors"
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
"k8s.io/apimachinery/pkg/runtime"
"k8s.io/klog"
"sigs.k8s.io/cluster-api-provider-aws/pkg/apis/awsprovider/v1alpha1"
clusterv1 "sigs.k8s.io/cluster-api/pkg/apis/cluster/v1alpha1"
client "sigs.k8s.io/cluster-api/pkg/client/clientset_generated/clientset/typed/cluster/v1alpha1"
Expand All @@ -33,17 +35,22 @@ type MachineScopeParams struct {
Cluster *clusterv1.Cluster
Machine *clusterv1.Machine
Client client.ClusterV1alpha1Interface
Logger logr.Logger
}

// NewMachineScope creates a new MachineScope from the supplied parameters.
// This is meant to be called for each machine actuator operation.
func NewMachineScope(params MachineScopeParams) (*MachineScope, error) {
scope, err := NewScope(ScopeParams{AWSClients: params.AWSClients, Client: params.Client, Cluster: params.Cluster})
scope, err := NewScope(ScopeParams{
AWSClients: params.AWSClients,
Client: params.Client, Cluster: params.Cluster,
Logger: params.Logger,
Copy link
Member

Choose a reason for hiding this comment

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

Should the WithName context be added here instead of below?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

No, otherwise machine will come before the APIVersion

})
if err != nil {
return nil, err
}

machineConfig, err := MachineConfigFromProviderSpec(params.Client, params.Machine.Spec.ProviderSpec)
machineConfig, err := MachineConfigFromProviderSpec(params.Client, params.Machine.Spec.ProviderSpec, scope.Logger)
if err != nil {
return nil, errors.Wrap(err, "failed to get machine config")
}
Expand All @@ -57,7 +64,7 @@ func NewMachineScope(params MachineScopeParams) (*MachineScope, error) {
if params.Client != nil {
machineClient = params.Client.Machines(params.Machine.Namespace)
}

scope.Logger = scope.Logger.WithName(params.Machine.Name)
detiber marked this conversation as resolved.
Show resolved Hide resolved
return &MachineScope{
Scope: scope,
Machine: params.Machine,
Expand Down Expand Up @@ -136,54 +143,54 @@ func (m *MachineScope) Close() {

latestMachine, err := m.storeMachineSpec(m.Machine)
if err != nil {
klog.Errorf("[machinescope] failed to update machine %q in namespace %q: %v", m.Machine.Name, m.Machine.Namespace, err)
m.Error(err, "failed to update machine")
return
}

_, err = m.storeMachineStatus(latestMachine)
if err != nil {
klog.Errorf("[machinescope] failed to store provider status for machine %q in namespace %q: %v", m.Machine.Name, m.Machine.Namespace, err)
m.Error(err, "failed to store machine provider status")
}
}

// MachineConfigFromProviderSpec tries to decode the JSON-encoded spec, falling back on getting a MachineClass if the value is absent.
func MachineConfigFromProviderSpec(clusterClient client.MachineClassesGetter, providerConfig clusterv1.ProviderSpec) (*v1alpha1.AWSMachineProviderSpec, error) {
func MachineConfigFromProviderSpec(clusterClient client.MachineClassesGetter, providerConfig clusterv1.ProviderSpec, log logr.Logger) (*v1alpha1.AWSMachineProviderSpec, error) {
Copy link
Member

Choose a reason for hiding this comment

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

Can this function be made a method? Is it used anywhere else? If so, I'm not sure if the log lines should actually be in here or expect the caller would log.

Copy link
Contributor Author

Choose a reason for hiding this comment

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

yes, this needs refactoring. I'll add it to the list of follow on issues.

var config v1alpha1.AWSMachineProviderSpec
if providerConfig.Value != nil {
klog.V(4).Info("Decoding ProviderConfig from Value")
return unmarshalProviderSpec(providerConfig.Value)
log.V(4).Info("Decoding ProviderConfig from Value")
return unmarshalProviderSpec(providerConfig.Value, log)
}

if providerConfig.ValueFrom != nil && providerConfig.ValueFrom.MachineClass != nil {
ref := providerConfig.ValueFrom.MachineClass
klog.V(4).Info("Decoding ProviderConfig from MachineClass")
klog.V(6).Infof("ref: %v", ref)
log.V(4).Info("Decoding ProviderConfig from MachineClass")
log.V(6).Info("Machine class reference", "ref", fmt.Sprintf("%+v", ref))
if ref.Provider != "" && ref.Provider != "aws" {
return nil, errors.Errorf("Unsupported provider: %q", ref.Provider)
}

if len(ref.Namespace) > 0 && len(ref.Name) > 0 {
klog.V(4).Infof("Getting MachineClass: %s/%s", ref.Namespace, ref.Name)
log.V(4).Info("Getting MachineClass", "reference-namespace", ref.Namespace, "reference-name", ref.Name)
mc, err := clusterClient.MachineClasses(ref.Namespace).Get(ref.Name, metav1.GetOptions{})
klog.V(6).Infof("Retrieved MachineClass: %+v", mc)
log.V(6).Info("Retrieved MachineClass", "machine-class", fmt.Sprintf("%+v", mc))
if err != nil {
return nil, err
}
providerConfig.Value = &mc.ProviderSpec
return unmarshalProviderSpec(&mc.ProviderSpec)
return unmarshalProviderSpec(&mc.ProviderSpec, log)
}
}

return &config, nil
}

func unmarshalProviderSpec(spec *runtime.RawExtension) (*v1alpha1.AWSMachineProviderSpec, error) {
func unmarshalProviderSpec(spec *runtime.RawExtension, log logr.Logger) (*v1alpha1.AWSMachineProviderSpec, error) {
Copy link
Member

Choose a reason for hiding this comment

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

Same as above

Copy link
Contributor Author

Choose a reason for hiding this comment

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

also added

var config v1alpha1.AWSMachineProviderSpec
if spec != nil {
if err := yaml.Unmarshal(spec.Raw, &config); err != nil {
return nil, err
}
}
klog.V(6).Infof("Found ProviderSpec: %+v", config)
log.V(6).Info("Found ProviderSpec", "provider-spec", fmt.Sprintf("%+v", config))
return &config, nil
}
Loading