Improve logs according to new guidelines

[fabriziopandini]

We recently merged our logging guidelines and a first PR ensuring all the logs from a reconcile have consistent keys.

Now it is possible make a pass on our controller and improve existing log messages to take benefit of key-value pairs, and a good way to do so is to focus on a simple workflow supported by CAPI, and make sure logs are representing what happens and all the dependencies across objects.

e.g I created a management cluster with logging enabled using Tilt, I created a cluster, and take a look at the logs documenting a machine being provisioned by using the following query: {app="capi-controller-manager",controller="machine"} | json | machine_name="classy1-23696-sxcsn-2jkvs"

msg="Bootstrap provider is not ready, requeuing" v=0
msg="Infrastructure provider is not ready, requeuing" v=0
msg="Cannot reconcile Machine's Node, no valid ProviderID yet" v=0
...
msg="Set Machine's NodeRef" v=0

They are ok, but we can do better, by making more explicit what we are waiting for and adding some more details when provisioning completes. So I created a small PR that gives us the following output:

msg="Waiting for bootstrap provider to generate data secret and report status.ready, requeing" v=0 (with a key value pair for the bootstrap object)
msg="Waiting for infrastructure provider to create machine infrastructure and report status.ready, requeing" v=0 (with a key value pair for the infrastructure object)
msg="Waiting for infrastructure provider to report spec.ProviderID, requeing" v=0 (with a key value pair for the infrastructure object)
...
msg="Bootstrap provider generated data secret and reports status.ready" v=0 (with a key value pair for the bootstrap object and one for the secret)
...
msg="Infrastructure provider completed machine infrastructure provisioning and reports status.ready" v=0 (with a key value pair for the infrastructure object)
msg="Infrastructure provider reporting spec.ProviderID, Kubernetes node is now available" v=0 (with a key value pair for the infrastructure object, one for providerID and one for the node)

And the idea behind this issue is to rally the community for creating similar PRs, each one doing small, incremental improvements for one of the Cluster API workflows:

• Cluster controller provisioning infrastructure
• Cluster deletion (@valaparthvi)
• Machine deletion
• Node deletion
• KCP creating/deleting Machine
• KCP remediating a Machine
• MD creating/deleting MS 🌱 [WIP] Improve logging for MachineDeployment scale up&down workflow #7168 (@furkatgofurov7)
• MS creating/deleting Machines 🌱 Improve logging for the MachineSet scale up/down workflow #7026 (@fabriziopandini)
• MS remediating a Machine
• MHC triggering machine remediation
• structuredmerge package
• (probably more, let me know).

Also worth to notice this is a great opportunity for people willing to dig in into CAPI and learn how things work

/help wanted
/kind cleanup

[fabriziopandini]

/help-wanted

[furkatgofurov7]

@fabriziopandini hi, I am happy to take up a few items from the list. For the start, I can go with MD creating/deleting MS, if no one is working on it.

[sbueringer]

@furkatgofurov7 Sounds great! Just go ahead, first come first serve. I'll reserve the sub-task for you above

[sbueringer]

@fabriziopandini Can we add another sub-task for the structuredmerge package?

I think it would be good if we had more logs there to make it easier to debug.
In my specific case I wanted to know what diff was detected by SSA, i.e.. why were there changes, but no spec changes.

xref: https://kubernetes.slack.com/archives/C8TSNPY4T/p1662462731560389

[valaparthvi]

I'd like to pick up Cluster deletion! @sbueringer, can you please reserve that for me?

[sbueringer]

Sure, done!

[fabriziopandini]

this is long tail of activity, not blocking for the milestone

[k8s-triage-robot]

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

This bot triages 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 PR is closed

You can:

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

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

/lifecycle stale

[sbueringer]

/remove-lifecycle stale

[fabriziopandini]

/unassign

[fabriziopandini]

/close
we are iteratively doing this

[k8s-ci-robot]

@fabriziopandini: Closing this issue.

In response to this:

/close
we are iteratively doing this

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.