From de8f9bffa37c66ee4d5a8176400ecb868bc5e2b4 Mon Sep 17 00:00:00 2001 From: Matthew McNeely Date: Mon, 21 Sep 2026 16:04:51 -0400 Subject: [PATCH] fix(vlog): recover the newest surviving file when a 0-byte .vlog is skipped populateFilesMap sets vlog.maxFid from the directory listing before the 0-byte skip runs, so when the crash artifact holds the highest fid the skip drops it from filesMap while maxFid keeps naming it. The filesMap[maxFid] lookup guarding the tail truncation then finds nothing, so iterate and Truncate never run and a partially written entry stays on the newest surviving .vlog. That is the same crash that dropped the 0-byte file, so recovery is skipped exactly when it is needed. The stale value also defeats the `fid != maxFid` guard that keeps a header-only newest file from being deleted. Track newestFid, the highest fid that survived the stat pass, and use it for both. Leave maxFid alone: createVlogFile takes maxFid+1 with O_EXCL, so lowering it would collide with the artifact still sitting on disk. Also log skipped files, wrap the stat error with errFile to match openMemTables, and lower ValueThreshold in TestOpenWithEmptyVlogFile so its values actually reach the value log and the read-only step exercises the vlog read path. Co-Authored-By: Claude Opus 5 (1M context) --- db_test.go | 108 +++++++++++++++++++++++++++++++++++++++++++++++++--- memtable.go | 18 ++++++--- value.go | 47 +++++++++++++++-------- 3 files changed, 147 insertions(+), 26 deletions(-) diff --git a/db_test.go b/db_test.go index f0e78d055..dd735e465 100644 --- a/db_test.go +++ b/db_test.go @@ -2841,14 +2841,20 @@ func TestOpenWithEmptyMemFile(t *testing.T) { func TestOpenWithEmptyVlogFile(t *testing.T) { dir := t.TempDir() opt := getTestOptions(dir) + // The default ValueThreshold is 1MB, which would inline every value in the + // LSM tree and leave the value log read path untested. Drop it so the + // values below actually land in a .vlog file. + opt.ValueThreshold = 32 + value := func(i int) []byte { + return []byte(fmt.Sprintf("value:%05d:%s", i, strings.Repeat("v", 64))) + } // Step 1: Create a DB with some data. db, err := Open(opt) require.NoError(t, err) for i := 0; i < 100; i++ { err := db.Update(func(txn *Txn) error { - return txn.Set([]byte(fmt.Sprintf("key:%05d", i)), - []byte(fmt.Sprintf("value:%05d", i))) + return txn.Set([]byte(fmt.Sprintf("key:%05d", i)), value(i)) }) require.NoError(t, err) } @@ -2902,8 +2908,7 @@ func TestOpenWithEmptyVlogFile(t *testing.T) { return err } err = item.Value(func(val []byte) error { - expected := fmt.Sprintf("value:%05d", i) - require.Equal(t, expected, string(val)) + require.Equal(t, value(i), val) return nil }) if err != nil { @@ -2925,10 +2930,103 @@ func TestOpenWithEmptyVlogFile(t *testing.T) { require.NoError(t, db2.Close()) }) - // Step 6: Read-only Open must also succeed with the empty .vlog file present. + // Step 6: Read-only Open must also succeed with the empty .vlog file + // present, and must serve reads out of the value log. Read-only never + // calls createVlogFile, so vlog.maxFid still names the skipped artifact + // here; the read path has to cope with that. roOpt := opt roOpt.ReadOnly = true db3, err := Open(roOpt) require.NoError(t, err, "read-only Open should succeed with an empty .vlog file") + require.NoError(t, db3.View(func(txn *Txn) error { + for i := 0; i < 100; i++ { + item, err := txn.Get([]byte(fmt.Sprintf("key:%05d", i))) + if err != nil { + return err + } + got, err := item.ValueCopy(nil) + if err != nil { + return err + } + require.Equal(t, value(i), got) + } + return nil + })) require.NoError(t, db3.Close()) } + +// TestEmptyVlogFileDoesNotSkipTailRecovery verifies that a 0-byte .vlog crash +// artifact does not rob the newest surviving value log file of its tail +// recovery. populateFilesMap sets vlog.maxFid from the directory listing before +// the 0-byte file is skipped, so maxFid names a file that is no longer in +// filesMap. Indexing filesMap by maxFid there would skip the iterate-and- +// truncate pass that trims a partially written entry off the last file — and +// the crash that leaves a 0-byte .vlog behind is exactly the crash that can +// leave a torn tail on the file before it. +func TestEmptyVlogFileDoesNotSkipTailRecovery(t *testing.T) { + newestVlog := func(dir string) (string, uint32) { + entries, err := os.ReadDir(dir) + require.NoError(t, err) + var maxFid uint32 + for _, e := range entries { + name := e.Name() + if !strings.HasSuffix(name, ".vlog") { + continue + } + fid, err := strconv.ParseUint(strings.TrimSuffix(name, ".vlog"), 10, 32) + require.NoError(t, err) + if uint32(fid) > maxFid { + maxFid = uint32(fid) + } + } + return filepath.Join(dir, fmt.Sprintf("%06d.vlog", maxFid)), maxFid + } + + // plantEmpty controls whether a 0-byte .vlog artifact sits above the torn + // file. Recovery must behave identically either way. + run := func(t *testing.T, plantEmpty bool) { + dir := t.TempDir() + opt := getTestOptions(dir) + opt.ValueThreshold = 32 + + db, err := Open(opt) + require.NoError(t, err) + val := []byte(strings.Repeat("v", 1024)) + for i := 0; i < 50; i++ { + require.NoError(t, db.Update(func(txn *Txn) error { + return txn.Set([]byte(fmt.Sprintf("key:%05d", i)), val) + })) + } + require.NoError(t, db.Close()) + + lastPath, lastFid := newestVlog(dir) + clean, err := os.Stat(lastPath) + require.NoError(t, err) + + // Simulate a write torn off by a crash. + f, err := os.OpenFile(lastPath, os.O_WRONLY|os.O_APPEND, 0600) + require.NoError(t, err) + _, err = f.Write([]byte("torn entry that is not a valid record")) + require.NoError(t, err) + require.NoError(t, f.Close()) + + if plantEmpty { + empty := filepath.Join(dir, fmt.Sprintf("%06d.vlog", lastFid+1)) + ef, err := os.Create(empty) + require.NoError(t, err) + require.NoError(t, ef.Close()) + } + + db2, err := Open(opt) + require.NoError(t, err) + recovered, err := os.Stat(lastPath) + require.NoError(t, err) + require.NoError(t, db2.Close()) + + require.Equal(t, clean.Size(), recovered.Size(), + "torn tail should have been truncated off %s", filepath.Base(lastPath)) + } + + t.Run("no artifact", func(t *testing.T) { run(t, false) }) + t.Run("with empty vlog artifact", func(t *testing.T) { run(t, true) }) +} diff --git a/memtable.go b/memtable.go index 64782d9b8..0273b2958 100644 --- a/memtable.go +++ b/memtable.go @@ -68,15 +68,21 @@ func (db *DB) openMemTables(opt Options) error { return fids[i] < fids[j] }) for _, fid := range fids { - // Skip empty .mem files that can be left behind by a crash - // between file creation and the first write. Stat-and-skip - // avoids opening them at all, which works for both read-write - // and read-only modes (no truncation required). - fi, err := os.Stat(db.mtFilePath(fid)) + // A crash between file creation and the first write can leave a 0-byte + // .mem behind. Stat and skip those before opening anything: + // z.OpenMmapFile would truncate such a file and hand back the + // z.NewFile sentinel, which the open below treats as fatal, and which + // read-only mode cannot produce at all because the truncate fails on + // an O_RDONLY fd. The file itself stays on disk, so read-only opens + // mutate nothing. The fid stays in fids as well, so nextMemFid below + // still advances past it and no new memtable reuses it. + path := db.mtFilePath(fid) + fi, err := os.Stat(path) if err != nil { - return errFile(err, db.mtFilePath(fid), "Unable to stat mem file.") + return errFile(err, path, "Unable to stat mem file.") } if fi.Size() == 0 { + db.opt.Infof("Skipping empty memtable file: %s", path) continue } diff --git a/value.go b/value.go index c171eaa33..5cd40448e 100644 --- a/value.go +++ b/value.go @@ -598,28 +598,43 @@ func (vlog *valueLog) open(db *DB) error { _, err := vlog.createVlogFile() return y.Wrapf(err, "Error while creating log file in valueLog.open") } + // A crash between file creation and the first write can leave a 0-byte .vlog behind. Stat + // and skip those before opening anything: z.OpenMmapFile would truncate such a file and hand + // back the z.NewFile sentinel, which the open below treats as fatal, and which read-only mode + // cannot produce at all because the truncate fails on an O_RDONLY fd. Skipping also drops the + // fid from filesMap, since nothing opened the file and its nil MmapFile would be dereferenced + // by anything that walks the map, vlog.Close() included. The file itself stays on disk, so + // read-only opens mutate nothing. fids := vlog.sortedFids() + live := make([]uint32, 0, len(fids)) for _, fid := range fids { lf, ok := vlog.filesMap[fid] y.AssertTrue(ok) - lf.opt = vlog.opt - - // Skip 0-byte .vlog files left behind by a crash between file - // creation and the first write. Stat-and-skip avoids opening them at - // all, which works in both read-write and read-only modes (no - // truncation required). The file stays on disk but is harmless. fi, err := os.Stat(lf.path) if err != nil { - return y.Wrapf(err, "Unable to stat file: %q", lf.path) + return errFile(err, lf.path, "Unable to stat value log file.") } if fi.Size() == 0 { - // Since the logfile, corresponding to this fid, does not - // have MmapFile initialized, susceptible to nil deref panic. - // Like that in vlog.Close() + vlog.opt.Infof("Skipping empty value log file: %s", lf.path) delete(vlog.filesMap, fid) continue } + live = append(live, fid) + } + + // vlog.maxFid can name a file that the skip above just dropped from filesMap, so track the + // newest file that actually survived and use that wherever the newest file matters. Leave + // maxFid itself alone: createVlogFile takes maxFid+1 with O_EXCL, so lowering it would + // collide with the skipped artifact still sitting on disk. + var newestFid uint32 + if len(live) > 0 { + newestFid = live[len(live)-1] + } + + for _, fid := range live { + lf := vlog.filesMap[fid] + lf.opt = vlog.opt flags := os.O_RDWR if vlog.opt.ReadOnly { @@ -629,8 +644,8 @@ func (vlog *valueLog) open(db *DB) error { 2*vlog.opt.ValueLogFileSize); err != nil { return y.Wrapf(err, "Open existing file: %q", lf.path) } - // We shouldn't delete the maxFid file. - if lf.size.Load() == vlogHeaderSize && fid != vlog.maxFid && !vlog.opt.ReadOnly { + // We shouldn't delete the newest file. + if lf.size.Load() == vlogHeaderSize && fid != newestFid && !vlog.opt.ReadOnly { vlog.opt.Infof("Deleting empty file: %s", lf.path) if err := lf.Delete(); err != nil { return y.Wrapf(err, "while trying to delete empty file: %s", lf.path) @@ -640,13 +655,15 @@ func (vlog *valueLog) open(db *DB) error { } if vlog.opt.ReadOnly { + // vlog.maxFid may still name a skipped artifact for the life of this handle, since the + // createVlogFile below never runs. That is safe: getFileRLocked keys on vp.Fid and skips + // its maxFid bound check in read-only mode. return nil } // Now we can read the latest value log file, and see if it needs truncation. We could // technically do this over all the value log files, but that would mean slowing down the value - // log open. If the maxFid file was a 0-byte crash artifact skipped above, it's no longer in - // filesMap and there's nothing to recover, so skip straight to creating a fresh file. - if last, ok := vlog.filesMap[vlog.maxFid]; ok { + // log open. + if last, ok := vlog.filesMap[newestFid]; ok { lastOff, err := last.iterate(vlog.opt.ReadOnly, vlogHeaderSize, func(_ Entry, vp valuePointer) error { return nil