Skip to content

Commit

Permalink
chore: Improve appcontroller logs further - Closes [argoproj#18113] (a…
Browse files Browse the repository at this point in the history 
…rgoproj#18174)

* chore: Improve appcontroller logs further - Closes [argoproj#18113]

Add application fully qualified name as a logrus field to several places that were missing it.
Remove appNamespace field and replace application name with a fully qualified name in a few places for consistency.
Add app project to the log fields.

Signed-off-by: Andrii Korotkov <andrii.korotkov@verkada.com>

* chore: Switch to using separate field for application name and qualified name, add a common function for app log entry - Closes[argoproj#18113]

Signed-off-by: Andrii Korotkov <andrii.korotkov@verkada.com>

---------

Signed-off-by: Andrii Korotkov <andrii.korotkov@verkada.com>
  • Loading branch information
@andrii-korotkov-verkada @Hariharasuthan99
andrii-korotkov-verkada authored and Hariharasuthan99 committed Jun 16, 2024
1 parent c55f8cd commit 2dfccc5
Showing 1 changed file with 42 additions and 33 deletions.
75 changes: 42 additions & 33 deletions controller/appcontroller.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -97,6 +97,15 @@ func (a CompareWith) Pointer() *CompareWith {
return &a
}

func getAppLog(app *appv1.Application) *log.Entry {
return log.WithFields(log.Fields{
"application": app.Name,
"app-namespace": app.Namespace,
"app-qualified-name": app.QualifiedName(),
"project": app.Spec.Project,
})
}

// ApplicationController is the controller for application resources.
type ApplicationController struct {
cache *appstatecache.Cache
Expand Down Expand Up @@ -413,10 +422,11 @@ func (ctrl *ApplicationController) handleObjectUpdated(managedByApp map[string]b
continue
}

logCtx := getAppLog(app)
// Enforce application's permission for the source namespace
_, err = ctrl.getAppProj(app)
if err != nil {
log.Errorf("Unable to determine project for app '%s': %v", app.QualifiedName(), err)
logCtx.Errorf("Unable to determine project for app '%s': %v", app.QualifiedName(), err)
continue
}

Expand All @@ -429,15 +439,14 @@ func (ctrl *ApplicationController) handleObjectUpdated(managedByApp map[string]b
if ref.Namespace == "" {
namespace = "(cluster-scoped)"
}
log.WithFields(log.Fields{
"application": appKey,
"level": level,
"namespace": namespace,
"name": ref.Name,
"api-version": ref.APIVersion,
"kind": ref.Kind,
"server": app.Spec.Destination.Server,
"cluster-name": app.Spec.Destination.Name,
logCtx.WithFields(log.Fields{
"comparison-level": level,
"namespace": namespace,
"name": ref.Name,
"api-version": ref.APIVersion,
"kind": ref.Kind,
"server": app.Spec.Destination.Server,
"cluster-name": app.Spec.Destination.Name,
}).Debug("Requesting app refresh caused by object update")

ctrl.requestAppRefresh(app.QualifiedName(), &level, nil)
Expand Down Expand Up @@ -914,7 +923,7 @@ func (ctrl *ApplicationController) processAppOperationQueueItem() (processNext b
// We cannot rely on informer since applications might be updated by both application controller and api server.
freshApp, err := ctrl.applicationClientset.ArgoprojV1alpha1().Applications(app.ObjectMeta.Namespace).Get(context.Background(), app.ObjectMeta.Name, metav1.GetOptions{})
if err != nil {
log.Errorf("Failed to retrieve latest application state: %v", err)
getAppLog(app).Errorf("Failed to retrieve latest application state: %v", err)
return
}
app = freshApp
Expand Down Expand Up @@ -1061,23 +1070,24 @@ func (ctrl *ApplicationController) getPermittedAppLiveObjects(app *appv1.Applica
}

func (ctrl *ApplicationController) isValidDestination(app *appv1.Application) (bool, *appv1.Cluster) {
logCtx := getAppLog(app)
// Validate the cluster using the Application destination's `name` field, if applicable,
// and set the Server field, if needed.
if err := argo.ValidateDestination(context.Background(), &app.Spec.Destination, ctrl.db); err != nil {
log.Warnf("Unable to validate destination of the Application being deleted: %v", err)
logCtx.Warnf("Unable to validate destination of the Application being deleted: %v", err)
return false, nil
}

cluster, err := ctrl.db.GetCluster(context.Background(), app.Spec.Destination.Server)
if err != nil {
log.Warnf("Unable to locate cluster URL for Application being deleted: %v", err)
logCtx.Warnf("Unable to locate cluster URL for Application being deleted: %v", err)
return false, nil
}
return true, cluster
}

func (ctrl *ApplicationController) finalizeApplicationDeletion(app *appv1.Application, projectClusters func(project string) ([]*appv1.Cluster, error)) error {
logCtx := log.WithField("application", app.QualifiedName())
logCtx := getAppLog(app)
// Get refreshed application info, since informer app copy might be stale
app, err := ctrl.applicationClientset.ArgoprojV1alpha1().Applications(app.Namespace).Get(context.Background(), app.Name, metav1.GetOptions{})
if err != nil {
Expand Down Expand Up @@ -1225,6 +1235,7 @@ func (ctrl *ApplicationController) updateFinalizers(app *appv1.Application) erro
}

func (ctrl *ApplicationController) setAppCondition(app *appv1.Application, condition appv1.ApplicationCondition) {
logCtx := getAppLog(app)
// do nothing if app already has same condition
for _, c := range app.Status.Conditions {
if c.Message == condition.Message && c.Type == condition.Type {
Expand All @@ -1244,12 +1255,12 @@ func (ctrl *ApplicationController) setAppCondition(app *appv1.Application, condi
_, err = ctrl.applicationClientset.ArgoprojV1alpha1().Applications(app.Namespace).Patch(context.Background(), app.Name, types.MergePatchType, patch, metav1.PatchOptions{})
}
if err != nil {
log.Errorf("Unable to set application condition: %v", err)
logCtx.Errorf("Unable to set application condition: %v", err)
}
}

func (ctrl *ApplicationController) processRequestedAppOperation(app *appv1.Application) {
logCtx := log.WithField("application", app.QualifiedName())
logCtx := getAppLog(app)
var state *appv1.OperationState
// Recover from any unexpected panics and automatically set the status to be failed
defer func() {
Expand Down Expand Up @@ -1364,8 +1375,7 @@ func (ctrl *ApplicationController) processRequestedAppOperation(app *appv1.Appli
}

func (ctrl *ApplicationController) setOperationState(app *appv1.Application, state *appv1.OperationState) {
logCtx := log.WithFields(log.Fields{"application": app.Name, "appNamespace": app.Namespace, "project": app.Spec.Project})

logCtx := getAppLog(app)
if state.Phase == "" {
// expose any bugs where we neglect to set phase
panic("no phase was set")
Expand Down Expand Up @@ -1443,7 +1453,7 @@ func (ctrl *ApplicationController) setOperationState(app *appv1.Application, sta
// writeBackToInformer writes a just recently updated App back into the informer cache.
// This prevents the situation where the controller operates on a stale app and repeats work
func (ctrl *ApplicationController) writeBackToInformer(app *appv1.Application) {
logCtx := log.WithFields(log.Fields{"application": app.Name, "appNamespace": app.Namespace, "project": app.Spec.Project, "informer-writeBack": true})
logCtx := getAppLog(app).WithField("informer-writeBack", true)
err := ctrl.appInformer.GetStore().Update(app)
if err != nil {
logCtx.Errorf("failed to update informer store: %v", err)
Expand Down Expand Up @@ -1497,12 +1507,11 @@ func (ctrl *ApplicationController) processAppRefreshQueueItem() (processNext boo
return
}
app := origApp.DeepCopy()
logCtx := log.WithFields(log.Fields{
"application": app.QualifiedName(),
"level": comparisonLevel,
"dest-server": origApp.Spec.Destination.Server,
"dest-name": origApp.Spec.Destination.Name,
"dest-namespace": origApp.Spec.Destination.Namespace,
logCtx := getAppLog(app).WithFields(log.Fields{
"comparison-level": comparisonLevel,
"dest-server": origApp.Spec.Destination.Server,
"dest-name": origApp.Spec.Destination.Name,
"dest-namespace": origApp.Spec.Destination.Namespace,
})

startTime := time.Now()
Expand Down Expand Up @@ -1542,10 +1551,10 @@ func (ctrl *ApplicationController) processAppRefreshQueueItem() (processNext boo
patchMs = ctrl.persistAppStatus(origApp, &app.Status)

if err := ctrl.cache.SetAppResourcesTree(app.InstanceName(ctrl.namespace), &appv1.ApplicationTree{}); err != nil {
log.Warnf("failed to set app resource tree: %v", err)
logCtx.Warnf("failed to set app resource tree: %v", err)
}
if err := ctrl.cache.SetAppManagedResources(app.InstanceName(ctrl.namespace), nil); err != nil {
log.Warnf("failed to set app managed resources tree: %v", err)
logCtx.Warnf("failed to set app managed resources tree: %v", err)
}
return
}
Expand Down Expand Up @@ -1669,7 +1678,7 @@ func currentSourceEqualsSyncedSource(app *appv1.Application) bool {
// Additionally, it returns whether full refresh was requested or not.
// If full refresh is requested then target and live state should be reconciled, else only live state tree should be updated.
func (ctrl *ApplicationController) needRefreshAppStatus(app *appv1.Application, statusRefreshTimeout, statusHardRefreshTimeout time.Duration) (bool, appv1.RefreshType, CompareWith) {
logCtx := log.WithFields(log.Fields{"application": app.QualifiedName()})
logCtx := getAppLog(app)
var reason string
compareWith := CompareWithLatest
refreshType := appv1.RefreshTypeNormal
Expand Down Expand Up @@ -1746,8 +1755,8 @@ func (ctrl *ApplicationController) refreshAppConditions(app *appv1.Application)

// normalizeApplication normalizes an application.spec and additionally persists updates if it changed
func (ctrl *ApplicationController) normalizeApplication(orig, app *appv1.Application) {
logCtx := log.WithFields(log.Fields{"application": app.QualifiedName()})
app.Spec = *argo.NormalizeApplicationSpec(&app.Spec)
logCtx := getAppLog(app)

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

Expand All @@ -1765,7 +1774,7 @@ func (ctrl *ApplicationController) normalizeApplication(orig, app *appv1.Applica

// persistAppStatus persists updates to application status. If no changes were made, it is a no-op
func (ctrl *ApplicationController) persistAppStatus(orig *appv1.Application, newStatus *appv1.ApplicationStatus) (patchMs time.Duration) {
logCtx := log.WithFields(log.Fields{"application": orig.QualifiedName()})
logCtx := getAppLog(orig)
if orig.Status.Sync.Status != newStatus.Sync.Status {
message := fmt.Sprintf("Updated sync status: %s -> %s", orig.Status.Sync.Status, newStatus.Sync.Status)
ctrl.auditLogger.LogAppEvent(orig, argo.EventInfo{Reason: argo.EventReasonResourceUpdated, Type: v1.EventTypeNormal}, message, "")
Expand Down Expand Up @@ -1812,7 +1821,7 @@ func (ctrl *ApplicationController) autoSync(app *appv1.Application, syncStatus *
if app.Spec.SyncPolicy == nil || app.Spec.SyncPolicy.Automated == nil {
return nil, 0
}
logCtx := log.WithFields(log.Fields{"application": app.QualifiedName()})
logCtx := getAppLog(app)

if app.Operation != nil {
logCtx.Infof("Skipping auto-sync: another operation is in progress")
Expand Down Expand Up @@ -2010,7 +2019,7 @@ func (ctrl *ApplicationController) canProcessApp(obj interface{}) bool {

if annotations := app.GetAnnotations(); annotations != nil {
if skipVal, ok := annotations[common.AnnotationKeyAppSkipReconcile]; ok {
logCtx := log.WithFields(log.Fields{"application": app.QualifiedName()})
logCtx := getAppLog(app)
if skipReconcile, err := strconv.ParseBool(skipVal); err == nil {
if skipReconcile {
logCtx.Debugf("Skipping Application reconcile based on annotation %s", common.AnnotationKeyAppSkipReconcile)
Expand Down Expand Up @@ -2146,7 +2155,7 @@ func (ctrl *ApplicationController) newApplicationInformerAndLister() (cache.Shar
newApp, newOK := new.(*appv1.Application)
if oldOK && newOK {
if automatedSyncEnabled(oldApp, newApp) {
log.WithField("application", newApp.QualifiedName()).Info("Enabled automated sync")
getAppLog(newApp).Info("Enabled automated sync")
compareWith = CompareWithLatest.Pointer()
}
if ctrl.statusRefreshJitter != 0 && oldApp.ResourceVersion == newApp.ResourceVersion {
Expand Down

0 comments on commit 2dfccc5

Please sign in to comment.