If resource count is zero (because we resumed a sync), log grant/entitlement progress every 10 seconds.

Author: ggreer

pkg/sync/syncer.go

@@ -84,12 +84,22 @@ func (p *ProgressCounts) LogResourcesProgress(ctx context.Context, resourceType
 func (p *ProgressCounts) LogEntitlementsProgress(ctx context.Context, resourceType string) {
 	entitlementsProgress := p.EntitlementsProgress[resourceType]
 	resources := p.Resources[resourceType]
+
+	l := ctxzap.Extract(ctx)
 	if resources == 0 {
+		// if resuming sync, resource counts will be zero, so don't calculate percentage. just log every 10 seconds.
+		if time.Since(p.LastEntitlementLog[resourceType]) > maxLogFrequency {
+			l.Info("Syncing entitlements",
+				zap.String("resource_type_id", resourceType),
+				zap.Int("synced", entitlementsProgress),
+			)
+			p.LastEntitlementLog[resourceType] = time.Now()
+		}
 		return
 	}
+
 	percentComplete := (entitlementsProgress * 100) / resources
 
-	l := ctxzap.Extract(ctx)
 	switch {
 	case entitlementsProgress > resources:
 		l.Error("more entitlement resources than resources",
@@ -118,12 +128,22 @@ func (p *ProgressCounts) LogEntitlementsProgress(ctx context.Context, resourceTy
 func (p *ProgressCounts) LogGrantsProgress(ctx context.Context, resourceType string) {
 	grantsProgress := p.GrantsProgress[resourceType]
 	resources := p.Resources[resourceType]
+
+	l := ctxzap.Extract(ctx)
 	if resources == 0 {
+		// if resuming sync, resource counts will be zero, so don't calculate percentage. just log every 10 seconds.
+		if time.Since(p.LastGrantLog[resourceType]) > maxLogFrequency {
+			l.Info("Syncing grants",
+				zap.String("resource_type_id", resourceType),
+				zap.Int("synced", grantsProgress),
+			)
+			p.LastGrantLog[resourceType] = time.Now()
+		}
 		return
 	}
+
 	percentComplete := (grantsProgress * 100) / resources
 
-	l := ctxzap.Extract(ctx)
 	switch {
 	case grantsProgress > resources:
 		l.Error("more grant resources than resources",