fix ever-growing log messages with overlapping fields #4302

nojnhuh · 2023-11-21T20:05:59Z

What type of PR is this?
/kind cleanup

What this PR does / why we need it:

The primary change here is to create new loggers (:= vs =) when adding key-value pairs to prevent those pairs from persisting longer than they should, leading to messages with an ever-growing set of redundant and mismatched values. A couple of other related minor changes also snuck into this PR.

Prevents log messages like:
I1121 02:04:56.879702 1 helpers.go:116] "unable to get the owner cluster" logger="controllers.AzureMachineReconciler.SetupWithManager" controller="AzureMachine" x-ms-correlation-request-id="53f02e71-85d8-45cc-9220-d6fa3c85d019" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-ode3dx-cc-vwfnf" Namespace="capz-e2e-ode3dx" AzureCluster="capz-e2e-ode3dx-cc-vwfnf" Namespace="capz-e2e-ode3dx" AzureCluster="capz-e2e-ode3dx-cc-vwfnf" Namespace="capz-e2e-ode3dx" AzureCluster="capz-e2e-ode3dx-cc-vwfnf" Namespace="capz-e2e-ode3dx" AzureCluster="capz-e2e-ode3dx-cc-vwfnf" Namespace="capz-e2e-ode3dx" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-tc4fvl-edgezone" Namespace="capz-e2e-tc4fvl" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-20z64k-dual-stack" Namespace="capz-e2e-20z64k" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-lmw5qj-intree" Namespace="capz-e2e-lmw5qj" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-gqwffh-azwi" Namespace="capz-e2e-gqwffh" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-jl3vsc-flatcar" Namespace="capz-e2e-jl3vsc" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-gl561r-flex" Namespace="capz-e2e-gl561r" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-m20fqa-gpu" Namespace="capz-e2e-m20fqa" AzureCluster="capz-e2e-a314xj-public-custom-vnet" Namespace="capz-e2e-a314xj" AzureCluster="capz-e2e-a314xj-public-custom-vnet" Namespace="capz-e2e-a314xj"

Which issue(s) this PR fixes (optional, in fixes #<issue number>(, fixes #<issue_number>, ...) format, will close the issue(s) when PR gets merged):
Fixes #

Special notes for your reviewer:

cherry-pick candidate

TODOs:

squashed commits
includes documentation
adds unit tests

Release note:

NONE

nojnhuh · 2023-11-21T20:06:27Z

controllers/asosecret_controller.go

@@ -116,7 +116,7 @@ func (asos *ASOSecretReconciler) Reconcile(ctx context.Context, req ctrl.Request
 	)
 	defer done()

-	log = log.WithValues("namespace", req.Namespace, "AzureCluster", req.Name)


AzureCluster is already set below if necessary.

nojnhuh · 2023-11-21T20:07:19Z

controllers/azureidentity_controller.go

@@ -151,8 +151,6 @@ func (r *AzureIdentityReconciler) Reconcile(ctx context.Context, req ctrl.Reques

 	var bindingsToDelete []aadpodv1.AzureIdentityBinding
 	for _, b := range bindings.Items {
-		log = log.WithValues("azureidentitybinding", b.Name)


This log was never getting used but the side effects from this WithValues would have persisted after this loop which doesn't seem right.

nojnhuh · 2023-11-21T20:11:09Z

/retest

codecov · 2023-11-21T20:16:55Z

Codecov Report

Attention: 2 lines in your changes are missing coverage. Please review.

Comparison is base (67b1dc2) 59.74% compared to head (e2fc46b) 59.75%.
Report is 18 commits behind head on main.

Files	Patch %	Lines
exp/controllers/helpers.go	33.33%	2 Missing ⚠️

Additional details and impacted files

@@           Coverage Diff           @@
##             main    #4302   +/-   ##
=======================================
  Coverage   59.74%   59.75%           
=======================================
  Files         192      192           
  Lines       19299    19297    -2     
=======================================
  Hits        11531    11531           
+ Misses       7137     7135    -2     
  Partials      631      631

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

nojnhuh · 2023-11-21T22:16:17Z

/retest

mboersma

/lgtm

k8s-ci-robot · 2023-11-22T22:06:46Z

LGTM label has been added.

Git tree hash: ec11983ef26596c42b679d270798bbc426eaf46c

CecileRobertMichon · 2023-11-28T01:11:36Z

/lgtm
/approve

k8s-ci-robot · 2023-11-28T01:11:43Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: CecileRobertMichon

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

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [CecileRobertMichon]

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 · 2023-11-28T03:31:21Z

@nojnhuh: 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-provider-azure-e2e-aks	`e2fc46b`	link	unknown	`/test pull-cluster-api-provider-azure-e2e-aks`

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.

nojnhuh · 2023-11-28T03:37:37Z

/retest

fix ever-growing log messages with overlapping fields

e2fc46b

k8s-ci-robot requested review from jackfrancis and willie-yao November 21, 2023 20:06

nojnhuh commented Nov 21, 2023

View reviewed changes

nojnhuh force-pushed the fix-infinilog branch from 8cd0171 to e2fc46b Compare November 21, 2023 20:08

mboersma reviewed Nov 22, 2023

View reviewed changes

k8s-ci-robot assigned mboersma Nov 22, 2023

k8s-ci-robot added the lgtm "Looks good to me", indicates that a PR is ready to be merged. label Nov 22, 2023

k8s-ci-robot assigned CecileRobertMichon Nov 28, 2023

k8s-ci-robot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Nov 28, 2023

k8s-ci-robot merged commit 209f6f2 into kubernetes-sigs:main Nov 28, 2023
10 checks passed

k8s-ci-robot added this to the v1.13 milestone Nov 28, 2023

nojnhuh deleted the fix-infinilog branch November 28, 2023 03:46

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix ever-growing log messages with overlapping fields #4302

fix ever-growing log messages with overlapping fields #4302

nojnhuh commented Nov 21, 2023

nojnhuh Nov 21, 2023

nojnhuh Nov 21, 2023

nojnhuh commented Nov 21, 2023

codecov bot commented Nov 21, 2023 •

edited

Loading

nojnhuh commented Nov 21, 2023

mboersma left a comment

k8s-ci-robot commented Nov 22, 2023

CecileRobertMichon commented Nov 28, 2023

k8s-ci-robot commented Nov 28, 2023

k8s-ci-robot commented Nov 28, 2023

nojnhuh commented Nov 28, 2023

fix ever-growing log messages with overlapping fields #4302

fix ever-growing log messages with overlapping fields #4302

Conversation

nojnhuh commented Nov 21, 2023

nojnhuh Nov 21, 2023

Choose a reason for hiding this comment

nojnhuh Nov 21, 2023

Choose a reason for hiding this comment

nojnhuh commented Nov 21, 2023

codecov bot commented Nov 21, 2023 • edited Loading

Codecov Report

nojnhuh commented Nov 21, 2023

mboersma left a comment

Choose a reason for hiding this comment

k8s-ci-robot commented Nov 22, 2023

CecileRobertMichon commented Nov 28, 2023

k8s-ci-robot commented Nov 28, 2023

k8s-ci-robot commented Nov 28, 2023

nojnhuh commented Nov 28, 2023

codecov bot commented Nov 21, 2023 •

edited

Loading