From 98afdfa2391a8cb4d1a75b35c89e1c6aa8387021 Mon Sep 17 00:00:00 2001 From: Richie Caputo Date: Wed, 14 Oct 2026 05:56:44 -0700 Subject: [PATCH 1/3] fix(attachments): pack after manual syncs in the background A sync or import sent to the daemon packed attachments inside its own request, with no runtime limit. That pass also listed and re-verified every packed blob, so on a large archive each manual sync waited minutes after its mail sync to pack a few new attachments. - After a successful ingest, the request marks packing pending and asks the attachment-pack job to run through the new Scheduler.RequestJob, then returns. The job takes the operation gate after the request releases it, stops after one minute, and yields to waiting requests. The idle tracker counts it from the moment it queues, so a daemon started on demand stays up until the pass finishes. It cannot rely on the job's six-hourly tick, which it may never live to see. - An attachment-pack pass verifies one bounded window of packed blobs and queues follow-ups only while loose blobs remain. The daily attachment-maintenance job still finishes whole verification cycles. - The unpacked-blob queries take candidate hashes from the hash indexes and read attachment rows only for unpacked hashes. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01793XPgu1pMcfXjFd423RNP --- cmd/msgvault/cmd/attachment_maintenance.go | 120 ++++++---- .../cmd/attachment_maintenance_test.go | 196 ++++++++++++---- cmd/msgvault/cmd/serve.go | 29 +-- cmd/msgvault/cmd/serve_test.go | 218 +++++++++++------- docs/changelog.md | 9 +- docs/cli-reference.md | 47 ++-- internal/scheduler/scheduler.go | 20 ++ internal/scheduler/scheduler_test.go | 49 ++++ internal/store/pack_liveness_index_test.go | 30 +++ internal/store/packs.go | 45 ++-- 10 files changed, 517 insertions(+), 246 deletions(-) diff --git a/cmd/msgvault/cmd/attachment_maintenance.go b/cmd/msgvault/cmd/attachment_maintenance.go index 10359d5ad..7a094acb8 100644 --- a/cmd/msgvault/cmd/attachment_maintenance.go +++ b/cmd/msgvault/cmd/attachment_maintenance.go @@ -25,9 +25,10 @@ const ( automaticAttachmentMaxRuntime = time.Minute attachmentMaintenanceJob = "attachment-maintenance" attachmentMaintenanceCron = "17 3 * * *" - // attachmentPackJob packs blobs that scheduled syncs left loose. A pass - // re-reads the whole pack catalog, so it runs a few times a day rather - // than after every sync. Bounded follow-ups drain any remaining backlog. + // attachmentPackJob packs loose blobs in bounded background passes. It + // runs on its schedule and whenever a manual ingest sent to the daemon + // succeeds, after that request has returned. Follow-ups drain a loose + // backlog larger than one pass's byte budget. attachmentPackJob = "attachment-pack" attachmentPackCron = "41 */6 * * *" importMboxCommand = "import-mbox" @@ -44,9 +45,14 @@ type attachmentMaintenance struct { logger *slog.Logger packCreationEnabled bool attachmentsDir string - // packPending records that a scheduled sync wrote loose blobs that no - // pack pass has drained yet. Startup requests one scan of existing blobs. + // packPending records that an ingest wrote loose blobs that no pack pass + // has drained yet. Startup requests one scan of existing blobs. packPending atomic.Bool + // requestPackJob asks the daemon scheduler for a background + // attachment-pack run. registerAttachmentPackJob sets it before the + // daemon serves requests; without it a pending pass waits for the job's + // schedule. + requestPackJob func() error } func newAttachmentMaintenance( @@ -126,10 +132,10 @@ func (m *attachmentMaintenance) unpack(ctx context.Context) (packstore.UnpackSta return stats, nil } -// runAutomaticPack performs one bounded maintenance pass. Errors remain -// visible to schedulers, while callers following a successful ingest can log -// or stream the warning and deliberately preserve the ingest result. -func (m *attachmentMaintenance) runAutomaticPack(ctx context.Context, emitWarning func(string) error) error { +// runAutomaticPack performs one pack pass with the automatic byte budget. +// Scheduled callers bound its verification work and runtime; errors remain +// visible to them. +func (m *attachmentMaintenance) runAutomaticPack(ctx context.Context) error { if !m.packCreationEnabled { m.log().Debug("automatic attachment packing disabled") return nil @@ -152,17 +158,9 @@ func (m *attachmentMaintenance) runAutomaticPack(ctx context.Context, emitWarnin } m.logAutomaticPackSummary("automatic attachment maintenance progress", stats, duration) - const retry = "run `msgvault pack-attachments` to retry" m.log().Warn("automatic attachment maintenance failed", "error", err, - "retry", retry) - if emitWarning != nil { - warning := fmt.Sprintf("Automatic attachment maintenance failed: %v; %s.\n", err, retry) - if emitErr := emitWarning(warning); emitErr != nil { - m.log().Warn("failed to emit automatic attachment maintenance warning", - "error", emitErr) - } - } + "retry", "run `msgvault pack-attachments` to retry") return err } @@ -241,41 +239,46 @@ func (m *attachmentMaintenance) logAutomaticRepackSummary(message string, stats "budget_exhausted", stats.BudgetExhausted) } -// runScheduledPack bounds existing-blob verification as well as new pack bytes. -func (m *attachmentMaintenance) runScheduledPack(ctx context.Context) error { +// runScheduledPack performs one pass that packs new loose blobs within the +// byte budget and verifies the next window of existing packed blobs, so its +// cost tracks new content rather than archive size. A pass that stops at its +// byte budget leaves packPending set. verifyMore reports that the durable +// verification cursor has further windows. +func (m *attachmentMaintenance) runScheduledPack(ctx context.Context) (verifyMore bool, err error) { if !m.packCreationEnabled { - return nil + return false, nil } packCtx, pass, err := m.store.BeginPackVerification(ctx, 128, 32<<20) if err != nil { - return err + return false, err } - if err := m.runAutomaticPack(packCtx, nil); err != nil { - return err + if err := m.runAutomaticPack(packCtx); err != nil { + return false, err } more, err := m.store.FinishPackVerification(ctx, pass) if err != nil { - return err + return false, err } if more { // A completed verification cycle restarts on the next request. Only an // unfinished window provides a resume point for a budgeted follow-up. jobctx.RecordProgress(ctx) - m.markPackPending() } - return nil + return more, nil } -// daily runs the two bounded phases in order. A failed pack phase stops the -// job so the scheduler records the failure instead of obscuring it with a -// second maintenance result. +// daily runs the two bounded phases in order. Follow-ups finish the loose +// backlog and the whole verification cycle before the repack phase. A failed +// pack phase stops the job so the scheduler records the failure instead of +// obscuring it with a second maintenance result. func (m *attachmentMaintenance) daily(ctx context.Context) error { m.packPending.Store(false) - if err := m.runScheduledPack(ctx); err != nil { + verifyMore, err := m.runScheduledPack(ctx) + if err != nil { m.markPackPending() return err } - if m.packPending.Load() { + if verifyMore || m.packPending.Load() { return scheduler.ErrReschedule } return m.runAutomaticRepack(ctx, nil) @@ -288,14 +291,17 @@ func (m *attachmentMaintenance) markPackPending() { } } -// runPendingPack runs one automatic pack pass when a scheduled sync left new -// loose blobs since the last pass. A failed pass leaves the request pending; -// an exhausted byte budget queues another pass behind waiting work. +// runPendingPack runs one automatic pack pass when an ingest left new loose +// blobs since the last pass. A failed pass leaves the request pending; an +// exhausted byte budget queues another pass behind waiting work. Each pass +// advances verification by one window but does not chain a whole +// verification cycle: on a large archive that is hundreds of passes, and the +// daily attachment-maintenance job completes cycles. func (m *attachmentMaintenance) runPendingPack(ctx context.Context) error { if m == nil || !m.packPending.Swap(false) { return nil } - if err := m.runScheduledPack(ctx); err != nil { + if _, err := m.runScheduledPack(ctx); err != nil { m.packPending.Store(true) return err } @@ -305,6 +311,25 @@ func (m *attachmentMaintenance) runPendingPack(ctx context.Context) error { return nil } +// requestPack records that a successful manual ingest may have left loose +// blobs and asks the attachment-pack job to pack them. It never waits: the +// job takes the operation gate after the ingest's request releases it, runs +// under the job's runtime limit, and counts as daemon activity while it +// waits and runs. Without a registered job the request stays pending. +func (m *attachmentMaintenance) requestPack() { + if m == nil || !m.packCreationEnabled { + return + } + m.markPackPending() + if m.requestPackJob == nil { + return + } + if err := m.requestPackJob(); err != nil { + m.log().Info("background attachment packing not started; new blobs stay pending", + "job", attachmentPackJob, "error", err) + } +} + // looseBlobWrites reports the in-process count of loose blobs created under // this maintenance's attachments directory. func (m *attachmentMaintenance) looseBlobWrites() int64 { @@ -321,21 +346,18 @@ func (m *attachmentMaintenance) log() *slog.Logger { return slog.Default() } -// runAfterSuccessfulAttachmentIngest runs bounded maintenance only after a -// successful ingest. Maintenance and warning-stream failures are best-effort: -// neither may replace the successful ingest result. +// runAfterSuccessfulAttachmentIngest requests background packing only after +// a successful ingest. The caller's request returns as soon as the ingest +// does; packing can neither delay nor replace the ingest result. func runAfterSuccessfulAttachmentIngest( ctx context.Context, maintenance *attachmentMaintenance, ingest func(context.Context) error, - emitWarning func(string) error, ) error { if err := runWithAttachmentMutation(ctx, maintenance, ingest); err != nil { return err } - if maintenance != nil { - _ = maintenance.runAutomaticPack(ctx, emitWarning) - } + maintenance.requestPack() return nil } @@ -406,15 +428,21 @@ func registerAttachmentMaintenanceJob(sched *scheduler.Scheduler, maintenance *a } func registerAttachmentPackJob(sched *scheduler.Scheduler, maintenance *attachmentMaintenance) error { - // Recheck the catalog on the first tick after startup. In-memory write + // Recheck the catalog on the first pass after startup. In-memory write // counts cannot tell us what a previous daemon left loose. maintenance.markPackPending() - return sched.AddJob(scheduler.Job{ + if err := sched.AddJob(scheduler.Job{ Name: attachmentPackJob, MaxRuntime: automaticAttachmentMaxRuntime, Schedule: attachmentPackCron, Run: maintenance.runPendingPack, - }) + }); err != nil { + return err + } + // A daemon started on demand may idle out long before the next cron + // tick, so ingests start the job themselves. + maintenance.requestPackJob = func() error { return sched.RequestJob(attachmentPackJob) } + return nil } func registerScheduledBeeperJob( diff --git a/cmd/msgvault/cmd/attachment_maintenance_test.go b/cmd/msgvault/cmd/attachment_maintenance_test.go index 712779ab9..922c696e5 100644 --- a/cmd/msgvault/cmd/attachment_maintenance_test.go +++ b/cmd/msgvault/cmd/attachment_maintenance_test.go @@ -15,6 +15,7 @@ import ( "path/filepath" "strings" "testing" + "testing/synctest" "time" "github.com/stretchr/testify/assert" @@ -22,6 +23,7 @@ import ( "go.kenn.io/kit/pack" "go.kenn.io/kit/packstore" + "go.kenn.io/msgvault/internal/api" "go.kenn.io/msgvault/internal/attachmentstore" "go.kenn.io/msgvault/internal/export" "go.kenn.io/msgvault/internal/jobctx" @@ -155,19 +157,14 @@ func TestAutomaticAttachmentMaintenancePacksBoundedAndLogsCompleteStats(t *testi f := newAttachmentMaintenanceFixture(t) content := []byte("automatic attachment maintenance payload") hash := f.addLoose(content) - warnings := 0 - err := f.maintenance.runAutomaticPack(context.Background(), func(string) error { - warnings++ - return nil - }) + err := f.maintenance.runAutomaticPack(context.Background()) require.NoError(err, "runAutomaticPack") gotAutomaticAttachmentBytes := automaticAttachmentBytes assert.Equal(wantAutomaticAttachmentBytes, gotAutomaticAttachmentBytes) assert.Equal("attachment-maintenance", attachmentMaintenanceJob) assert.Equal("17 3 * * *", attachmentMaintenanceCron) - assert.Zero(warnings, "successful automatic packing must not emit CLI output") require.NotNil(f.packedEntry(hash), "loose attachment must be packed") assert.Equal(content, f.readBlob(hash), "packed attachment stays readable") @@ -205,7 +202,7 @@ func TestLooseAttachmentModeSkipsAutomaticPackingAndRejectsPackCreation(t *testi f.maintenance.packCreationEnabled = false hash := f.addLoose([]byte("remain loose when attachment packing is disabled")) - err := f.maintenance.runAutomaticPack(context.Background(), nil) + err := f.maintenance.runAutomaticPack(context.Background()) require.NoError(err) assert.Nil(f.packedEntry(hash)) assert.Contains(f.logs.String(), "automatic attachment packing disabled") @@ -225,38 +222,26 @@ func TestAutomaticAttachmentMaintenanceCancellationIsInformational(t *testing.T) f := newAttachmentMaintenanceFixture(t) ctx, cancel := context.WithCancel(context.Background()) cancel() - warnings := 0 - err := f.maintenance.runAutomaticPack(ctx, func(string) error { - warnings++ - return nil - }) + err := f.maintenance.runAutomaticPack(ctx) require.ErrorIs(err, context.Canceled) - assert.Zero(warnings) assert.Contains(f.logs.String(), "level=INFO msg=\"automatic attachment maintenance canceled\"") assert.NotContains(f.logs.String(), "level=WARN") } -func TestAutomaticAttachmentMaintenanceFailureWarnsWithoutReplacingIngestSuccess(t *testing.T) { +func TestBackgroundPackFailureLogsProgressAndStaysPending(t *testing.T) { require := require.New(t) assert := assert.New(t) maintenance, logs := newFailingAttachmentMaintenance(t) - var warning string - err := runAfterSuccessfulAttachmentIngest( - context.Background(), - maintenance, - func(context.Context) error { return nil }, - func(message string) error { - warning = message - return nil - }, - ) + require.NoError(runAfterSuccessfulAttachmentIngest( + context.Background(), maintenance, func(context.Context) error { return nil }, + ), "a later maintenance failure cannot reach the ingest result") + require.Error(maintenance.runPendingPack(context.Background()), "the job records the failure") + assert.True(maintenance.packPending.Load(), "a failed pass leaves its work pending") - require.NoError(err, "maintenance failure must preserve successful ingest") - assert.Contains(warning, "pack-attachments") - assert.Contains(warning, "retry") + require.Error(maintenance.runAutomaticPack(context.Background())) logOutput := logs.String() progressAt := strings.Index(logOutput, "level=INFO msg=\"automatic attachment maintenance progress\"") warnAt := strings.Index(logOutput, "level=WARN msg=\"automatic attachment maintenance failed\"") @@ -268,24 +253,6 @@ func TestAutomaticAttachmentMaintenanceFailureWarnsWithoutReplacingIngestSuccess assert.Contains(logOutput, "pack-attachments", "log names the explicit retry command") } -func TestAutomaticAttachmentMaintenanceWarningFailurePreservesIngestSuccess(t *testing.T) { - require := require.New(t) - assert := assert.New(t) - maintenance, logs := newFailingAttachmentMaintenance(t) - warningErr := errors.New("warning stream closed") - - err := runAfterSuccessfulAttachmentIngest( - context.Background(), - maintenance, - func(context.Context) error { return nil }, - func(string) error { return warningErr }, - ) - - require.NoError(err, "warning failure must preserve successful ingest") - assert.Contains(logs.String(), "failed to emit automatic attachment maintenance warning") - assert.Contains(logs.String(), warningErr.Error()) -} - func (f *attachmentMaintenanceFixture) ingestLoose(content []byte) string { f.t.Helper() f.sequence++ @@ -657,7 +624,7 @@ func TestAttachmentIngestMutationLeaseWaitsForMaintenance(t *testing.T) { func(context.Context) error { close(ingestStarted) return nil - }, nil, + }, ) }() @@ -686,14 +653,17 @@ func TestPendingPackCheckpointsVerificationAndStillPacksNewBlobs(t *testing.T) { require.NoError(err) fresh := f.addLoose([]byte("new attachment while verification is pending")) f.maintenance.markPackPending() - require.ErrorIs(f.maintenance.runPendingPack(t.Context()), scheduler.ErrReschedule) + require.NoError(f.maintenance.runPendingPack(t.Context()), + "one window of verification does not chain the whole cycle") require.NotNil(f.packedEntry(fresh), "new blobs must not wait for the whole verification cycle") // A reconstructed daemon resumes the durable verification cursor. resumed, err := newAttachmentMaintenance(f.store, f.dir, nil, true) require.NoError(err) defer func() { require.NoError(resumed.close()) }() - resumed.markPackPending() - require.NoError(resumed.runPendingPack(t.Context())) + ctx := jobctx.WithProgress(t.Context()) + verifyMore, err := resumed.runScheduledPack(ctx) + require.NoError(err) + assert.False(t, verifyMore, "the second window finishes the cycle the first pass started") stats, err := resumed.unpack(t.Context()) require.NoError(err) assert.Equal(t, existing+1, stats.BlobsRestored, "manual unpack must see the full catalog") @@ -702,7 +672,9 @@ func TestPendingPackCheckpointsVerificationAndStillPacksNewBlobs(t *testing.T) { func TestCompletedPackVerificationRecordsNoProgress(t *testing.T) { f := newAttachmentMaintenanceFixture(t) ctx := jobctx.WithProgress(t.Context()) - require.NoError(t, f.maintenance.runScheduledPack(ctx)) + verifyMore, err := f.maintenance.runScheduledPack(ctx) + require.NoError(t, err) + assert.False(t, verifyMore) assert.False(t, jobctx.HasProgress(ctx), "an empty completed scan provides no resume point for a cancelled repack") } @@ -749,7 +721,129 @@ func TestRemovingRedundantOrphanPackCountsAsProgress(t *testing.T) { require.NoError(os.MkdirAll(filepath.Dir(orphan), 0o700)) require.NoError(os.WriteFile(orphan, data, 0o600)) ctx := jobctx.WithProgress(t.Context()) - require.NoError(f.maintenance.runAutomaticPack(ctx, nil)) + require.NoError(f.maintenance.runAutomaticPack(ctx)) assert.NoFileExists(t, orphan) assert.True(t, jobctx.HasProgress(ctx), "a removed pack is committed progress a timed-out pass can resume after") } + +// holdPackPass stands in for a pass that cannot finish quickly: an +// attachment mutation in progress keeps Pack waiting for its exclusive lease, +// exactly where a pass waits behind a running ingest. +func (f *attachmentMaintenanceFixture) holdPackPass() func() { + f.t.Helper() + lease, err := f.maintenance.coordinator.AcquireMutation(f.t.Context()) + require.NoError(f.t, err) + return func() { require.NoError(f.t, lease.Release()) } +} + +func TestBackgroundPackKeepsIdleDaemonAliveUntilItFinishes(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + hash := f.addLoose([]byte("blob packed while the daemon would otherwise idle out")) + const idleTimeout = 20 * time.Second + idleShutdown := make(chan struct{}) + idle := api.NewIdleTracker(idleTimeout, func() { close(idleShutdown) }) + sched, media := newServeSchedulers(nil, f.maintenance.logger, idle, api.NewSerialOperationGate()) + defer func() { <-serveSchedulers{sched, media}.Stop().Done() }() + require.NoError(registerAttachmentPackJob(sched, f.maintenance)) + go idle.Run(t.Context()) + release := f.holdPackPass() + + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil })) + // Longer than the idle timeout, shorter than the job's runtime limit. + synctest.Sleep(2 * idleTimeout) + select { + case <-idleShutdown: + require.FailNow("the daemon idled out while its pack job was running") + default: + } + require.Less(2*idleTimeout, automaticAttachmentMaxRuntime) + assert.True(attachmentPackJobStatus(t, sched).Running) + + release() + synctest.Wait() + assert.NotNil(f.packedEntry(hash), "the pass finishes once it can take the maintenance lease") + select { + case <-idleShutdown: + require.FailNow("idle timeout must count from the end of the pack job") + default: + } + synctest.Sleep(idleTimeout + time.Second) + select { + case <-idleShutdown: + default: + assert.Fail("an idle daemon must still shut down after packing") + } + }) +} + +func TestBackgroundPackStopsAtRuntimeLimitAndNextIngestResumesIt(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + hash := f.addLoose([]byte("blob whose first pass runs out of time")) + sched, _ := newBackgroundPackHarness(t, f) + release := f.holdPackPass() + + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil })) + synctest.Sleep(automaticAttachmentMaxRuntime + time.Second) + synctest.Wait() + + status := attachmentPackJobStatus(t, sched) + assert.False(status.Running, "the runtime limit ends the pass and releases the gate") + assert.False(status.Pending, "a pass without committed progress waits for the next trigger") + assert.Contains(status.LastError, jobctx.ErrRunBudgetExceeded.Error()) + assert.Nil(f.packedEntry(hash)) + assert.True(f.maintenance.packPending.Load(), "the unfinished work stays pending") + + release() + // The next manual ingest restarts the job, which picks up the pending work. + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil })) + synctest.Wait() + assert.NotNil(f.packedEntry(hash)) + assert.False(f.maintenance.packPending.Load()) + assert.Empty(attachmentPackJobStatus(t, sched).LastError) + }) +} + +func TestBackgroundPackCancelsOnShutdownAndRestartResumesIt(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + hash := f.addLoose([]byte("blob whose pass is interrupted by shutdown")) + gate := api.NewSerialOperationGate() + sched, media := newServeSchedulers(nil, f.maintenance.logger, nil, gate) + require.NoError(registerAttachmentPackJob(sched, f.maintenance)) + release := f.holdPackPass() + + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil })) + synctest.Wait() + require.True(attachmentPackJobStatus(t, sched).Running) + require.NoError(shutdownServeRuntime(t.Context(), io.Discard, nil, + serveSchedulers{sched, media}, gate)) + assert.Nil(f.packedEntry(hash), "a cancelled pass commits nothing") + assert.Contains(f.logs.String(), "automatic attachment maintenance canceled") + release() + + // A restarted daemon has no in-memory request; its job rechecks the + // catalog on the first pass after startup. + restarted, err := newAttachmentMaintenance(f.store, f.dir, f.maintenance.logger, true) + require.NoError(err) + defer func() { require.NoError(restarted.close()) }() + restartedSched := scheduler.New(nil).WithLogger(f.maintenance.logger) + defer func() { <-restartedSched.Stop().Done() }() + require.NoError(registerAttachmentPackJob(restartedSched, restarted)) + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), restarted, + func(context.Context) error { return nil })) + synctest.Wait() + assert.NotNil(f.packedEntry(hash)) + }) +} diff --git a/cmd/msgvault/cmd/serve.go b/cmd/msgvault/cmd/serve.go index e8c814cef..f789241c6 100644 --- a/cmd/msgvault/cmd/serve.go +++ b/cmd/msgvault/cmd/serve.go @@ -2085,15 +2085,9 @@ func (a *storeAPIAdapter) runCLISyncWithRunner( } return emit(api.CLISyncEvent{Type: stream, Data: data}) } - emitWarning := func(message string) error { - if emit == nil { - return nil - } - return emit(api.CLISyncEvent{Type: "stderr", Data: message}) - } return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, func(ctx context.Context) error { return run(ctx, cliSyncSubprocessArgs(req), emitSubprocess) - }, emitWarning) + }) } // emitFolderArgs appends a --folder/--skip-folder flag for each @@ -2230,13 +2224,7 @@ func (a *storeAPIAdapter) runCLIRepairMessageWithRunner( if req.Audit { return runRepair(ctx) } - emitWarning := func(message string) error { - if emit == nil { - return nil - } - return emit(api.CLIRepairMessageEvent{Type: "stderr", Data: message}) - } - return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, runRepair, emitWarning) + return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, runRepair) } func cliRepairMessageSubprocessArgs(req api.CLIRepairMessageRequest) []string { @@ -2349,18 +2337,7 @@ func (a *storeAPIAdapter) runCLICommandWithRunner( ctx, a.attachmentMaintenance, runSubprocess, emitWarning, ) } - emitWarning := func(message string) error { - if emit == nil { - return nil - } - return emit(api.CLIRunEvent{Type: "stderr", Data: message}) - } - return runAfterSuccessfulAttachmentIngest( - ctx, - a.attachmentMaintenance, - runSubprocess, - emitWarning, - ) + return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, runSubprocess) } func attachmentRemovalCommand(args []string) bool { diff --git a/cmd/msgvault/cmd/serve_test.go b/cmd/msgvault/cmd/serve_test.go index 17dc0fca8..c28e23b6c 100644 --- a/cmd/msgvault/cmd/serve_test.go +++ b/cmd/msgvault/cmd/serve_test.go @@ -20,6 +20,7 @@ import ( "strings" "sync" "testing" + "testing/synctest" "time" "github.com/spf13/cobra" @@ -2037,52 +2038,92 @@ func TestStoreAPIAdapterServesSourceStatus(t *testing.T) { assert.Equal(store.SyncStatusCompleted, got.LastSuccessfulSync.Status, "LastSuccessfulSync.Status") } -func TestStoreAPIAdapterRunCLISyncPacksOnlyAfterSubprocessSuccess(t *testing.T) { +// newBackgroundPackHarness wires the attachment-pack job the way the daemon +// does: on the daemon scheduler, behind the operation gate. The startup +// catalog recheck is cleared so a test observes only what a request asks for; +// TestRegisterAttachmentPackJobFindsBacklogAfterRestart covers that recheck. +func newBackgroundPackHarness(t *testing.T, f *attachmentMaintenanceFixture) (*scheduler.Scheduler, *api.SerialOperationGate) { + t.Helper() + gate := api.NewSerialOperationGate() + sched, media := newServeSchedulers(nil, f.maintenance.logger, nil, gate) + t.Cleanup(func() { <-serveSchedulers{sched, media}.Stop().Done() }) + require.NoError(t, registerAttachmentPackJob(sched, f.maintenance)) + f.maintenance.packPending.Store(false) + return sched, gate +} + +func attachmentPackJobStatus(t *testing.T, sched *scheduler.Scheduler) scheduler.JobStatus { + t.Helper() + for _, status := range sched.JobStatus() { + if status.Name == attachmentPackJob { + return status + } + } + require.FailNow(t, "attachment-pack job is not registered") + return scheduler.JobStatus{} +} + +// TestStoreAPIAdapterRunCLISyncReturnsBeforeBackgroundPack proves a manual +// sync's request finishes without packing: the pack job only queues for the +// operation gate the request still holds, and packs once it is released. +func TestStoreAPIAdapterRunCLISyncReturnsBeforeBackgroundPack(t *testing.T) { tests := []struct { name string predecessorErr error wantPacked bool - wantAttempts int }{ - {name: "success", wantPacked: true, wantAttempts: 1}, + {name: "success", wantPacked: true}, {name: "failure", predecessorErr: errors.New("sync subprocess failed")}, } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - require := require.New(t) - assert := assert.New(t) - f := newAttachmentMaintenanceFixture(t) - hash := f.addLoose([]byte("CLI sync attachment payload")) - adapter := &storeAPIAdapter{store: f.store, attachmentMaintenance: f.maintenance} - var events []api.CLISyncEvent - runnerCalls := 0 - - err := adapter.runCLISyncWithRunner( - context.Background(), - api.CLISyncRequest{Email: "alice@example.com"}, - func(event api.CLISyncEvent) error { - events = append(events, event) - return nil - }, - func(_ context.Context, args []string, _ func(string, string) error) error { - runnerCalls++ - assert.Equal([]string{"sync", "alice@example.com"}, args) - assert.Nil(f.packedEntry(hash), "packing must follow subprocess success") - return tt.predecessorErr - }, - ) - - if tt.predecessorErr != nil { - require.ErrorIs(err, tt.predecessorErr) - } else { - require.NoError(err) - } - assert.Equal(1, runnerCalls) - assert.Equal(tt.wantPacked, f.packedEntry(hash) != nil) - assert.Equal(tt.wantAttempts, - strings.Count(f.logs.String(), "automatic attachment maintenance complete")) - assert.Empty(events, "successful automatic maintenance writes no normal CLI output") + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + hash := f.addLoose([]byte("CLI sync attachment payload")) + sched, gate := newBackgroundPackHarness(t, f) + adapter := &storeAPIAdapter{store: f.store, attachmentMaintenance: f.maintenance} + var events []api.CLISyncEvent + runnerCalls := 0 + + // The API middleware holds the gate for the whole request. + releaseRequest, ok := gate.BeginRequestWorkContext(t.Context(), "msgvault sync") + require.True(ok) + err := adapter.runCLISyncWithRunner( + t.Context(), + api.CLISyncRequest{Email: "alice@example.com"}, + func(event api.CLISyncEvent) error { + events = append(events, event) + return nil + }, + func(_ context.Context, args []string, _ func(string, string) error) error { + runnerCalls++ + assert.Equal([]string{"sync", "alice@example.com"}, args) + return tt.predecessorErr + }, + ) + if tt.predecessorErr != nil { + require.ErrorIs(err, tt.predecessorErr) + } else { + require.NoError(err) + } + assert.Equal(1, runnerCalls) + assert.Empty(events, "packing writes no CLI output") + synctest.Wait() + assert.Nil(f.packedEntry(hash), "the request returns before any packing") + assert.Equal(tt.wantPacked, attachmentPackJobStatus(t, sched).Queued, + "only a successful sync queues the pack job behind its request") + + releaseRequest() + synctest.Wait() + assert.Equal(tt.wantPacked, f.packedEntry(hash) != nil) + status := attachmentPackJobStatus(t, sched) + assert.False(status.Running) + assert.Empty(status.LastError) + assert.Equal(tt.wantPacked, !status.LastRun.IsZero()) + }) }) } } @@ -2293,13 +2334,11 @@ func TestStoreAPIAdapterRunCLICommandPacksOnlyAllowlistedSuccess(t *testing.T) { args []string predecessorErr error wantPacked bool - wantAttempts int }{ { - name: "allowlisted success", - args: []string{importMboxCommand, "archive.mbox"}, - wantPacked: true, - wantAttempts: 1, + name: "allowlisted success", + args: []string{importMboxCommand, "archive.mbox"}, + wantPacked: true, }, { name: "unrelated success", @@ -2314,47 +2353,51 @@ func TestStoreAPIAdapterRunCLICommandPacksOnlyAllowlistedSuccess(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - require := require.New(t) - assert := assert.New(t) - f := newAttachmentMaintenanceFixture(t) - hash := f.addLoose([]byte("generic CLI attachment payload")) - adapter := &storeAPIAdapter{store: f.store, attachmentMaintenance: f.maintenance} - var events []api.CLIRunEvent - runnerCalls := 0 - - err := adapter.runCLICommandWithRunner( - context.Background(), - api.CLIRunRequest{Args: tt.args, Env: map[string]string{"TEST": "value"}, Cwd: "/tmp"}, - func(event api.CLIRunEvent) error { - events = append(events, event) - return nil - }, - func( - _ context.Context, - args []string, - env map[string]string, - cwd string, - _ func(string, string) error, - ) error { - runnerCalls++ - assert.Equal(tt.args, args) - assert.Equal(map[string]string{"TEST": "value"}, env) - assert.Equal("/tmp", cwd) - assert.Nil(f.packedEntry(hash), "packing must follow subprocess success") - return tt.predecessorErr - }, - ) + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + hash := f.addLoose([]byte("generic CLI attachment payload")) + sched, _ := newBackgroundPackHarness(t, f) + adapter := &storeAPIAdapter{store: f.store, attachmentMaintenance: f.maintenance} + var events []api.CLIRunEvent + runnerCalls := 0 + + err := adapter.runCLICommandWithRunner( + t.Context(), + api.CLIRunRequest{Args: tt.args, Env: map[string]string{"TEST": "value"}, Cwd: "/tmp"}, + func(event api.CLIRunEvent) error { + events = append(events, event) + return nil + }, + func( + _ context.Context, + args []string, + env map[string]string, + cwd string, + _ func(string, string) error, + ) error { + runnerCalls++ + assert.Equal(tt.args, args) + assert.Equal(map[string]string{"TEST": "value"}, env) + assert.Equal("/tmp", cwd) + assert.Nil(f.packedEntry(hash), "packing must follow subprocess success") + return tt.predecessorErr + }, + ) - if tt.predecessorErr != nil { - require.ErrorIs(err, tt.predecessorErr) - } else { - require.NoError(err) - } - assert.Equal(1, runnerCalls) - assert.Equal(tt.wantPacked, f.packedEntry(hash) != nil) - assert.Equal(tt.wantAttempts, - strings.Count(f.logs.String(), "automatic attachment maintenance complete")) - assert.Empty(events, "successful automatic maintenance writes no normal CLI output") + if tt.predecessorErr != nil { + require.ErrorIs(err, tt.predecessorErr) + } else { + require.NoError(err) + } + assert.Equal(1, runnerCalls) + synctest.Wait() + assert.Equal(tt.wantPacked, f.packedEntry(hash) != nil) + assert.Equal(tt.wantPacked, !attachmentPackJobStatus(t, sched).LastRun.IsZero(), + "only successful attachment-producing commands start the pack job") + assert.Empty(events, "background packing writes no CLI output") + }) }) } } @@ -2657,7 +2700,7 @@ func TestStoreAPIAdapterExplicitRepackCancellationFailsFast(t *testing.T) { assert.True(has, "fail-fast cancellation leaves physical inventory untouched") } -func TestStoreAPIAdapterMaintenanceWarningStreamsWithoutChangingSuccess(t *testing.T) { +func TestStoreAPIAdapterSyncNeverWaitsForOrStreamsBackgroundPackFailures(t *testing.T) { require := require.New(t) assert := assert.New(t) maintenance, logs := newFailingAttachmentMaintenance(t) @@ -2674,14 +2717,11 @@ func TestStoreAPIAdapterMaintenanceWarningStreamsWithoutChangingSuccess(t *testi func(context.Context, []string, func(string, string) error) error { return nil }, ) - require.NoError(err, "automatic maintenance failure must preserve sync success") - require.Len(events, 1, "one concise warning event") - assert.Equal("stderr", events[0].Type) - assert.Contains(events[0].Data, "pack-attachments") - assert.Contains(events[0].Data, "retry") - assert.Contains(logs.String(), "automatic attachment maintenance failed") + require.NoError(err, "a maintenance fault cannot fail the sync request") + assert.Empty(events, "the request streams only the sync's own output") + assert.True(maintenance.packPending.Load(), "the sync leaves its pack request pending") + assert.NotContains(logs.String(), "automatic attachment maintenance", "no pack pass ran inside the request") } - func TestStoreAPIAdapterMaintenanceWarningStreamFailurePreservesSuccess(t *testing.T) { require := require.New(t) assert := assert.New(t) diff --git a/docs/changelog.md b/docs/changelog.md index 5ab743dc8..e396c6d39 100644 --- a/docs/changelog.md +++ b/docs/changelog.md @@ -1,5 +1,5 @@ --- -last_edited: "2026-10-05" +last_edited: "2026-10-14" title: Changelog description: Release history for msgvault --- @@ -8,6 +8,13 @@ All notable changes to msgvault, grouped by release. ## Unreleased +- A `sync` or import sent to the daemon returns when its own work finishes. + Attachment packing now runs afterwards as the daemon's bounded + `attachment-pack` job instead of inside the request, and a daemon started on + demand stays up until that job finishes. Each pass verifies one bounded + window of existing packs instead of every packed blob, and finding new loose + blobs no longer reads every attachment row. + - `add-o365 --graph --as ` syncs a shared or delegated Microsoft 365 mailbox through Microsoft Graph, signed in as you. It needs the `Mail.Read.Shared` permission. See diff --git a/docs/cli-reference.md b/docs/cli-reference.md index 76ba6a5d6..cbbb9c8fe 100644 --- a/docs/cli-reference.md +++ b/docs/cli-reference.md @@ -1,5 +1,5 @@ --- -last_edited: "2026-10-05" +last_edited: "2026-10-14" title: CLI Reference description: Complete command reference for all msgvault commands. --- @@ -1783,22 +1783,35 @@ msgvault pack-attachments The daemon serializes packing against sync and backup operations. Reads remain available from loose, packed, or mixed storage, and the command is safe to -rerun as new loose content arrives. Bounded packing also runs after successful -attachment-producing commands sent to the daemon. Scheduled syncs never pack -inline: when one writes new loose blobs, the daemon's `attachment-pack` job -(every 6 hours) packs them, and the daily `attachment-maintenance` job packs -and repacks. Each automatic pack pass has a 256 MiB soft raw-byte budget and -finishes its current blob before stopping for that byte limit. Scheduled packing -and daily attachment maintenance also stop after one minute, which lets queued -scheduled work run. Each scheduled pack pass verifies at most 128 -existing packed blobs or 32 MiB of their raw content, allowing one oversized -blob. Its durable hash cursor resumes verification after a restart, while new -loose blobs can be packed during each pass. Manual unpacking reads the full -catalog. Cancellation preserves committed packs. A pass with committed -progress resumes behind waiting work; runtime expiry without a checkpoint -records an error and waits for the next trigger. The first pack tick after a -restart also checks for blobs left by the previous daemon. -This command processes the complete eligible backlog immediately. +rerun as new loose content arrives. This command processes the complete +eligible backlog immediately. + +The daemon also packs automatically: + +- After a successful attachment-producing command sent to the daemon, such as + `sync` or an import, the command returns as soon as its own work finishes. + The daemon then starts its `attachment-pack` job in the background. A daemon + started on demand stays running while that job waits and runs, and still + stops after its idle timeout once the job finishes. +- The `attachment-pack` job also runs every 6 hours, which packs loose blobs + written by scheduled syncs. Scheduled syncs never pack inline. +- The daily `attachment-maintenance` job packs, finishes a verification + cycle, and repacks. + +Each automatic pack pass has a 256 MiB soft raw-byte budget and finishes its +current blob before stopping for that byte limit. Passes stop after one minute, +which lets queued work run, and yield to waiting requests. Each pass also +verifies the next window of at most 128 existing packed blobs or 32 MiB of +their raw content, allowing one oversized blob, so its cost follows the new +content rather than the archive's size. A durable hash cursor resumes +verification after a restart. The `attachment-pack` job verifies one window +per pass and queues follow-ups only while loose blobs remain; the daily job +continues until the whole cycle is verified. Manual unpacking reads the full +catalog. Cancellation, including daemon shutdown, preserves committed packs. A +pass with committed progress resumes behind waiting work; runtime expiry +without a checkpoint records an error and waits for the next trigger, such as +the next sync. The first pack pass after a restart also checks for blobs left +by the previous daemon. With `[data].loose_attachments = true`, automatic packing is disabled and this command refuses to run. diff --git a/internal/scheduler/scheduler.go b/internal/scheduler/scheduler.go index ef3d096ca..f5cb95561 100644 --- a/internal/scheduler/scheduler.go +++ b/internal/scheduler/scheduler.go @@ -830,6 +830,26 @@ func (s *Scheduler) StartJob(name string) error { return nil } +// RequestJob asks for one run of the named generic job without waiting for +// it. Like StartJob, it returns once the run is reserved, so a caller that +// holds the daemon's operation gate releases it before the job acquires it. +// Like a cron tick, a request that finds the job executing queues one +// follow-up run instead of being dropped, and a request that finds a run +// still waiting to start is absorbed by that run. +func (s *Scheduler) RequestJob(name string) error { + run, ok, err := s.reserveGenericJob(name, true) + if err != nil { + return err + } + if !ok { + return nil + } + go func() { + _ = s.runJob(name, run) + }() + return nil +} + // onJobTick handles one cron firing for a generic job, coalescing a tick // that arrives while the job is active like onAccountTick does. func (s *Scheduler) onJobTick(name string) { diff --git a/internal/scheduler/scheduler_test.go b/internal/scheduler/scheduler_test.go index 5cf4a9b0d..f03b46895 100644 --- a/internal/scheduler/scheduler_test.go +++ b/internal/scheduler/scheduler_test.go @@ -267,6 +267,55 @@ func TestStartJobIsAsync(t *testing.T) { }) } +// TestRequestJobCoalescesLikeATick proves RequestJob returns before the job +// holds the work gate, that a request made while a run waits for the gate is +// absorbed by that run, and that a request made while a run executes queues +// exactly one follow-up instead of being dropped. +func TestRequestJobCoalescesLikeATick(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + var runs atomic.Int32 + release := make(chan struct{}) + tracker := newSerialWorkTracker() + s := New(func(context.Context, string) error { return nil }).WithWorkTracker(tracker) + defer func() { <-s.Stop().Done() }() + require.NoError(s.AddJob(Job{Name: "job", Schedule: "0 0 1 1 *", Run: func(context.Context) error { + if runs.Add(1) == 1 { + <-release + } + return nil + }})) + + // The caller holds the gate, as an HTTP handler does. + holding, ok := tracker.BeginWork() + require.True(ok) + require.NoError(s.RequestJob("job"), "request while the caller holds the gate") + synctest.Wait() + assert.True(s.JobStatus()[0].Queued, "the run waits for the caller's gate") + require.NoError(s.RequestJob("job"), "request while a run waits to start") + assert.False(s.JobStatus()[0].Pending, "a waiting run absorbs the request") + assert.Equal(int32(0), runs.Load()) + + holding() + synctest.Wait() + require.Equal(int32(1), runs.Load(), "the run starts once the caller releases the gate") + require.NoError(s.RequestJob("job"), "request while the run executes") + require.NoError(s.RequestJob("job"), "a second request coalesces into the same follow-up") + assert.True(s.JobStatus()[0].Pending, "an executing run queues one follow-up") + + close(release) + synctest.Wait() + assert.Equal(int32(2), runs.Load(), "exactly one follow-up runs") + assert.False(s.JobStatus()[0].Running) + + require.Error(s.RequestJob("missing"), "unknown jobs are rejected") + <-s.Stop().Done() + require.Error(s.RequestJob("job"), "a stopped scheduler starts nothing") + assert.Equal(int32(2), runs.Load()) + }) +} + func TestStartStop(t *testing.T) { s := New(func(ctx context.Context, email string) error { return nil diff --git a/internal/store/pack_liveness_index_test.go b/internal/store/pack_liveness_index_test.go index 047dd9da8..939250473 100644 --- a/internal/store/pack_liveness_index_test.go +++ b/internal/store/pack_liveness_index_test.go @@ -47,3 +47,33 @@ func TestAttachmentPackLivenessQueriesUseExpressionIndexes(t *testing.T) { }) } } + +func TestUnpackedBlobQueriesReadOnlyCandidateRows(t *testing.T) { + require := require.New(t) + dir := t.TempDir() + st, err := OpenForTest(filepath.Join(dir, "unpacked.db")) + require.NoError(err) + defer func() { require.NoError(st.Close()) }() + require.NoError(st.InitSchema()) + + tests := map[string]struct { + sql string + index string + key string + }{ + "content": {sql: listUnpackedContentBlobsSQL, index: "idx_attachments_hash", key: "content_hash"}, + "thumbnail": {sql: listUnpackedThumbnailBlobsSQL, index: "idx_attachments_thumbnail_hash", key: "thumbnail_hash"}, + } + for name, tc := range tests { + t.Run(name, func(t *testing.T) { + assert := assert.New(t) + plan := explainPlan(t, st, tc.sql) + t.Logf("query plan:\n%s", plan) + assert.Contains(plan, "candidate USING COVERING INDEX "+tc.index, + "candidates must come from the hash index without reading attachment rows:\n%s", plan) + assert.Contains(plan, "SEARCH attachments USING INDEX "+tc.index+" ("+tc.key+"=?)", + "attachment rows must be read only for candidate hashes:\n%s", plan) + assert.NotContains(plan, "SCAN attachments", "no attachment table scan:\n%s", plan) + }) + } +} diff --git a/internal/store/packs.go b/internal/store/packs.go index a6c0f05d9..b03bde65c 100644 --- a/internal/store/packs.go +++ b/internal/store/packs.go @@ -694,34 +694,47 @@ func (s *Store) ListUnpackedBlobsContext(ctx context.Context) ([]UnpackedBlob, e return nil } - if err := collect(` + if err := collect(listUnpackedContentBlobsSQL, true); err != nil { + return nil, err + } + if err := collect(listUnpackedThumbnailBlobsSQL, false); err != nil { + return nil, err + } + return blobs, nil +} + +// The unpacked-blob queries find their few candidate hashes from the hash +// indexes alone, then read attachment rows only for those hashes. Testing +// every row against the pack index directly would read every attachment row +// of a large archive to find a handful of new blobs. +const ( + listUnpackedContentBlobsSQL = ` SELECT content_hash, storage_path, COALESCE(MAX(size), -1) FROM attachments - WHERE content_hash IS NOT NULL AND content_hash != '' + WHERE content_hash IN ( + SELECT candidate.content_hash FROM attachments AS candidate + WHERE candidate.content_hash IS NOT NULL AND candidate.content_hash != '' + AND NOT EXISTS (SELECT 1 FROM attachment_pack_index p + WHERE p.blob_hash = LOWER(candidate.content_hash))) AND storage_path IS NOT NULL AND storage_path != '' AND LOWER(storage_path) NOT LIKE 'http://%' AND LOWER(storage_path) NOT LIKE 'https://%' - AND NOT EXISTS (SELECT 1 FROM attachment_pack_index p - WHERE p.blob_hash = LOWER(attachments.content_hash)) GROUP BY content_hash, storage_path - ORDER BY MIN(id), storage_path`, true); err != nil { - return nil, err - } - if err := collect(` + ORDER BY MIN(id), storage_path` + listUnpackedThumbnailBlobsSQL = ` SELECT thumbnail_hash, thumbnail_path FROM attachments - WHERE thumbnail_hash IS NOT NULL AND thumbnail_hash != '' + WHERE thumbnail_hash IN ( + SELECT candidate.thumbnail_hash FROM attachments AS candidate + WHERE candidate.thumbnail_hash IS NOT NULL AND candidate.thumbnail_hash != '' + AND NOT EXISTS (SELECT 1 FROM attachment_pack_index p + WHERE p.blob_hash = LOWER(candidate.thumbnail_hash))) AND thumbnail_path IS NOT NULL AND thumbnail_path != '' AND LOWER(thumbnail_path) NOT LIKE 'http://%' AND LOWER(thumbnail_path) NOT LIKE 'https://%' - AND NOT EXISTS (SELECT 1 FROM attachment_pack_index p - WHERE p.blob_hash = LOWER(attachments.thumbnail_hash)) GROUP BY thumbnail_hash, thumbnail_path - ORDER BY MIN(id), thumbnail_path`, false); err != nil { - return nil, err - } - return blobs, nil -} + ORDER BY MIN(id), thumbnail_path` +) // ListIndexedBlobHashes returns the set of all packed blob hashes. func (s *Store) ListIndexedBlobHashes() (map[string]struct{}, error) { From 217ba7adaef09dabba3b22bab616de31f61e8037 Mon Sep 17 00:00:00 2001 From: Richie Caputo Date: Wed, 14 Oct 2026 06:19:15 -0700 Subject: [PATCH 2/3] test(attachments): cover import requests that cannot stream pack failures The import path no longer packs inside the request, so there is no pack warning to stream. Assert that a maintenance fault neither fails nor writes to an import request and that the pack request stays pending. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01793XPgu1pMcfXjFd423RNP --- cmd/msgvault/cmd/serve_test.go | 16 ++++++++++------ 1 file changed, 10 insertions(+), 6 deletions(-) diff --git a/cmd/msgvault/cmd/serve_test.go b/cmd/msgvault/cmd/serve_test.go index c28e23b6c..c5e0c4b49 100644 --- a/cmd/msgvault/cmd/serve_test.go +++ b/cmd/msgvault/cmd/serve_test.go @@ -2722,25 +2722,29 @@ func TestStoreAPIAdapterSyncNeverWaitsForOrStreamsBackgroundPackFailures(t *test assert.True(maintenance.packPending.Load(), "the sync leaves its pack request pending") assert.NotContains(logs.String(), "automatic attachment maintenance", "no pack pass ran inside the request") } -func TestStoreAPIAdapterMaintenanceWarningStreamFailurePreservesSuccess(t *testing.T) { +func TestStoreAPIAdapterImportNeverStreamsBackgroundPackFailures(t *testing.T) { require := require.New(t) assert := assert.New(t) maintenance, logs := newFailingAttachmentMaintenance(t) adapter := &storeAPIAdapter{store: maintenance.store, attachmentMaintenance: maintenance} - warningErr := errors.New("client disconnected") + emitted := 0 err := adapter.runCLICommandWithRunner( context.Background(), api.CLIRunRequest{Args: []string{importMboxCommand, "archive.mbox"}}, - func(api.CLIRunEvent) error { return warningErr }, + func(api.CLIRunEvent) error { + emitted++ + return errors.New("client disconnected") + }, func(context.Context, []string, map[string]string, string, func(string, string) error) error { return nil }, ) - require.NoError(err, "warning stream failure must preserve command success") - assert.Contains(logs.String(), "failed to emit automatic attachment maintenance warning") - assert.Contains(logs.String(), warningErr.Error()) + require.NoError(err, "a maintenance fault cannot fail the import request") + assert.Zero(emitted, "the request streams only the import's own output") + assert.True(maintenance.packPending.Load(), "the import leaves its pack request pending") + assert.NotContains(logs.String(), "automatic attachment maintenance", "no pack pass ran inside the request") } func TestStoreAPIAdapterServesCLIInitDB(t *testing.T) { From a73b7b9d0c458c0bd8bfb2435cf071675afa6247 Mon Sep 17 00:00:00 2001 From: Richie Caputo Date: Wed, 14 Oct 2026 08:23:36 -0700 Subject: [PATCH 3/3] fix(attachments): warn the next ingest when background packing failed A background pack pass has no request to report to, so its failures were visible only in the daemon log. The next sync, import, or message repair sent to the daemon now prints one line on stderr when the attachment-pack job's last pass failed, naming the error and `msgvault pack-attachments`. A clean pass clears the notice, and a notice that cannot be delivered never changes the ingest result. Tests now also cover the daily job chaining a whole verification cycle, the idle tracker counting the pack job while it waits for the gate, and the unpacked-blob queries against a row-by-row definition on seeded random archives. The docs no longer claim a pass's cost is independent of archive size: each pass still lists every hash and checks every pack file. Co-Authored-By: Claude Opus 5.5 Claude-Session: https://claude.ai/code/session_01793XPgu1pMcfXjFd423RNP --- cmd/msgvault/cmd/attachment_maintenance.go | 53 ++++- .../cmd/attachment_maintenance_test.go | 135 +++++++++++- cmd/msgvault/cmd/serve.go | 15 +- cmd/msgvault/cmd/serve_test.go | 75 ++++++- docs/changelog.md | 5 +- docs/cli-reference.md | 15 +- .../store/pack_unpacked_equivalence_test.go | 203 ++++++++++++++++++ 7 files changed, 471 insertions(+), 30 deletions(-) create mode 100644 internal/store/pack_unpacked_equivalence_test.go diff --git a/cmd/msgvault/cmd/attachment_maintenance.go b/cmd/msgvault/cmd/attachment_maintenance.go index 7a094acb8..c3e5b5c51 100644 --- a/cmd/msgvault/cmd/attachment_maintenance.go +++ b/cmd/msgvault/cmd/attachment_maintenance.go @@ -5,6 +5,7 @@ import ( "errors" "fmt" "log/slog" + "strings" "sync/atomic" "time" @@ -49,10 +50,12 @@ type attachmentMaintenance struct { // has drained yet. Startup requests one scan of existing blobs. packPending atomic.Bool // requestPackJob asks the daemon scheduler for a background - // attachment-pack run. registerAttachmentPackJob sets it before the - // daemon serves requests; without it a pending pass waits for the job's - // schedule. - requestPackJob func() error + // attachment-pack run, and packJobLastError reports the scheduler's + // record of that job's last failure. registerAttachmentPackJob sets both + // before the daemon serves requests; without them a pending pass waits + // for the job's schedule. + requestPackJob func() error + packJobLastError func() string } func newAttachmentMaintenance( @@ -240,9 +243,10 @@ func (m *attachmentMaintenance) logAutomaticRepackSummary(message string, stats } // runScheduledPack performs one pass that packs new loose blobs within the -// byte budget and verifies the next window of existing packed blobs, so its -// cost tracks new content rather than archive size. A pass that stops at its -// byte budget leaves packPending set. verifyMore reports that the durable +// byte budget and verifies only the next window of existing packed blobs. +// The pass still lists every referenced hash and checks every pack file, so +// part of its cost grows with the archive. A pass that stops at its byte +// budget leaves packPending set. verifyMore reports that the durable // verification cursor has further windows. func (m *attachmentMaintenance) runScheduledPack(ctx context.Context) (verifyMore bool, err error) { if !m.packCreationEnabled { @@ -346,17 +350,40 @@ func (m *attachmentMaintenance) log() *slog.Logger { return slog.Default() } +// reportPackFailure tells the user of a manual ingest that the previous +// background pack pass failed. A background pass has no request to report +// to, so the next ingest carries a one-line notice. Notices are +// best-effort and never change the ingest result. +func (m *attachmentMaintenance) reportPackFailure(emitNotice func(string) error) { + if m == nil || emitNotice == nil || m.packJobLastError == nil { + return + } + lastErr := strings.TrimSpace(m.packJobLastError()) + if lastErr == "" { + return + } + notice := fmt.Sprintf( + "Warning: the last background attachment packing pass failed: %s; run `msgvault pack-attachments` to retry.\n", + strings.Join(strings.Fields(lastErr), " ")) + if err := emitNotice(notice); err != nil { + m.log().Warn("failed to emit attachment packing notice", "error", err) + } +} + // runAfterSuccessfulAttachmentIngest requests background packing only after // a successful ingest. The caller's request returns as soon as the ingest -// does; packing can neither delay nor replace the ingest result. +// does; packing can neither delay nor replace the ingest result. A failure +// of the previous background pass is reported through emitNotice. func runAfterSuccessfulAttachmentIngest( ctx context.Context, maintenance *attachmentMaintenance, ingest func(context.Context) error, + emitNotice func(string) error, ) error { if err := runWithAttachmentMutation(ctx, maintenance, ingest); err != nil { return err } + maintenance.reportPackFailure(emitNotice) maintenance.requestPack() return nil } @@ -440,8 +467,16 @@ func registerAttachmentPackJob(sched *scheduler.Scheduler, maintenance *attachme return err } // A daemon started on demand may idle out long before the next cron - // tick, so ingests start the job themselves. + // tick, so ingests start the job themselves and report its failures. maintenance.requestPackJob = func() error { return sched.RequestJob(attachmentPackJob) } + maintenance.packJobLastError = func() string { + for _, status := range sched.JobStatus() { + if status.Name == attachmentPackJob { + return status.LastError + } + } + return "" + } return nil } diff --git a/cmd/msgvault/cmd/attachment_maintenance_test.go b/cmd/msgvault/cmd/attachment_maintenance_test.go index 922c696e5..5e430c21e 100644 --- a/cmd/msgvault/cmd/attachment_maintenance_test.go +++ b/cmd/msgvault/cmd/attachment_maintenance_test.go @@ -236,7 +236,7 @@ func TestBackgroundPackFailureLogsProgressAndStaysPending(t *testing.T) { maintenance, logs := newFailingAttachmentMaintenance(t) require.NoError(runAfterSuccessfulAttachmentIngest( - context.Background(), maintenance, func(context.Context) error { return nil }, + context.Background(), maintenance, func(context.Context) error { return nil }, nil, ), "a later maintenance failure cannot reach the ingest result") require.Error(maintenance.runPendingPack(context.Background()), "the job records the failure") assert.True(maintenance.packPending.Load(), "a failed pass leaves its work pending") @@ -624,7 +624,7 @@ func TestAttachmentIngestMutationLeaseWaitsForMaintenance(t *testing.T) { func(context.Context) error { close(ingestStarted) return nil - }, + }, nil, ) }() @@ -752,7 +752,7 @@ func TestBackgroundPackKeepsIdleDaemonAliveUntilItFinishes(t *testing.T) { release := f.holdPackPass() require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, - func(context.Context) error { return nil })) + func(context.Context) error { return nil }, nil)) // Longer than the idle timeout, shorter than the job's runtime limit. synctest.Sleep(2 * idleTimeout) select { @@ -790,7 +790,7 @@ func TestBackgroundPackStopsAtRuntimeLimitAndNextIngestResumesIt(t *testing.T) { release := f.holdPackPass() require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, - func(context.Context) error { return nil })) + func(context.Context) error { return nil }, nil)) synctest.Sleep(automaticAttachmentMaxRuntime + time.Second) synctest.Wait() @@ -802,16 +802,135 @@ func TestBackgroundPackStopsAtRuntimeLimitAndNextIngestResumesIt(t *testing.T) { assert.True(f.maintenance.packPending.Load(), "the unfinished work stays pending") release() - // The next manual ingest restarts the job, which picks up the pending work. + // The next manual ingest reports the failed pass and restarts the job, + // which picks up the pending work. + var notices []string + collect := func(message string) error { + notices = append(notices, message) + return nil + } require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, - func(context.Context) error { return nil })) + func(context.Context) error { return nil }, collect)) + require.Len(notices, 1, "one notice about the failed pass") + assert.Contains(notices[0], "last background attachment packing pass failed") + assert.Contains(notices[0], jobctx.ErrRunBudgetExceeded.Error()) + assert.Contains(notices[0], "msgvault pack-attachments") + assert.Equal(1, strings.Count(notices[0], "\n"), "the notice is one line") synctest.Wait() assert.NotNil(f.packedEntry(hash)) assert.False(f.maintenance.packPending.Load()) assert.Empty(attachmentPackJobStatus(t, sched).LastError) + + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil }, collect)) + assert.Len(notices, 1, "a clean pass clears the notice") + synctest.Wait() + }) +} + +func TestPackFailureNoticeCannotFailTheIngest(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + f.addLoose([]byte("blob whose pass fails before a disconnected client returns")) + _, _ = newBackgroundPackHarness(t, f) + release := f.holdPackPass() + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil }, nil)) + synctest.Sleep(automaticAttachmentMaxRuntime + time.Second) + synctest.Wait() + release() + + err := runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil }, + func(string) error { return errors.New("client disconnected") }) + + require.NoError(err, "a notice that cannot be delivered never fails the ingest") + synctest.Wait() // the requested pass also writes to the log + assert.Contains(f.logs.String(), "failed to emit attachment packing notice") + assert.Contains(f.logs.String(), "client disconnected") }) } +// TestQueuedPackJobCountsAsDaemonActivity covers the window before the job +// holds the operation gate: another holder keeps it queued past the idle +// timeout, and the daemon must not stop with packing still waiting. +func TestQueuedPackJobCountsAsDaemonActivity(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + hash := f.addLoose([]byte("blob queued behind another gate holder")) + const idleTimeout = 20 * time.Second + idleShutdown := make(chan struct{}) + idle := api.NewIdleTracker(idleTimeout, func() { close(idleShutdown) }) + gate := api.NewSerialOperationGate() + sched, media := newServeSchedulers(nil, f.maintenance.logger, idle, gate) + defer func() { <-serveSchedulers{sched, media}.Stop().Done() }() + require.NoError(registerAttachmentPackJob(sched, f.maintenance)) + go idle.Run(t.Context()) + releaseGate, ok := gate.BeginLabeledWorkContext(t.Context(), "other archive work") + require.True(ok) + + require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, + func(context.Context) error { return nil }, nil)) + synctest.Sleep(2 * idleTimeout) + select { + case <-idleShutdown: + require.FailNow("the daemon idled out while its pack job waited for the gate") + default: + } + status := attachmentPackJobStatus(t, sched) + assert.True(status.Queued, "the job is still waiting for the gate") + assert.Nil(f.packedEntry(hash)) + + releaseGate() + synctest.Wait() + assert.NotNil(f.packedEntry(hash)) + synctest.Sleep(idleTimeout + time.Second) + select { + case <-idleShutdown: + default: + assert.Fail("an idle daemon must still shut down after packing") + } + }) +} + +// TestDailyMaintenanceChainsTheWholeVerificationCycle runs the daily job the +// way the scheduler does, one pass per follow-up, and checks that it verifies +// every window before it repacks. +func TestDailyMaintenanceChainsTheWholeVerificationCycle(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + for i := range 140 { // two verification windows: 128 + 12 + f.addLoose([]byte(fmt.Sprintf("packed before the daily job %d", i))) + } + _, err := f.maintenance.pack(t.Context(), 0) + require.NoError(err) + + followUps := 0 + for { + err := f.maintenance.daily(t.Context()) + if !errors.Is(err, scheduler.ErrReschedule) { + require.NoError(err) + break + } + followUps++ + require.Less(followUps, 10, "the daily chain must end") + } + + assert.Equal(1, followUps, "the second window needs one follow-up") + var cursor string + require.NoError(f.store.DB().QueryRow(f.store.Rebind( + `SELECT value FROM archive_metadata WHERE key = ?`), "attachment_pack_verification_cursor").Scan(&cursor)) + assert.Empty(cursor, "a finished cycle resets the verification cursor") + assert.Equal(2, strings.Count(f.logs.String(), "automatic attachment maintenance complete")) + assert.Equal(1, strings.Count(f.logs.String(), "automatic attachment repack complete"), + "repack runs once, after the cycle") +} + func TestBackgroundPackCancelsOnShutdownAndRestartResumesIt(t *testing.T) { synctest.Test(t, func(t *testing.T) { require := require.New(t) @@ -824,7 +943,7 @@ func TestBackgroundPackCancelsOnShutdownAndRestartResumesIt(t *testing.T) { release := f.holdPackPass() require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), f.maintenance, - func(context.Context) error { return nil })) + func(context.Context) error { return nil }, nil)) synctest.Wait() require.True(attachmentPackJobStatus(t, sched).Running) require.NoError(shutdownServeRuntime(t.Context(), io.Discard, nil, @@ -842,7 +961,7 @@ func TestBackgroundPackCancelsOnShutdownAndRestartResumesIt(t *testing.T) { defer func() { <-restartedSched.Stop().Done() }() require.NoError(registerAttachmentPackJob(restartedSched, restarted)) require.NoError(runAfterSuccessfulAttachmentIngest(t.Context(), restarted, - func(context.Context) error { return nil })) + func(context.Context) error { return nil }, nil)) synctest.Wait() assert.NotNil(f.packedEntry(hash)) }) diff --git a/cmd/msgvault/cmd/serve.go b/cmd/msgvault/cmd/serve.go index f789241c6..fd0c85951 100644 --- a/cmd/msgvault/cmd/serve.go +++ b/cmd/msgvault/cmd/serve.go @@ -2085,9 +2085,12 @@ func (a *storeAPIAdapter) runCLISyncWithRunner( } return emit(api.CLISyncEvent{Type: stream, Data: data}) } + emitNotice := func(message string) error { + return emitSubprocess(cliStreamStderr, message) + } return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, func(ctx context.Context) error { return run(ctx, cliSyncSubprocessArgs(req), emitSubprocess) - }) + }, emitNotice) } // emitFolderArgs appends a --folder/--skip-folder flag for each @@ -2224,7 +2227,10 @@ func (a *storeAPIAdapter) runCLIRepairMessageWithRunner( if req.Audit { return runRepair(ctx) } - return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, runRepair) + emitNotice := func(message string) error { + return emitSubprocess(cliStreamStderr, message) + } + return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, runRepair, emitNotice) } func cliRepairMessageSubprocessArgs(req api.CLIRepairMessageRequest) []string { @@ -2337,7 +2343,10 @@ func (a *storeAPIAdapter) runCLICommandWithRunner( ctx, a.attachmentMaintenance, runSubprocess, emitWarning, ) } - return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, runSubprocess) + emitNotice := func(message string) error { + return emitSubprocess(cliStreamStderr, message) + } + return runAfterSuccessfulAttachmentIngest(ctx, a.attachmentMaintenance, runSubprocess, emitNotice) } func attachmentRemovalCommand(args []string) bool { diff --git a/cmd/msgvault/cmd/serve_test.go b/cmd/msgvault/cmd/serve_test.go index c5e0c4b49..1957c6b90 100644 --- a/cmd/msgvault/cmd/serve_test.go +++ b/cmd/msgvault/cmd/serve_test.go @@ -2328,6 +2328,77 @@ func TestStoreAPIAdapterFinalizesSyncOperationAfterRunnerReturns(t *testing.T) { assert.Equal("done", op.Status) } +// TestStoreAPIAdapterIngestsReportPreviousPackFailure proves each ingest +// request tells its CLI, on stderr, that the last background pack pass failed. +func TestStoreAPIAdapterIngestsReportPreviousPackFailure(t *testing.T) { + ingests := map[string]func(*storeAPIAdapter, context.Context) ([]string, error){ + "sync": func(a *storeAPIAdapter, ctx context.Context) ([]string, error) { + var stderr []string + err := a.runCLISyncWithRunner(ctx, api.CLISyncRequest{Email: "alice@example.com"}, + func(event api.CLISyncEvent) error { + if event.Type == cliStreamStderr { + stderr = append(stderr, event.Data) + } + return nil + }, + func(context.Context, []string, func(string, string) error) error { return nil }) + return stderr, err + }, + "import": func(a *storeAPIAdapter, ctx context.Context) ([]string, error) { + var stderr []string + err := a.runCLICommandWithRunner(ctx, api.CLIRunRequest{Args: []string{importMboxCommand, "archive.mbox"}}, + func(event api.CLIRunEvent) error { + if event.Type == cliStreamStderr { + stderr = append(stderr, event.Data) + } + return nil + }, + func(context.Context, []string, map[string]string, string, func(string, string) error) error { + return nil + }) + return stderr, err + }, + "repair": func(a *storeAPIAdapter, ctx context.Context) ([]string, error) { + var stderr []string + err := a.runCLIRepairMessageWithRunner(ctx, api.CLIRepairMessageRequest{Reference: "gmail-42"}, + func(event api.CLIRepairMessageEvent) error { + if event.Type == cliStreamStderr { + stderr = append(stderr, event.Data) + } + return nil + }, + func(context.Context, []string, func(string, string) error) error { return nil }) + return stderr, err + }, + } + for name, ingest := range ingests { + t.Run(name, func(t *testing.T) { + synctest.Test(t, func(t *testing.T) { + require := require.New(t) + assert := assert.New(t) + f := newAttachmentMaintenanceFixture(t) + f.addLoose([]byte("blob whose first background pass fails")) + _, _ = newBackgroundPackHarness(t, f) + adapter := &storeAPIAdapter{store: f.store, attachmentMaintenance: f.maintenance} + release := f.holdPackPass() + _, err := ingest(adapter, t.Context()) + require.NoError(err) + synctest.Sleep(automaticAttachmentMaxRuntime + time.Second) + synctest.Wait() + release() + + stderr, err := ingest(adapter, t.Context()) + + require.NoError(err) + require.Len(stderr, 1) + assert.Contains(stderr[0], "last background attachment packing pass failed") + assert.Contains(stderr[0], "msgvault pack-attachments") + synctest.Wait() + }) + }) + } +} + func TestStoreAPIAdapterRunCLICommandPacksOnlyAllowlistedSuccess(t *testing.T) { tests := []struct { name string @@ -2700,7 +2771,7 @@ func TestStoreAPIAdapterExplicitRepackCancellationFailsFast(t *testing.T) { assert.True(has, "fail-fast cancellation leaves physical inventory untouched") } -func TestStoreAPIAdapterSyncNeverWaitsForOrStreamsBackgroundPackFailures(t *testing.T) { +func TestStoreAPIAdapterSyncDoesNotPackInsideTheRequest(t *testing.T) { require := require.New(t) assert := assert.New(t) maintenance, logs := newFailingAttachmentMaintenance(t) @@ -2722,7 +2793,7 @@ func TestStoreAPIAdapterSyncNeverWaitsForOrStreamsBackgroundPackFailures(t *test assert.True(maintenance.packPending.Load(), "the sync leaves its pack request pending") assert.NotContains(logs.String(), "automatic attachment maintenance", "no pack pass ran inside the request") } -func TestStoreAPIAdapterImportNeverStreamsBackgroundPackFailures(t *testing.T) { +func TestStoreAPIAdapterImportDoesNotPackInsideTheRequest(t *testing.T) { require := require.New(t) assert := assert.New(t) maintenance, logs := newFailingAttachmentMaintenance(t) diff --git a/docs/changelog.md b/docs/changelog.md index e396c6d39..b5fe51484 100644 --- a/docs/changelog.md +++ b/docs/changelog.md @@ -10,8 +10,9 @@ All notable changes to msgvault, grouped by release. - A `sync` or import sent to the daemon returns when its own work finishes. Attachment packing now runs afterwards as the daemon's bounded - `attachment-pack` job instead of inside the request, and a daemon started on - demand stays up until that job finishes. Each pass verifies one bounded + `attachment-pack` job instead of inside the request. A daemon started on + demand stays up until that job finishes, and the next such command warns + when the previous background pass failed. Each pass verifies one bounded window of existing packs instead of every packed blob, and finding new loose blobs no longer reads every attachment row. diff --git a/docs/cli-reference.md b/docs/cli-reference.md index cbbb9c8fe..831b54770 100644 --- a/docs/cli-reference.md +++ b/docs/cli-reference.md @@ -1792,7 +1792,9 @@ The daemon also packs automatically: `sync` or an import, the command returns as soon as its own work finishes. The daemon then starts its `attachment-pack` job in the background. A daemon started on demand stays running while that job waits and runs, and still - stops after its idle timeout once the job finishes. + stops after its idle timeout once the job finishes. If the job's previous + pass failed, the command prints a one-line warning on stderr; run + `msgvault pack-attachments` to retry. - The `attachment-pack` job also runs every 6 hours, which packs loose blobs written by scheduled syncs. Scheduled syncs never pack inline. - The daily `attachment-maintenance` job packs, finishes a verification @@ -1802,11 +1804,12 @@ Each automatic pack pass has a 256 MiB soft raw-byte budget and finishes its current blob before stopping for that byte limit. Passes stop after one minute, which lets queued work run, and yield to waiting requests. Each pass also verifies the next window of at most 128 existing packed blobs or 32 MiB of -their raw content, allowing one oversized blob, so its cost follows the new -content rather than the archive's size. A durable hash cursor resumes -verification after a restart. The `attachment-pack` job verifies one window -per pass and queues follow-ups only while loose blobs remain; the daily job -continues until the whole cycle is verified. Manual unpacking reads the full +their raw content, allowing one oversized blob, instead of every packed blob. +A pass still lists every attachment hash and checks every pack file, so it +takes longer on a larger archive even when little is new. A durable hash +cursor resumes verification after a restart. The `attachment-pack` job +verifies one window per pass and queues follow-ups only while loose blobs +remain; the daily job continues until the whole cycle is verified. Manual unpacking reads the full catalog. Cancellation, including daemon shutdown, preserves committed packs. A pass with committed progress resumes behind waiting work; runtime expiry without a checkpoint records an error and waits for the next trigger, such as diff --git a/internal/store/pack_unpacked_equivalence_test.go b/internal/store/pack_unpacked_equivalence_test.go new file mode 100644 index 000000000..968e999d4 --- /dev/null +++ b/internal/store/pack_unpacked_equivalence_test.go @@ -0,0 +1,203 @@ +package store + +// The unpacked-blob queries read attachment rows only for candidate hashes. +// This test holds them to the plain row-by-row definition below, which tests +// every attachment row against the pack index, on seeded random archives with +// mixed-case, NULL, empty, BLOB, and integer hash values. + +import ( + "fmt" + "math/rand/v2" + "path/filepath" + "strings" + "testing" + + "github.com/stretchr/testify/require" +) + +const rowByRowUnpackedContentSQL = ` + SELECT content_hash, storage_path, COALESCE(MAX(size), -1) + FROM attachments + WHERE content_hash IS NOT NULL AND content_hash != '' + AND storage_path IS NOT NULL AND storage_path != '' + AND LOWER(storage_path) NOT LIKE 'http://%' + AND LOWER(storage_path) NOT LIKE 'https://%' + AND NOT EXISTS (SELECT 1 FROM attachment_pack_index p + WHERE p.blob_hash = LOWER(attachments.content_hash)) + GROUP BY content_hash, storage_path + ORDER BY MIN(id), storage_path` + +const rowByRowUnpackedThumbnailSQL = ` + SELECT thumbnail_hash, thumbnail_path + FROM attachments + WHERE thumbnail_hash IS NOT NULL AND thumbnail_hash != '' + AND thumbnail_path IS NOT NULL AND thumbnail_path != '' + AND LOWER(thumbnail_path) NOT LIKE 'http://%' + AND LOWER(thumbnail_path) NOT LIKE 'https://%' + AND NOT EXISTS (SELECT 1 FROM attachment_pack_index p + WHERE p.blob_hash = LOWER(attachments.thumbnail_hash)) + GROUP BY thumbnail_hash, thumbnail_path + ORDER BY MIN(id), thumbnail_path` + +func dumpUnpackedQuery(t *testing.T, st *Store, query string) []string { + t.Helper() + rows, err := st.db.QueryContext(t.Context(), query) + require.NoError(t, err) + defer func() { _ = rows.Close() }() + cols, err := rows.Columns() + require.NoError(t, err) + var out []string + for rows.Next() { + vals := make([]any, len(cols)) + ptrs := make([]any, len(cols)) + for i := range vals { + ptrs[i] = &vals[i] + } + require.NoError(t, rows.Scan(ptrs...)) + var b strings.Builder + for _, v := range vals { + fmt.Fprintf(&b, "%T:%v|", v, v) + } + out = append(out, b.String()) + } + require.NoError(t, rows.Err()) + return out +} + +func TestUnpackedBlobQueriesMatchRowByRowDefinition(t *testing.T) { + require := require.New(t) + const iterations = 300 + dir := t.TempDir() + st, err := OpenForTest(filepath.Join(dir, "equiv.db")) + require.NoError(err) + defer func() { require.NoError(st.Close()) }() + require.NoError(st.InitSchema()) + ctx := t.Context() + // One connection, so the pragma applies to every statement below. + st.db.SetMaxOpenConns(1) + _, err = st.db.ExecContext(ctx, `PRAGMA foreign_keys = OFF`) + require.NoError(err) + + hexHash := func(r *rand.Rand) string { + const hexd = "0123456789abcdef" + b := make([]byte, 64) + for i := range b { + b[i] = hexd[r.IntN(16)] + } + return string(b) + } + totalContent, totalThumb, nonEmpty := 0, 0, 0 + for iter := range iterations { + r := rand.New(rand.NewPCG(uint64(iter), 0x5eed)) //nolint:gosec // Seeded so a failing iteration reproduces. + _, err := st.db.ExecContext(ctx, `DELETE FROM attachments`) + require.NoError(err) + _, err = st.db.ExecContext(ctx, `DELETE FROM attachment_pack_index`) + require.NoError(err) + + poolSize := 1 + r.IntN(40) + pool := make([]string, poolSize) + for i := range pool { + pool[i] = hexHash(r) + } + hashValue := func() any { + switch r.IntN(20) { + case 0: + return nil + case 1: + return "" + case 2: + return strings.ToUpper(pool[r.IntN(poolSize)]) + case 3: // mixed case + h := []byte(pool[r.IntN(poolSize)]) + for i := range h { + if r.IntN(2) == 0 { + h[i] = strings.ToUpper(string(h[i]))[0] + } + } + return string(h) + case 4: + return "not-a-hash" + case 5: + return " " + pool[r.IntN(poolSize)] + case 6: + return []byte(pool[r.IntN(poolSize)]) // BLOB-typed value + case 7: + return 12345 + default: + return pool[r.IntN(poolSize)] + } + } + pathValue := func(nullable bool) any { + switch k := r.IntN(14); { + case k == 0 && nullable: + return nil + case k == 1: + return "" + case k == 2: + return "http://example.com/x" + case k == 3: + return "HTTPS://Example.com/y" + case k == 4: + return "hTtP://mixed" + case k == 5: + return "ftp://x" + default: + return fmt.Sprintf("%02x/p%d", r.IntN(4), r.IntN(6)) + } + } + rowsN := r.IntN(120) + for i := range rowsN { + var size any + if r.IntN(5) != 0 { + size = r.IntN(1000) + } + var thumbHash, thumbPath any + if r.IntN(3) == 0 { + thumbHash = hashValue() + thumbPath = pathValue(true) + } + _, err := st.db.ExecContext(ctx, `INSERT INTO attachments + (id, message_id, size, content_hash, storage_path, thumbnail_hash, thumbnail_path) + VALUES (?, ?, ?, ?, ?, ?, ?)`, + 1+i*(1+r.IntN(3)), 1+r.IntN(5), size, hashValue(), pathValue(false), thumbHash, thumbPath) + if err != nil && strings.Contains(err.Error(), "UNIQUE") { + continue + } + require.NoError(err) + } + for _, h := range pool { + if r.IntN(2) == 0 { + key := h + if r.IntN(10) == 0 { + key = strings.ToUpper(h) // non-canonical index row + } + _, err := st.db.ExecContext(ctx, `INSERT OR IGNORE INTO attachment_pack_index + (blob_hash, pack_id, pack_offset, stored_len, raw_len, flags, crc32c) + VALUES (?, 'p', 0, 1, 1, 0, 0)`, key) + require.NoError(err) + } + } + if r.IntN(4) == 0 { + _, err := st.db.ExecContext(ctx, `INSERT OR IGNORE INTO attachment_pack_index + (blob_hash, pack_id, pack_offset, stored_len, raw_len, flags, crc32c) + VALUES ('12345', 'p', 0, 1, 1, 0, 0), ('not-a-hash', 'p', 0, 1, 1, 0, 0)`) + require.NoError(err) + } + + wantContent := dumpUnpackedQuery(t, st, rowByRowUnpackedContentSQL) + gotContent := dumpUnpackedQuery(t, st, listUnpackedContentBlobsSQL) + require.Equal(wantContent, gotContent, "content query diverges at iteration %d", iter) + wantThumbnail := dumpUnpackedQuery(t, st, rowByRowUnpackedThumbnailSQL) + gotThumbnail := dumpUnpackedQuery(t, st, listUnpackedThumbnailBlobsSQL) + require.Equal(wantThumbnail, gotThumbnail, "thumbnail query diverges at iteration %d", iter) + totalContent += len(wantContent) + totalThumb += len(wantThumbnail) + if len(wantContent) > 0 && len(wantThumbnail) > 0 { + nonEmpty++ + } + } + // Guard against a generator that stops producing rows to compare. + require.Positive(totalContent) + require.Positive(totalThumb) + require.Positive(nonEmpty) +}