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

Jump to bottom

🌱 WIP: Reformat logs/bootstrap #6110

Closed

killianmuldoon wants to merge 7 commits into kubernetes-sigs:main from killianmuldoon:logs/bootstrap

Contributor

killianmuldoon commented Feb 11, 2022

This PR is a work in progress and leads on from #5571. This is a poc to see how we should improve our logging overall and should not be merged.

Add extra key-value pairs and add logging levels to logs in the bootstrap package.

k8s-ci-robot added cncf-cla: yes size/L labels

Contributor

k8s-ci-robot commented Feb 11, 2022

[APPROVALNOTIFIER] This PR is NOT APPROVED

This pull-request has been approved by:
To complete the pull request process, please assign neolit123 after the PR has been reviewed.
You can assign the PR to them by writing /assign @neolit123 in a comment when ready.

The full list of commands accepted by this bot can be found here.

Needs approval from an approver in each of these files:

OWNERS

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

k8s-ci-robot requested review from fabriziopandini and stmcginnis

February 11, 2022 16:01

killianmuldoon force-pushed the logs/bootstrap branch 3 times, most recently from 78c3a2d to 412c1c3 Compare

February 16, 2022 12:24

k8s-ci-robot added the needs-rebase label

killianmuldoon force-pushed the logs/bootstrap branch 2 times, most recently from 45590c2 to 9098dfc Compare

February 23, 2022 12:39

killianmuldoon added 5 commits

February 23, 2022 12:44


          add json logging to bootstrap

354e8cf

Signed-off-by: killianmuldoon <kmuldoon@vmware.com>


          change log levels in bootstrap

0bdf829


          removed most debug level logs. removed scope logger

520c3bb


          add patch logging to util/patch

63a4ae6


          \merged with ctrlruntime customizations

ce4f037

killianmuldoon force-pushed the logs/bootstrap branch from 9098dfc to 1af7aa5 Compare

February 23, 2022 12:46

k8s-ci-robot removed the needs-rebase label

killianmuldoon force-pushed the logs/bootstrap branch 3 times, most recently from cc83ff8 to 1edf198 Compare

February 23, 2022 16:04


          update with logger customizer

47eee00

killianmuldoon force-pushed the logs/bootstrap branch 2 times, most recently from 75bcaeb to ee6b5b3 Compare

February 23, 2022 19:26


          add log sanitizer for patch

dffc1ae

killianmuldoon force-pushed the logs/bootstrap branch from ee6b5b3 to dffc1ae Compare

February 23, 2022 19:26

Contributor

k8s-ci-robot commented Feb 23, 2022

@killianmuldoon: The following test failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name	Commit	Details	Required	Rerun command
pull-cluster-api-verify-main	`dffc1ae`	link	true	`/test pull-cluster-api-verify-main`

Full PR test history. Your PR dashboard. Please help us cut down on flakes by linking to an open issue when you hit one in your PR.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. I understand the commands that are listed here.

fabriziopandini reviewed

View reviewed changes

Member

fabriziopandini left a comment

Some nits, but i really like the direction of this PR

bootstrap/kubeadm/internal/controllers/kubeadmconfig_controller.go

               	}
               	// Look up the owner of this kubeadm config if there is one
               	configOwner, err := bsutil.GetConfigOwner(ctx, r.Client, config)
               	if apierrors.IsNotFound(err) {
+              		log.Info("Reconcile finished - waiting for KubeadmConfig owner to be set by Machine or MachinePool controller")

Member

fabriziopandini Feb 24, 2022

What about

Suggested change

      
            		log.Info("Reconcile finished - waiting for KubeadmConfig owner to be set by Machine or MachinePool controller")
          
            		log.Info(fmt.Sprintf("Waiting for %s owner to be set by Machine or MachinePool controller", klog.KObj(KubeadmConfig))

So it will read

Reconciling ...
Waiting for ... owner to be set by Machine or MachinePool controller
No changes to ...

If this is ok let's apply to other similar messages (drop "Reconcile finished", add obj name)

bootstrap/kubeadm/internal/controllers/kubeadmconfig_controller.go

               		return ctrl.Result{}, err
               	}
               	if shouldRotate {
-              		log.V(2).Info("Creating new bootstrap token")

Member

fabriziopandini Feb 24, 2022

I will keep this otherwise it won't be clear why a new token has been created; might be the message should be "Rotating the bootstrap token for the MachinePool"

bootstrap/kubeadm/internal/controllers/kubeadmconfig_controller.go

               		// update the bootstrap data
               		return r.joinWorker(ctx, scope)
               	}
+              	log.Info("Extending MachinePool token lifetime")

Member

fabriziopandini Feb 24, 2022

I would drop this given that we are not extending token lifecycle but creating new tokens

bootstrap/kubeadm/internal/controllers/kubeadmconfig_controller.go

               		config.Spec.JoinConfiguration = &bootstrapv1.JoinConfiguration{}
               	}
               	// it's a control plane join
               	if configOwner.IsControlPlaneMachine() {
-              		return r.joinControlplane(ctx, scope)

Member

fabriziopandini Feb 24, 2022

I think we can drop this change and L287

bootstrap/kubeadm/internal/controllers/kubeadmconfig_controller.go

    
              		return ctrl.Result{RequeueAfter: 30 * time.Second}, nil

              	}

              	// if the machine has not ClusterConfiguration and InitConfiguration, requeue

              	if scope.Config.Spec.InitConfiguration == nil && scope.Config.Spec.ClusterConfiguration == nil {

              		scope.Info("Control plane is not ready, requeing joining control planes until ready.")

              		log.Info("Reconcile finished - control plane is not ready, requeuing joining control planes until ready")

Member

fabriziopandini Feb 24, 2022

Note for a follow up PR
We should drop RequeAfter and instead watch for machines (and probably MachinePools); same at line 382.

Member

fabriziopandini Feb 24, 2022

Should this be "Waiting for control plane object to be ready before generating DataSecret for ..."?
~same for L382

bootstrap/kubeadm/internal/controllers/kubeadmconfig_controller.go

               	if res, err := r.reconcileDiscovery(ctx, scope.Cluster, scope.Config, certificates); err != nil {
               		return ctrl.Result{}, err
               	} else if !res.IsZero() {
+              		log.Info("Reconcile finished - discovery configuration set")

Member

fabriziopandini Feb 24, 2022

I will drop this in favor of logging inside reconcileDiscovery when we return non zero values

bootstrap/kubeadm/internal/controllers/kubeadmconfig_controller.go

               		return ctrl.Result{}, err
               	}
+              	log.Info("Reconcile finished - bootstrap data generated for Machine")

Member

fabriziopandini Feb 24, 2022

I'm not sure about this message; is this a duplicate of the side effect? if not, should this have the secret KObj?

Member

fabriziopandini Feb 24, 2022

Similar consideration applies to joinWorker/joinControlplane

bootstrap/kubeadm/internal/locking/control_plane_init_mutex.go

               func (c *ControlPlaneInitMutex) Unlock(ctx context.Context, cluster *clusterv1.Cluster) bool {
               	sema := newSemaphore()
               	cmName := configMapName(cluster.Name)
-              	log := c.log.WithValues("namespace", cluster.Namespace, "cluster-name", cluster.Name, "configmap-name", cmName)
-              	log.Info("Checking for lock")
+              	log := c.log.WithValues("ConfigMap", fmt.Sprintf("%s/%s", cluster.Namespace, cmName), "Cluster", newkObj(cluster))

Member

fabriziopandini Feb 24, 2022

Can we use KObj/KRef?

k8s-ci-robot added the needs-rebase label

Contributor

k8s-ci-robot commented Mar 11, 2022

@killianmuldoon: PR needs rebase.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

k8s-triage-robot commented Jun 9, 2022

The Kubernetes project currently lacks enough contributors to adequately respond to all issues and PRs.

This bot triages issues and PRs according to the following rules:

After 90d of inactivity, lifecycle/stale is applied
After 30d of inactivity since lifecycle/stale was applied, lifecycle/rotten is applied
After 30d of inactivity since lifecycle/rotten was applied, the issue is closed

You can:

Mark this issue or PR as fresh with /remove-lifecycle stale
Mark this issue or PR as rotten with /lifecycle rotten
Close this issue or PR with /close
Offer to help out with Issue Triage

Please send feedback to sig-contributor-experience at kubernetes/community.

/lifecycle stale

k8s-ci-robot added the lifecycle/stale label

Member

vincepri commented Jun 17, 2022

@killianmuldoon do you still want to pursue these changes, or shall we close?

Contributor Author

killianmuldoon commented Jun 17, 2022

@killianmuldoon do you still want to pursue these changes, or shall we close?
I think I'll come back to this over the next few weeks.

Contributor Author

killianmuldoon commented Jul 6, 2022

Closing this for now as the changes are stale / behind where we are on logging right now. Will possibly come back to this on a new PR, or open a new PR with similar changes.

/close

k8s-ci-robot closed this

Contributor

k8s-ci-robot commented Jul 6, 2022

@killianmuldoon: Closed this PR.

In response to this:

Closing this for now as the changes are stale / behind where we are on logging right now. Will possibly come back to this on a new PR, or open a new PR with similar changes.

/close

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment