Skip to content

Commit ad9ebdb

Browse files
dhawosdhawos
committed
chore(logs): standardize application logging
Signed-off-by: Louis Gérard <[email protected]>
1 parent 5ef4faa commit ad9ebdb

File tree

12 files changed

+142
-111
lines changed

12 files changed

+142
-111
lines changed

‎applicationset/controllers/applicationset_controller.go‎

Lines changed: 13 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,7 @@ import (
5151
"github.com/argoproj/argo-cd/v3/applicationset/status"
5252
"github.com/argoproj/argo-cd/v3/applicationset/utils"
5353
"github.com/argoproj/argo-cd/v3/common"
54+
applog "github.com/argoproj/argo-cd/v3/util/app/log"
5455
"github.com/argoproj/argo-cd/v3/util/db"
5556

5657
argov1alpha1 "github.com/argoproj/argo-cd/v3/pkg/apis/application/v1alpha1"
@@ -575,7 +576,7 @@ func (r *ApplicationSetReconciler) createOrUpdateInCluster(ctx context.Context,
575576
var firstError error
576577
// Creates or updates the application in appList
577578
for _, generatedApp := range desiredApplications {
578-
appLog := logCtx.WithFields(log.Fields{"app": generatedApp.QualifiedName()})
579+
appLog := logCtx.WithFields(applog.GetAppLog(&generatedApp))
579580

580581
// Normalize to avoid fighting with the application controller.
581582
generatedApp.Spec = *argoutil.NormalizeApplicationSpec(&generatedApp.Spec)
@@ -738,7 +739,7 @@ func (r *ApplicationSetReconciler) deleteInCluster(ctx context.Context, logCtx *
738739
// Delete apps that are not in m[string]bool
739740
var firstError error
740741
for _, app := range current {
741-
logCtx = logCtx.WithField("app", app.QualifiedName())
742+
logCtx = logCtx.WithFields(applog.GetAppLog(&app))
742743
_, exists := m[app.Name]
743744

744745
if !exists {
@@ -1463,23 +1464,23 @@ func getApplicationOwnsHandler(enableProgressiveSyncs bool) predicate.Funcs {
14631464
// if we are the owner and there is a create event, we most likely created it and do not need to
14641465
// re-reconcile
14651466
if log.IsLevelEnabled(log.DebugLevel) {
1466-
var appName string
1467+
logFields := log.Fields{"app": ""}
14671468
app, isApp := e.Object.(*argov1alpha1.Application)
14681469
if isApp {
1469-
appName = app.QualifiedName()
1470+
logFields = applog.GetAppLog(app)
14701471
}
1471-
log.WithField("app", appName).Debugln("received create event from owning an application")
1472+
log.WithFields(logFields).Debugln("received create event from owning an application")
14721473
}
14731474
return false
14741475
},
14751476
DeleteFunc: func(e event.DeleteEvent) bool {
14761477
if log.IsLevelEnabled(log.DebugLevel) {
1477-
var appName string
1478+
logFields := log.Fields{"app": ""}
14781479
app, isApp := e.Object.(*argov1alpha1.Application)
14791480
if isApp {
1480-
appName = app.QualifiedName()
1481+
logFields = applog.GetAppLog(app)
14811482
}
1482-
log.WithField("app", appName).Debugln("received delete event from owning an application")
1483+
log.WithFields(logFields).Debugln("received delete event from owning an application")
14831484
}
14841485
return true
14851486
},
@@ -1488,7 +1489,7 @@ func getApplicationOwnsHandler(enableProgressiveSyncs bool) predicate.Funcs {
14881489
if !isApp {
14891490
return false
14901491
}
1491-
logCtx := log.WithField("app", appOld.QualifiedName())
1492+
logCtx := log.WithFields(applog.GetAppLog(appOld))
14921493
logCtx.Debugln("received update event from owning an application")
14931494
appNew, isApp := e.ObjectNew.(*argov1alpha1.Application)
14941495
if !isApp {
@@ -1500,12 +1501,12 @@ func getApplicationOwnsHandler(enableProgressiveSyncs bool) predicate.Funcs {
15001501
},
15011502
GenericFunc: func(e event.GenericEvent) bool {
15021503
if log.IsLevelEnabled(log.DebugLevel) {
1503-
var appName string
1504+
logFields := log.Fields{}
15041505
app, isApp := e.Object.(*argov1alpha1.Application)
15051506
if isApp {
1506-
appName = app.QualifiedName()
1507+
logFields = applog.GetAppLog(app)
15071508
}
1508-
log.WithField("app", appName).Debugln("received generic event from owning an application")
1509+
log.WithFields(logFields).Debugln("received generic event from owning an application")
15091510
}
15101511
return true
15111512
},

‎applicationset/controllers/applicationset_controller_test.go‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -37,6 +37,7 @@ import (
3737
argocommon "github.com/argoproj/argo-cd/v3/common"
3838
"github.com/argoproj/argo-cd/v3/pkg/apis/application"
3939
"github.com/argoproj/argo-cd/v3/pkg/apis/application/v1alpha1"
40+
applog "github.com/argoproj/argo-cd/v3/util/app/log"
4041
"github.com/argoproj/argo-cd/v3/util/db"
4142
"github.com/argoproj/argo-cd/v3/util/settings"
4243
)
@@ -1178,7 +1179,7 @@ func TestRemoveFinalizerOnInvalidDestination_FinalizerTypes(t *testing.T) {
11781179
clusterList, err := utils.ListClusters(context.Background(), kubeclientset, "namespace")
11791180
require.NoError(t, err)
11801181

1181-
appLog := log.WithFields(log.Fields{"app": app.Name, "appSet": ""})
1182+
appLog := log.WithFields(applog.GetAppLog(&app)).WithField("appSet", "")
11821183

11831184
appInputParam := app.DeepCopy()
11841185

@@ -1335,7 +1336,7 @@ func TestRemoveFinalizerOnInvalidDestination_DestinationTypes(t *testing.T) {
13351336
clusterList, err := utils.ListClusters(context.Background(), kubeclientset, "argocd")
13361337
require.NoError(t, err)
13371338

1338-
appLog := log.WithFields(log.Fields{"app": app.Name, "appSet": ""})
1339+
appLog := log.WithFields(applog.GetAppLog(&app)).WithField("appSet", "")
13391340

13401341
appInputParam := app.DeepCopy()
13411342

‎controller/appcontroller.go‎

Lines changed: 22 additions & 30 deletions
Original file line numberDiff line numberDiff line change
@@ -54,6 +54,7 @@ import (
5454
"github.com/argoproj/argo-cd/v3/pkg/client/informers/externalversions/application/v1alpha1"
5555
applisters "github.com/argoproj/argo-cd/v3/pkg/client/listers/application/v1alpha1"
5656
"github.com/argoproj/argo-cd/v3/reposerver/apiclient"
57+
applog "github.com/argoproj/argo-cd/v3/util/app/log"
5758
"github.com/argoproj/argo-cd/v3/util/argo"
5859
argodiff "github.com/argoproj/argo-cd/v3/util/argo/diff"
5960
"github.com/argoproj/argo-cd/v3/util/argo/normalizers"
@@ -98,15 +99,6 @@ func (a CompareWith) Pointer() *CompareWith {
9899
return &a
99100
}
100101

101-
func getAppLog(app *appv1.Application) *log.Entry {
102-
return log.WithFields(log.Fields{
103-
"application": app.Name,
104-
"app-namespace": app.Namespace,
105-
"app-qualified-name": app.QualifiedName(),
106-
"project": app.Spec.Project,
107-
})
108-
}
109-
110102
// ApplicationController is the controller for application resources.
111103
type ApplicationController struct {
112104
cache *appstatecache.Cache
@@ -439,7 +431,7 @@ func (ctrl *ApplicationController) handleObjectUpdated(managedByApp map[string]b
439431
continue
440432
}
441433

442-
logCtx := getAppLog(app)
434+
logCtx := log.WithFields(applog.GetAppLog(app))
443435
// Enforce application's permission for the source namespace
444436
_, err = ctrl.getAppProj(app)
445437
if err != nil {
@@ -475,7 +467,7 @@ func (ctrl *ApplicationController) handleObjectUpdated(managedByApp map[string]b
475467
func (ctrl *ApplicationController) setAppManagedResources(destCluster *appv1.Cluster, a *appv1.Application, comparisonResult *comparisonResult) (*appv1.ApplicationTree, error) {
476468
ts := stats.NewTimingStats()
477469
defer func() {
478-
logCtx := getAppLog(a)
470+
logCtx := log.WithFields(applog.GetAppLog(a))
479471
for k, v := range ts.Timings() {
480472
logCtx = logCtx.WithField(k, v.Milliseconds())
481473
}
@@ -532,7 +524,7 @@ func isKnownOrphanedResourceExclusion(key kube.ResourceKey, proj *appv1.AppProje
532524
func (ctrl *ApplicationController) getResourceTree(destCluster *appv1.Cluster, a *appv1.Application, managedResources []*appv1.ResourceDiff) (*appv1.ApplicationTree, error) {
533525
ts := stats.NewTimingStats()
534526
defer func() {
535-
logCtx := getAppLog(a)
527+
logCtx := log.WithFields(applog.GetAppLog(a))
536528
for k, v := range ts.Timings() {
537529
logCtx = logCtx.WithField(k, v.Milliseconds())
538530
}
@@ -662,7 +654,7 @@ func (ctrl *ApplicationController) getResourceTree(destCluster *appv1.Cluster, a
662654
func (ctrl *ApplicationController) getAppHosts(destCluster *appv1.Cluster, a *appv1.Application, appNodes []appv1.ResourceNode) ([]appv1.HostInfo, error) {
663655
ts := stats.NewTimingStats()
664656
defer func() {
665-
logCtx := getAppLog(a)
657+
logCtx := log.WithFields(applog.GetAppLog(a))
666658
for k, v := range ts.Timings() {
667659
logCtx = logCtx.WithField(k, v.Milliseconds())
668660
}
@@ -990,7 +982,7 @@ func (ctrl *ApplicationController) processAppOperationQueueItem() (processNext b
990982
return
991983
}
992984
app := origApp.DeepCopy()
993-
logCtx := getAppLog(app)
985+
logCtx := log.WithFields(applog.GetAppLog(app))
994986
ts := stats.NewTimingStats()
995987
defer func() {
996988
for k, v := range ts.Timings() {
@@ -1154,7 +1146,7 @@ func (ctrl *ApplicationController) getPermittedAppLiveObjects(destCluster *appv1
11541146
}
11551147

11561148
func (ctrl *ApplicationController) finalizeApplicationDeletion(app *appv1.Application, projectClusters func(project string) ([]*appv1.Cluster, error)) error {
1157-
logCtx := getAppLog(app)
1149+
logCtx := log.WithFields(applog.GetAppLog(app))
11581150
// Get refreshed application info, since informer app copy might be stale
11591151
app, err := ctrl.applicationClientset.ArgoprojV1alpha1().Applications(app.Namespace).Get(context.Background(), app.Name, metav1.GetOptions{})
11601152
if err != nil {
@@ -1312,7 +1304,7 @@ func (ctrl *ApplicationController) updateFinalizers(app *appv1.Application) erro
13121304
}
13131305

13141306
func (ctrl *ApplicationController) setAppCondition(app *appv1.Application, condition appv1.ApplicationCondition) {
1315-
logCtx := getAppLog(app)
1307+
logCtx := log.WithFields(applog.GetAppLog(app))
13161308
// do nothing if app already has same condition
13171309
for _, c := range app.Status.Conditions {
13181310
if c.Message == condition.Message && c.Type == condition.Type {
@@ -1337,7 +1329,7 @@ func (ctrl *ApplicationController) setAppCondition(app *appv1.Application, condi
13371329
}
13381330

13391331
func (ctrl *ApplicationController) processRequestedAppOperation(app *appv1.Application) {
1340-
logCtx := getAppLog(app)
1332+
logCtx := log.WithFields(applog.GetAppLog(app))
13411333
var state *appv1.OperationState
13421334
// Recover from any unexpected panics and automatically set the status to be failed
13431335
defer func() {
@@ -1473,7 +1465,7 @@ func (ctrl *ApplicationController) processRequestedAppOperation(app *appv1.Appli
14731465
}
14741466

14751467
func (ctrl *ApplicationController) setOperationState(app *appv1.Application, state *appv1.OperationState) {
1476-
logCtx := getAppLog(app)
1468+
logCtx := log.WithFields(applog.GetAppLog(app))
14771469
if state.Phase == "" {
14781470
// expose any bugs where we neglect to set phase
14791471
panic("no phase was set")
@@ -1551,7 +1543,7 @@ func (ctrl *ApplicationController) setOperationState(app *appv1.Application, sta
15511543
// writeBackToInformer writes a just recently updated App back into the informer cache.
15521544
// This prevents the situation where the controller operates on a stale app and repeats work
15531545
func (ctrl *ApplicationController) writeBackToInformer(app *appv1.Application) {
1554-
logCtx := getAppLog(app).WithField("informer-writeBack", true)
1546+
logCtx := log.WithFields(applog.GetAppLog(app)).WithField("informer-writeBack", true)
15551547
err := ctrl.appInformer.GetStore().Update(app)
15561548
if err != nil {
15571549
logCtx.Errorf("failed to update informer store: %v", err)
@@ -1608,7 +1600,7 @@ func (ctrl *ApplicationController) processAppRefreshQueueItem() (processNext boo
16081600
return
16091601
}
16101602
app := origApp.DeepCopy()
1611-
logCtx := getAppLog(app).WithFields(log.Fields{
1603+
logCtx := log.WithFields(applog.GetAppLog(app)).WithFields(log.Fields{
16121604
"comparison-level": comparisonLevel,
16131605
"dest-server": origApp.Spec.Destination.Server,
16141606
"dest-name": origApp.Spec.Destination.Name,
@@ -1814,7 +1806,7 @@ func (ctrl *ApplicationController) processAppHydrateQueueItem() (processNext boo
18141806

18151807
ctrl.hydrator.ProcessAppHydrateQueueItem(origApp)
18161808

1817-
getAppLog(origApp).Debug("Successfully processed app hydrate queue item")
1809+
log.WithFields(applog.GetAppLog(origApp)).Debug("Successfully processed app hydrate queue item")
18181810
return
18191811
}
18201812

@@ -1863,7 +1855,7 @@ func currentSourceEqualsSyncedSource(app *appv1.Application) bool {
18631855
// Additionally, it returns whether full refresh was requested or not.
18641856
// If full refresh is requested then target and live state should be reconciled, else only live state tree should be updated.
18651857
func (ctrl *ApplicationController) needRefreshAppStatus(app *appv1.Application, statusRefreshTimeout, statusHardRefreshTimeout time.Duration) (bool, appv1.RefreshType, CompareWith) {
1866-
logCtx := getAppLog(app)
1858+
logCtx := log.WithFields(applog.GetAppLog(app))
18671859
var reason string
18681860
compareWith := CompareWithLatest
18691861
refreshType := appv1.RefreshTypeNormal
@@ -1941,7 +1933,7 @@ func (ctrl *ApplicationController) refreshAppConditions(app *appv1.Application)
19411933
// normalizeApplication normalizes an application.spec and additionally persists updates if it changed
19421934
func (ctrl *ApplicationController) normalizeApplication(orig, app *appv1.Application) {
19431935
app.Spec = *argo.NormalizeApplicationSpec(&app.Spec)
1944-
logCtx := getAppLog(app)
1936+
logCtx := log.WithFields(applog.GetAppLog(app))
19451937

19461938
patch, modified, err := diff.CreateTwoWayMergePatch(orig, app, appv1.Application{})
19471939

@@ -1975,7 +1967,7 @@ func createMergePatch(orig, new any) ([]byte, bool, error) {
19751967

19761968
// persistAppStatus persists updates to application status. If no changes were made, it is a no-op
19771969
func (ctrl *ApplicationController) persistAppStatus(orig *appv1.Application, newStatus *appv1.ApplicationStatus) (patchMs time.Duration) {
1978-
logCtx := getAppLog(orig)
1970+
logCtx := log.WithFields(applog.GetAppLog(orig))
19791971
if orig.Status.Sync.Status != newStatus.Sync.Status {
19801972
message := fmt.Sprintf("Updated sync status: %s -> %s", orig.Status.Sync.Status, newStatus.Sync.Status)
19811973
ctrl.logAppEvent(context.TODO(), orig, argo.EventInfo{Reason: argo.EventReasonResourceUpdated, Type: corev1.EventTypeNormal}, message)
@@ -2020,7 +2012,7 @@ func (ctrl *ApplicationController) persistAppStatus(orig *appv1.Application, new
20202012

20212013
// autoSync will initiate a sync operation for an application configured with automated sync
20222014
func (ctrl *ApplicationController) autoSync(app *appv1.Application, syncStatus *appv1.SyncStatus, resources []appv1.ResourceStatus, revisionUpdated bool) (*appv1.ApplicationCondition, time.Duration) {
2023-
logCtx := getAppLog(app)
2015+
logCtx := log.WithFields(applog.GetAppLog(app))
20242016
ts := stats.NewTimingStats()
20252017
defer func() {
20262018
for k, v := range ts.Timings() {
@@ -2181,16 +2173,16 @@ func alreadyAttemptedSync(app *appv1.Application, commitSHA string, commitSHAsMS
21812173
return false, ""
21822174
}
21832175
} else {
2184-
log.WithField("application", app.Name).Debugf("Skipping auto-sync: commitSHA %s has no changes", commitSHA)
2176+
log.WithFields(applog.GetAppLog(app)).Debugf("Skipping auto-sync: commitSHA %s has no changes", commitSHA)
21852177
}
21862178
} else {
21872179
if revisionUpdated {
2188-
log.WithField("application", app.Name).Infof("Executing compare of syncResult.Revision and commitSha because manifest changed: %v", commitSHA)
2180+
log.WithFields(applog.GetAppLog(app)).Infof("Executing compare of syncResult.Revision and commitSha because manifest changed: %v", commitSHA)
21892181
if app.Status.OperationState.SyncResult.Revision != commitSHA {
21902182
return false, ""
21912183
}
21922184
} else {
2193-
log.WithField("application", app.Name).Debugf("Skipping auto-sync: commitSHA %s has no changes", commitSHA)
2185+
log.WithFields(applog.GetAppLog(app)).Debugf("Skipping auto-sync: commitSHA %s has no changes", commitSHA)
21942186
}
21952187
}
21962188

@@ -2249,7 +2241,7 @@ func (ctrl *ApplicationController) canProcessApp(obj any) bool {
22492241

22502242
if annotations := app.GetAnnotations(); annotations != nil {
22512243
if skipVal, ok := annotations[common.AnnotationKeyAppSkipReconcile]; ok {
2252-
logCtx := getAppLog(app)
2244+
logCtx := log.WithFields(applog.GetAppLog(app))
22532245
if skipReconcile, err := strconv.ParseBool(skipVal); err == nil {
22542246
if skipReconcile {
22552247
logCtx.Debugf("Skipping Application reconcile based on annotation %s", common.AnnotationKeyAppSkipReconcile)
@@ -2376,7 +2368,7 @@ func (ctrl *ApplicationController) newApplicationInformerAndLister() (cache.Shar
23762368
newApp, newOK := new.(*appv1.Application)
23772369
if oldOK && newOK {
23782370
if automatedSyncEnabled(oldApp, newApp) {
2379-
getAppLog(newApp).Info("Enabled automated sync")
2371+
log.WithFields(applog.GetAppLog(newApp)).Info("Enabled automated sync")
23802372
compareWith = CompareWithLatest.Pointer()
23812373
}
23822374
if ctrl.statusRefreshJitter != 0 && oldApp.ResourceVersion == newApp.ResourceVersion {

‎controller/health.go‎

Lines changed: 6 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -11,10 +11,11 @@ import (
1111
metav1 "k8s.io/apimachinery/pkg/apis/meta/v1"
1212
"k8s.io/apimachinery/pkg/runtime/schema"
1313

14-
"github.com/argoproj/argo-cd/v3/common"
15-
"github.com/argoproj/argo-cd/v3/pkg/apis/application"
16-
appv1 "github.com/argoproj/argo-cd/v3/pkg/apis/application/v1alpha1"
17-
"github.com/argoproj/argo-cd/v3/util/lua"
14+
"github.com/argoproj/argo-cd/v2/common"
15+
"github.com/argoproj/argo-cd/v2/pkg/apis/application"
16+
appv1 "github.com/argoproj/argo-cd/v2/pkg/apis/application/v1alpha1"
17+
"github.com/argoproj/argo-cd/v2/util/lua"
18+
applog "github.com/argoproj/argo-cd/v3/util/app/log"
1819
)
1920

2021
// setApplicationHealth updates the health statuses of all resources performed in the comparison
@@ -51,7 +52,7 @@ func setApplicationHealth(resources []managedResource, statuses []appv1.Resource
5152
errCount++
5253
savedErr = fmt.Errorf("failed to get resource health for %q with name %q in namespace %q: %w", res.Live.GetKind(), res.Live.GetName(), res.Live.GetNamespace(), err)
5354
// also log so we don't lose the message
54-
log.WithField("application", app.QualifiedName()).Warn(savedErr)
55+
log.WithFields(applog.GetAppLog(app)).Warn(savedErr)
5556
}
5657
}
5758

‎controller/hydrator/hydrator.go‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -11,9 +11,9 @@ import (
1111
"k8s.io/apimachinery/pkg/apis/meta/v1/unstructured"
1212

1313
commitclient "github.com/argoproj/argo-cd/v3/commitserver/apiclient"
14-
"github.com/argoproj/argo-cd/v3/controller/utils"
1514
appv1 "github.com/argoproj/argo-cd/v3/pkg/apis/application/v1alpha1"
1615
"github.com/argoproj/argo-cd/v3/reposerver/apiclient"
16+
applog "github.com/argoproj/argo-cd/v3/util/app/log"
1717
argoio "github.com/argoproj/argo-cd/v3/util/io"
1818
)
1919

@@ -55,7 +55,7 @@ func (h *Hydrator) ProcessAppHydrateQueueItem(origApp *appv1.Application) {
5555
return
5656
}
5757

58-
logCtx := utils.GetAppLog(app)
58+
logCtx := log.WithFields(applog.GetAppLog(app))
5959

6060
logCtx.Debug("Processing app hydrate queue item")
6161

@@ -130,7 +130,7 @@ func (h *Hydrator) ProcessHydrationQueueItem(hydrationKey HydrationQueueKey) (pr
130130
// in case we did.
131131
app.Status.SourceHydrator.CurrentOperation.DrySHA = drySHA
132132
h.dependencies.PersistAppHydratorStatus(origApp, &app.Status.SourceHydrator)
133-
logCtx = logCtx.WithField("app", app.QualifiedName())
133+
logCtx = logCtx.WithFields(applog.GetAppLog(app))
134134
logCtx.Errorf("Failed to hydrate app: %v", err)
135135
}
136136
return

0 commit comments

Comments
 (0)