diff --git a/pkg/atproto/atproto.go b/pkg/atproto/atproto.go index fb28b0ded..fe4f90484 100644 --- a/pkg/atproto/atproto.go +++ b/pkg/atproto/atproto.go @@ -171,6 +171,10 @@ func (atsync *ATProtoSynchronizer) SyncBlueskyRepo(ctx context.Context, handle s return nil, fmt.Errorf("failed to add repo to stateful DB for %s: %w", ident.DID.String(), err) } + // The one Info line a sync gets. The walks it took are Debug; this is the + // state change that matters: the repo is servable from here. + log.Log(ctx, "shallow sync complete", "rev", result.Rev, "deepSyncDone", done) + return &newRepo, nil } diff --git a/pkg/atproto/backfill_walk.go b/pkg/atproto/backfill_walk.go index bc2828428..d30fc0f60 100644 --- a/pkg/atproto/backfill_walk.go +++ b/pkg/atproto/backfill_walk.go @@ -332,7 +332,11 @@ func (atsync *ATProtoSynchronizer) walkBackfill(ctx context.Context, ident *iden return "", "", err } - log.Log(ctx, "walked repo", "did", did, "handle", ident.Handle.String(), "rev", head.Rev, "root", head.Root.String(), "records", records) + // Debug: this fires once per walk, and a deepening repo walks one window + // at a time -- at Info it was nearly half of a boot's log. The Info-level + // story is one line per repo: "shallow sync complete" when it becomes + // servable, "deep sync complete" when its history is all in. + log.Debug(ctx, "walked repo", "did", did, "handle", ident.Handle.String(), "rev", head.Rev, "root", head.Root.String(), "records", records) return head.Rev, head.Root.String(), nil } diff --git a/pkg/atproto/sweep.go b/pkg/atproto/sweep.go index 65702c0f9..117a58548 100644 --- a/pkg/atproto/sweep.go +++ b/pkg/atproto/sweep.go @@ -677,7 +677,7 @@ func (atsync *ATProtoSynchronizer) sweepWindow(ctx context.Context, progress *sw progress.window(step.DID, backfillFloorTime(floor)) if done { progress.deepened(step.DID) - log.Log(ctx, "finished deepening repo history", "did", step.DID, "handle", step.Handle, "windows", step.Windows+1) + log.Log(ctx, "deep sync complete", "did", step.DID, "handle", step.Handle, "windows", step.Windows+1) return false } return true diff --git a/pkg/model/indexed.go b/pkg/model/indexed.go index 0bc60f0bc..dee06a726 100644 --- a/pkg/model/indexed.go +++ b/pkg/model/indexed.go @@ -115,7 +115,10 @@ func createOrVerify[T any, PT interface { return ErrAlreadyIndexed } - log.Log(ctx, "record changed on redelivery, updated", + // Debug: an updated record arriving again with a new CID is routine -- + // every place.stream.livestream heartbeat does it -- not an anomaly worth + // a line per occurrence. + log.Debug(ctx, "record changed on redelivery, updated", "uri", row.recordURI(), "oldCid", PT(&existing).recordCID(), "newCid", row.recordCID()) return m.DB.WithContext(ctx).Save(row).Error }