From 5f63da5962a80c5de40f6ef7d0893e00b57a1a96 Mon Sep 17 00:00:00 2001 From: Ihor Rusyn <0kaba0@gmail.com> Date: Sun, 19 Jul 2026 08:52:07 +0200 Subject: [PATCH] debug: identify the writer that persists NextUID via flush()/createFresh() (#644/#647) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Live evidence on 2.1.13: the properly-locked reload (locked=true) already observes NextUID=1 on disk at the moment it reads — the regression is committed to the base .index file BEFORE that read, not caused by it. This rules out withFolderRO's unlocked reload (#647) as the direct writer in this instance and points back to whichever flush()/createFresh() call persisted the bad value in the first place. flush() now logs its caller (via runtime.Caller) and the NextUID/ MessagesCount it's about to persist — the single choke point that writes fs.file.Header as ground truth and discards the log, called from compactLogIfNeeded, SaveFolder, RecomputeVSize, and reload's indexid-mismatch recovery. createFresh() now logs its caller and requested UIDValidity on every invocation, at WARN — it unconditionally resets NextUID to 1, correct only for a genuinely first-ever OpenFolder or the documented post-corruption fallback. An invocation on an already-established folder (one that has delivered mail earlier in the same run) is the bug. Purely additive logging behind LOG_LEVEL=debug (WARN for createFresh, to survive without needing debug level enabled) — no behavior change. --- helm/Chart.yaml | 4 ++-- internal/storage/index/file/folder.go | 33 +++++++++++++++++++++++++++ 2 files changed, 35 insertions(+), 2 deletions(-) diff --git a/helm/Chart.yaml b/helm/Chart.yaml index b213408b..9b9a3c08 100644 --- a/helm/Chart.yaml +++ b/helm/Chart.yaml @@ -2,8 +2,8 @@ apiVersion: v2 name: yarilo description: Production-grade IMAP/POP3/Submission mail server type: application -version: 2.0.19 -appVersion: "2.1.13" +version: 2.0.20 +appVersion: "2.1.14" keywords: - imap - submission diff --git a/internal/storage/index/file/folder.go b/internal/storage/index/file/folder.go index f2bd399e..88c35dc4 100644 --- a/internal/storage/index/file/folder.go +++ b/internal/storage/index/file/folder.go @@ -7,6 +7,7 @@ import ( "io" "log/slog" "os" + "runtime" "sort" "time" @@ -177,6 +178,22 @@ func (u *userIndex) loadOrInit(fs *folderState, uidValidity uint32) error { // for first-ever OpenFolder and as the fallback after a corrupt // file is moved aside. func (fs *folderState) createFresh(uidValidity uint32) error { + // Breadcrumb (#644/#647): this unconditionally resets NextUID to 1. Correct + // for a genuinely first-ever OpenFolder or post-corruption fallback; a bug + // if ever invoked on a folder whose .index legitimately still exists but a + // caller's os.Stat momentarily/incorrectly reported ErrNotExist. Logs the + // caller so a live repro can tell "expected first-open" from "unexpected + // reset of an established folder" (the latter would show a caller other + // than the two documented ones, or a folder already known to have delivered + // mail before this run). + if pc, _, _, ok := runtime.Caller(1); ok { + caller := "unknown" + if fn := runtime.FuncForPC(pc); fn != nil { + caller = fn.Name() + } + slog.Warn("fileindex: createFresh resetting NextUID to 1", + "folder", fs.folder, "caller", caller, "requested_uidvalidity", uidValidity) + } if uidValidity == 0 { uidValidity = uint32(time.Now().Unix()) } @@ -367,6 +384,22 @@ func (fs *folderState) advanceModSeqAtLeast(target uint64) error { // parameter so a future incremental-names optimisation can be // gated cleanly. func (fs *folderState) flush(wholeNames bool) error { + // Breadcrumb (#644/#647): flush() is the single choke point that persists + // fs.file.Header.NextUID as ground truth and discards the log — if this + // value is ever lower than what another process already advanced the + // folder to, this is where the regression lands on disk. Logs the caller + // (compactLogIfNeeded, SaveFolder, RecomputeVSize, reload's indexid-mismatch + // recovery, ...) so a live repro can identify which flush() call actually + // wrote the bad value, not just that a reader later observed it. + if pc, _, _, ok := runtime.Caller(1); ok { + caller := "unknown" + if fn := runtime.FuncForPC(pc); fn != nil { + caller = fn.Name() + } + slog.Debug("fileindex: flush persisting header", + "folder", fs.folder, "caller", caller, "next_uid", fs.file.Header.NextUID, + "messages_count", fs.file.Header.MessagesCount) + } if err := os.MkdirAll(fs.indexDir, 0o700); err != nil { return fmt.Errorf("fileindex/flush: mkdir: %w", err) }