diff --git a/internal/cmd/reconciler/main.go b/internal/cmd/reconciler/main.go index fbf1f80..bf0c48b 100644 --- a/internal/cmd/reconciler/main.go +++ b/internal/cmd/reconciler/main.go @@ -166,7 +166,8 @@ func run(ctx context.Context, cfg *Config, log logrus.FieldLogger) error { wg.Go(func() error { defer log.Debug("Done listening for pubsub events") - return reconcilerManager.ListenForEvents(ctx) + reconcilerManager.ListenForEvents(ctx) + return nil }) if err = reconcilerManager.SyncAllTeams(ctx, time.Minute*30); err != nil { diff --git a/internal/reconcilers/manager.go b/internal/reconcilers/manager.go index 211eeb4..4facf5e 100644 --- a/internal/reconcilers/manager.go +++ b/internal/reconcilers/manager.go @@ -79,6 +79,7 @@ func NewManager(ctx context.Context, c *apiclient.APIClient, enableDuringRegistr // AddReconciler will add a reconciler to the manager. func (m *Manager) AddReconciler(r Reconciler) { + m.log.WithField("reconciler", r.Name()).Debugf("adding reconciler to the manager") m.reconcilers = append(m.reconcilers, r) } @@ -97,10 +98,10 @@ func (m *Manager) RegisterReconcilersWithAPI(ctx context.Context) error { // ListenForEvents will listen for events on the pubsub subscription, if configured. This function will block until the // context is canceled. -func (m *Manager) ListenForEvents(ctx context.Context) error { +func (m *Manager) ListenForEvents(ctx context.Context) { if m.pubsubSubscription == nil { m.log.Warn("no pubsub subscription configured, not listening for events") - return nil + return } for { @@ -169,7 +170,7 @@ func (m *Manager) ListenForEvents(ctx context.Context) error { if err == nil || errors.Is(err, context.Canceled) { // Receive will return nil error when canceled - return nil + return } else if err != nil { m.log.WithError(err).Error("error while receiving pubsub message") } @@ -198,6 +199,7 @@ func (m *Manager) Run(ctx context.Context) { // context is canceled. func (m *Manager) SyncAllTeams(ctx context.Context, fullSyncInterval time.Duration) error { for { + m.log.Debugf("scheduling all teams for reconciliation") if err := m.scheduleAllTeams(ctx, uuid.New()); err != nil { m.log.WithError(err).Errorf("error when scheduling all teams") } @@ -221,7 +223,7 @@ func (m *Manager) syncTeam(ctx context.Context, input Input) { if !m.inFlight.Set(input.TeamSlug) { log.Info("already in flight - adding to back of queue") - time.Sleep(100 * time.Millisecond) + time.Sleep(10 * time.Second) if err := m.syncQueue.Add(input); err != nil { log.WithError(err).Error("failed while re-queueing team that is in flight") } @@ -297,12 +299,14 @@ func (m *Manager) deleteTeam(ctx context.Context, reconcilers []Reconciler, nais log = log.WithField("trace_id", input.TraceID) } + log.WithField("time", teamStart).Debugf("start team deletion process") successfulDelete := true for _, r := range reconcilers { log := log.WithField("reconciler", r.Name()) start := time.Now() hasError := false + log.WithField("time", start).Debugf("start delete") if err := r.Delete(ctx, m.apiclient, naisTeam, log); err != nil { successfulDelete = false hasError = true @@ -328,6 +332,11 @@ func (m *Manager) deleteTeam(ctx context.Context, reconcilers []Reconciler, nais } } + log. + WithField("duration", time.Since(start)). + WithField("has_error", hasError). + Debugf("finished delete") + m.metricReconcilerTime.Record( ctx, time.Since(start).Milliseconds(), @@ -348,6 +357,11 @@ func (m *Manager) deleteTeam(ctx context.Context, reconcilers []Reconciler, nais } } + log. + WithField("duration", time.Since(teamStart)). + WithField("success", successfulDelete). + Debugf("finished team deletion process") + m.metricReconcileTeam.Record( ctx, time.Since(teamStart).Milliseconds(), @@ -372,12 +386,14 @@ func (m *Manager) reconcileTeam(ctx context.Context, reconcilers []Reconciler, n log = log.WithField("trace_id", input.TraceID) } + log.WithField("time", teamStart).Debugf("start team reconciliation process") successfulSync := true for _, r := range reconcilers { log := log.WithField("reconciler", r.Name()) start := time.Now() hasError := false + log.WithField("time", start).Debugf("start reconcile") if err := r.Reconcile(ctx, m.apiclient, naisTeam, log); err != nil { successfulSync = false hasError = true @@ -403,6 +419,11 @@ func (m *Manager) reconcileTeam(ctx context.Context, reconcilers []Reconciler, n } } + log. + WithField("duration", time.Since(start)). + WithField("has_error", hasError). + Debugf("finished reconcile") + m.metricReconcilerTime.Record( ctx, time.Since(start).Milliseconds(), @@ -422,6 +443,11 @@ func (m *Manager) reconcileTeam(ctx context.Context, reconcilers []Reconciler, n } } + log. + WithField("duration", time.Since(teamStart)). + WithField("success", successfulSync). + Debugf("finished team reconciliation process") + m.metricReconcileTeam.Record(ctx, time.Since(teamStart).Milliseconds()) } @@ -440,6 +466,8 @@ func (m *Manager) scheduleAllTeams(ctx context.Context, correlationID uuid.UUID) return err } + m.log.WithField("num_teams", len(teams)).Debugf("fetched teams from API") + for _, team := range teams { err := m.syncQueue.Add(Input{ CorrelationID: correlationID.String(),