debug: tag reload() breadcrumbs with lock state and NextUID (#647)

helm/Chart.yaml

@@ -2,8 +2,8 @@ apiVersion: v2
 name: yarilo
 description: Production-grade IMAP/POP3/Submission mail server
 type: application
-version: 2.0.18
-appVersion: "2.1.12"
+version: 2.0.19
+appVersion: "2.1.13"
 keywords:
   - imap
   - submission

internal/storage/index/file/file.go

@@ -457,8 +457,16 @@ func (u *userIndex) withFolderRO(folderID uint64, fn func(*folderState) error) e
 	}
 	// Brief exclusive lock to reload on-disk state (another process may
 	// have written since our last flush). Held only for the disk read.
+	//
+	// NOTE (#647): this reload is NOT serialized against u.b.locker, the
+	// cross-process distributed lock every write path (withFolderLock) takes
+	// before its own reload. A concurrent, lock-holding compaction on another
+	// process can interleave with this unlocked read and load a torn view into
+	// the shared in-memory folderState — which every subsequent, correctly
+	// locked write then trusts as a baseline. Passing locked=false so the
+	// reload debug breadcrumbs make this window visible in a live repro.
 	fs.mu.Lock()
-	err := fs.reload()
+	err := fs.reload(false)
 	fs.mu.Unlock()
 	if err != nil && !errors.Is(err, os.ErrNotExist) {
 		return err

internal/storage/index/file/folder.go

@@ -435,7 +435,7 @@
 		return fmt.Errorf("fileindex: folder %d not open", folderID)
 	}
 	return u.withFolderLock(fs, func() error {
-		if err := fs.reload(); err != nil && !errors.Is(err, os.ErrNotExist) {
+		if err := fs.reload(true); err != nil && !errors.Is(err, os.ErrNotExist) {
 			return err
 		}
 		return fn(fs)
@@ -455,9 +455,21 @@
 //     any cross-pod writes without a full base re-read.
 //
 //  3. If the base file changed (after OptimizeIndex), do a full
 //     re-read of base + remaining log.
-func (fs *folderState) reload() error {
+// reload re-syncs fs from disk. locked reports whether the caller holds the
+// cross-process distributed lock (u.b.locker) for this folder — withFolder
+// (writes) always passes true; withFolderRO (reads) passes false, since it
+// only takes the in-process fs.mu (#647: this makes withFolderRO's reload
+// unserialized against another process's locked compaction, a suspected
+// second trigger for the #644 NextUID-regression class of bug alongside the
+// #645 stale-logFD fix). Logged on every reload so a live repro can show an
+// unlocked reload's NextUID diverging from a concurrent locked writer's.
+func (fs *folderState) reload(locked bool) error {
 	t0 := time.Now()
+	nextUIDBefore := uint32(0)
+	if fs.file != nil {
+		nextUIDBefore = fs.file.Header.NextUID
+	}
 	baseStat, baseErr := os.Stat(fs.indexPath)
 
 	// Stat the .log by PATH so a replacement is detected by file IDENTITY, not
@@ -496,8 +508,10 @@
 	if !logReplaced && newBaseMod == fs.baseMod && newLogSize == fs.logSize {
 		slog.Debug("fileindex: reload fast-path",
 			"folder", fs.folder,
+			"locked", locked,
 			"log_size", fs.logSize,
 			"base_mod", fs.baseMod.UnixNano(),
+			"next_uid", nextUIDBefore,
 			"dur_ms", time.Since(t0).Milliseconds())
 		return nil
 	}
@@ -507,10 +521,12 @@
 	}
 	slog.Debug("fileindex: reload full",
 		"folder", fs.folder,
+		"locked", locked,
 		"new_log_size", newLogSize,
 		"old_log_size", fs.logSize,
 		"new_base_mod", newBaseMod.UnixNano(),
 		"old_base_mod", fs.baseMod.UnixNano(),
+		"next_uid_before", nextUIDBefore,
 		"dur_ms", time.Since(t0).Milliseconds())
 
 	// Base file changed (or first open, or the log was replaced by a concurrent
@@ -559,8 +575,11 @@
 	// just-written record was picked up (records_after > records_before) or not.
 	slog.Debug("fileindex: reload applied",
 		"folder", fs.folder,
+		"locked", locked,
 		"records_before", recordsBefore,
 		"records_after", len(fs.file.Records),
+		"next_uid_before", nextUIDBefore,
+		"next_uid_after", fs.file.Header.NextUID,
 		"log_size", fs.logSize,
 		"dur_ms", time.Since(t0).Milliseconds())
 	return nil

internal/storage/index/file/log_replace_test.go

@@ -66,7 +66,7 @@ func TestConcurrentCompactionNoUIDRegression(t *testing.T) {
 	// Pod A reloads. The stale logFD (I1) must be recognised as replaced,
 	// dropped, and the advanced NextUID picked up from the rewritten base.
 	fsA.mu.Lock()
-	if err := fsA.reload(); err != nil {
+	if err := fsA.reload(true); err != nil {
 		fsA.mu.Unlock()
 		t.Fatalf("podA reload: %v", err)
 	}