Unreadable memory files are named and kept, and a killed write is not taken for a hand edit

cmd/logos/index.go

@@ -193,6 +193,10 @@ func indexPass(ix *index.Index, w io.Writer, p *provider.Provider, embed string)
 	// nothing" cannot depend on a model being reachable.
 	mems, rescuedMems, edits, err := ix.SyncMemoryEdits(p, embed)
 	if err != nil {
+		// What the scan found before it refused is still true, and an
+		// unreadable file left out of this run would otherwise go unnamed
+		// behind the refusal.
+		printConflictCopies(w, "", nil, edits)
 		return err
 	}
 	printMemoryEdits(w, edits)
@@ -395,6 +399,13 @@ func printConflictCopies(w io.Writer, prefix string, walked []string, e memory.E
 		fmt.Fprintf(w, "%sset aside %d sync conflict %s of a memory that is no longer current — delete %s, or rename one to its original name to bring the memory back: %s\n",
 			prefix, n, plural2(n, "copy", "copies"), plural2(n, "it", "them"), terminalSafe(strings.Join(e.Orphaned, ", "), 2000))
 	}
+	// Said here, with the other files an index left out, because it is the
+	// same promise: a file on disk that is not in memory is named, or the
+	// counts read as a vault that simply has fewer memories.
+	if n := len(e.Unreadable); n > 0 {
+		fmt.Fprintf(w, "%scould not read %d memory %s; a memory the index already has is kept, but none is read from %s until %s readable: %s\n",
+			prefix, n, plural2(n, "file", "files"), plural2(n, "it", "them"), plural2(n, "it is", "they are"), terminalSafe(strings.Join(e.Unreadable, ", "), 2000))
+	}
 }
 
 func plural2(n int, one, many string) string {

cmd/logos/index_unreadable_memory_test.go

@@ -0,0 +1,136 @@
+package main
+
+import (
+	"os"
+	"path/filepath"
+	"runtime"
+	"strings"
+	"testing"
+)
+
+// A memory file the index cannot read was skipped with a bare continue: after
+// a rebuild `logos index` counted one memory fewer, the digest was rewritten
+// without it, and nothing named the file still sitting on disk.
+func TestAnUnreadableMemoryFileIsNamedByTheIndexThatLeftItOut(t *testing.T) {
+	if runtime.GOOS == "windows" || os.Geteuid() == 0 {
+		t.Skip("needs a file permission that stops its owner reading it")
+	}
+	vaultDir := t.TempDir()
+	t.Setenv("LOGOS_VAULT", vaultDir)
+	t.Setenv("LOGOS_EMBED", "off")
+	for _, text := range []string{"Decided to use Stripe for payments", "Deploys go out on Tuesdays"} {
+		if err := memoryCmd([]string{"add", "--project", "shop", text}); err != nil {
+			t.Fatalf("memory add: %v", err)
+		}
+	}
+	matches, err := filepath.Glob(filepath.Join(vaultDir, "memories", "fact", "*.md"))
+	if err != nil || len(matches) != 2 {
+		t.Fatalf("got %v per-memory fact files (%v), want 2", matches, err)
+	}
+	locked := matches[0]
+	if err := os.Chmod(locked, 0); err != nil {
+		t.Fatal(err)
+	}
+	t.Cleanup(func() { os.Chmod(locked, 0o644) })
+	if err := os.RemoveAll(filepath.Join(vaultDir, ".logos")); err != nil {
+		t.Fatal(err)
+	}
+
+	out := captureStdout(t, func() {
+		if err := runIndex(false); err != nil {
+			t.Fatal(err)
+		}
+	})
+	want := "could not read 1 memory file; a memory the index already has is kept, but none is read from it until it is readable: memories/fact/" + filepath.Base(locked) + ": permission denied"
+	if !strings.Contains(out, want) {
+		t.Errorf("index did not name the file it could not read; want %q in:\n%s", want, out)
+	}
+}
+
+// Over an index that already had the memory, an unreadable file read as a line
+// the user deleted: the index forgot the memory and removed the file it could
+// not read, so fixing the permission afterwards brought nothing back.
+func TestAnUnreadableMemoryFileIsNotForgottenByTheNextIndex(t *testing.T) {
+	if runtime.GOOS == "windows" || os.Geteuid() == 0 {
+		t.Skip("needs a file permission that stops its owner reading it")
+	}
+	vaultDir := t.TempDir()
+	t.Setenv("LOGOS_VAULT", vaultDir)
+	t.Setenv("LOGOS_EMBED", "off")
+	for _, text := range []string{"Decided to use Stripe for payments", "Deploys go out on Tuesdays"} {
+		if err := memoryCmd([]string{"add", "--project", "shop", text}); err != nil {
+			t.Fatalf("memory add: %v", err)
+		}
+	}
+	matches, err := filepath.Glob(filepath.Join(vaultDir, "memories", "fact", "*.md"))
+	if err != nil || len(matches) != 2 {
+		t.Fatalf("got %v per-memory fact files (%v), want 2", matches, err)
+	}
+	locked := matches[0]
+	if err := os.Chmod(locked, 0); err != nil {
+		t.Fatal(err)
+	}
+	t.Cleanup(func() { os.Chmod(locked, 0o644) })
+
+	out := captureStdout(t, func() {
+		if err := runIndex(false); err != nil {
+			t.Fatal(err)
+		}
+	})
+	if strings.Contains(out, "forgot") {
+		t.Errorf("index forgot the memory whose file it could not read:\n%s", out)
+	}
+	if _, err := os.Lstat(locked); err != nil {
+		t.Fatalf("index removed the memory file it could not read: %v", err)
+	}
+	if err := os.Chmod(locked, 0o644); err != nil {
+		t.Fatal(err)
+	}
+	listed := captureStdout(t, func() {
+		if err := memoryCmd(nil); err != nil {
+			t.Fatal(err)
+		}
+	})
+	for _, text := range []string{"Stripe", "Tuesdays"} {
+		if !strings.Contains(listed, text) {
+			t.Errorf("%q is not listed after the file was readable again:\n%s", text, listed)
+		}
+	}
+}
+
+// A damaged digest elsewhere makes the index refuse, and the refusal returned
+// before the notice: the unreadable file the same scan found went unnamed, so
+// the one run that had found it said nothing about it.
+func TestAnUnreadableMemoryFileIsNamedWhenTheIndexRefuses(t *testing.T) {
+	if runtime.GOOS == "windows" || os.Geteuid() == 0 {
+		t.Skip("needs a file permission that stops its owner reading it")
+	}
+	vaultDir := t.TempDir()
+	t.Setenv("LOGOS_VAULT", vaultDir)
+	t.Setenv("LOGOS_EMBED", "off")
+	if err := memoryCmd([]string{"add", "--project", "shop", "Deploys go out on Tuesdays"}); err != nil {
+		t.Fatalf("memory add: %v", err)
+	}
+	matches, err := filepath.Glob(filepath.Join(vaultDir, "memories", "fact", "*.md"))
+	if err != nil || len(matches) != 1 {
+		t.Fatalf("got %v per-memory fact files (%v), want 1", matches, err)
+	}
+	locked := matches[0]
+	if err := os.Chmod(locked, 0); err != nil {
+		t.Fatal(err)
+	}
+	t.Cleanup(func() { os.Chmod(locked, 0o644) })
+	torn := filepath.Join(vaultDir, "memories", "context.md")
+	if err := os.WriteFile(torn, []byte("- Shipping in November <!-- uid=0123"), 0o600); err != nil {
+		t.Fatal(err)
+	}
+
+	var ierr error
+	out := captureStdout(t, func() { ierr = runIndex(false) })
+	if ierr == nil {
+		t.Fatal("index accepted a torn context.md")
+	}
+	if want := "memories/fact/" + filepath.Base(locked) + ": permission denied"; !strings.Contains(out, want) {
+		t.Errorf("the refusing index did not name the file it could not read; want %q in:\n%s", want, out)
+	}
+}

internal/memory/killed_write_test.go

@@ -0,0 +1,75 @@
+package memory
+
+import (
+	"crypto/sha256"
+	"strings"
+	"testing"
+)
+
+// A process killed after a memory file or digest reached the disk, and before
+// its hash was recorded, left a file the stamp did not claim. The next store
+// took logos's own write for a hand edit and refused, and so did every one
+// after it. Seen once in the chaos tier's killed memory add (#371).
+func TestAWriteKilledBeforeItsStampIsNotTakenForAHandEdit(t *testing.T) {
+	for name, file := range map[string]string{"digest": "/fact.md", "own file": ".md"} {
+		t.Run(name, func(t *testing.T) {
+			db, _ := vaultDB(t)
+			// The same text each time: after the first, each store is a
+			// reinforcement that rewrites the memory's own file and the
+			// digest, both already stamped, each through its hand-edit guard.
+			store := func() error {
+				_, err := Store(db, nil, "", &Memory{Text: "Deploys go out on Tuesdays", Kind: Fact, Source: "manual"})
+				return err
+			}
+			if err := store(); err != nil {
+				t.Fatal(err)
+			}
+			// The own file is written first and ends in ".md"; "/fact.md"
+			// matches only the digest.
+			t.Cleanup(func() { vaultWritten = func(string) {} })
+			vaultWritten = func(path string) {
+				if strings.HasSuffix(path, file) {
+					panic("killed")
+				}
+			}
+			func() {
+				defer func() { recover() }()
+				store()
+			}()
+			vaultWritten = func(string) {}
+
+			if err := store(); err != nil {
+				t.Fatalf("the store after a killed write was refused: %v", err)
+			}
+		})
+	}
+}
+
+// A write that keeps failing — a read-only or full vault — calls stampPending
+// once per attempt. Appended beside whatever was there, the column grew a hash
+// per attempt, and every one of them stayed a claim the file was logos's own.
+func TestARepeatedlyFailingWriteHoldsOnlyOnePendingHash(t *testing.T) {
+	db, _ := vaultDB(t)
+	r, err := Store(db, nil, "", &Memory{Text: "Deploys go out on Tuesdays", Kind: Fact, Source: "manual"})
+	if err != nil {
+		t.Fatal(err)
+	}
+	var uid string
+	if err := db.QueryRow(`SELECT uid FROM memories WHERE id = ?`, r.ID).Scan(&uid); err != nil {
+		t.Fatal(err)
+	}
+	for i := 0; i < 3; i++ {
+		next := sha256.Sum256([]byte{byte(i)})
+		stampPending(db, Fact, next)
+		fileStampPending(db, uid, next)
+	}
+	for table, where := range map[string]string{"digest_stamps": "kind = 'fact'", "memory_file_stamps": "uid = '" + uid + "'"} {
+		var sha string
+		if err := db.QueryRow(`SELECT sha FROM ` + table + ` WHERE ` + where).Scan(&sha); err != nil {
+			t.Fatal(err)
+		}
+		if n := strings.Count(sha, ",") + 1; n != 2 {
+			t.Errorf("%s holds %d hashes after three failed writes, want the confirmed one and the last pending one", table, n)
+		}
+	}
+}

internal/memory/memory.go

@@ -997,14 +997,19 @@ func carryRecallTimes(db *sql.DB, kind Kind, ms []Memory, now int64) error {
 			errs = append(errs, fmt.Errorf("memories/%s/%s.md has no uses= to update", kind, m.Uid))
 			continue
 		}
-		last, stamped := fileStampSeen(db, m.Uid)
-		ours := stamped && sha256.Sum256(raw) == last
-		if err := vault.WriteAtomic(path, []byte(patched)); err != nil {
+		last, seen := fileStampSeen(db, m.Uid)
+		ours := seen && stamped(last, sha256.Sum256(raw))
+		out := []byte(patched)
+		sum := sha256.Sum256(out)
+		if ours {
+			fileStampPending(db, m.Uid, sum)
+		}
+		if err := vault.WriteAtomic(path, out); err != nil {
 			errs = append(errs, fmt.Errorf("memory #%d: %w", m.ID, err))
 			continue
 		}
 		if ours {
-			fileStamp(db, m.Uid, sha256.Sum256([]byte(patched)))
+			fileStamp(db, m.Uid, sum)
 		}
 	}
 	return errors.Join(errs...)

internal/memory/unreadable_file_test.go

@@ -0,0 +1,79 @@
+package memory
+
+import (
+	"bytes"
+	"database/sql"
+	"os"
+	"runtime"
+	"testing"
+)
+
+// storeUnreadable stores one fact and makes its own file unreadable, the
+// state a chmod, a sync client mid-download or a disk error leaves behind.
+func storeUnreadable(t *testing.T) (db *sql.DB, dir, path string, id int64) {
+	t.Helper()
+	if runtime.GOOS == "windows" || os.Getuid() == 0 {
+		t.Skip("needs a file its owner cannot read")
+	}
+	db, dir = vaultDB(t)
+	r, err := Store(db, nil, "", &Memory{Text: "Deploys go out on Tuesdays", Kind: Fact, Source: "manual"})
+	if err != nil {
+		t.Fatal(err)
+	}
+	var uid string
+	if err := db.QueryRow(`SELECT uid FROM memories WHERE id = ?`, r.ID).Scan(&uid); err != nil {
+		t.Fatal(err)
+	}
+	path = memoryFilePath(dir, Fact, uid)
+	if err := os.Chmod(path, 0); err != nil {
+		t.Fatal(err)
+	}
+	t.Cleanup(func() { os.Chmod(path, 0o600) })
+	return db, dir, path, r.ID
+}
+
+// An unreadable file confirms nothing about its memory. Counted as found, it
+// cleared the unflushed flag of a memory no read had seen in the vault, and
+// doctor stopped reporting a row that one more wipe would lose.
+func TestAnUnreadableMemoryFileKeepsItsUnflushedFlag(t *testing.T) {
+	db, dir, _, id := storeUnreadable(t)
+	if _, err := db.Exec(`UPDATE memories SET unflushed = 1 WHERE id = ?`, id); err != nil {
+		t.Fatal(err)
+	}
+	if _, _, _, err := ImportEdits(db, nil, "", dir); err != nil {
+		t.Fatal(err)
+	}
+	var unflushed int
+	if err := db.QueryRow(`SELECT unflushed FROM memories WHERE id = ?`, id).Scan(&unflushed); err != nil {
+		t.Fatalf("the memory behind an unreadable file is gone: %v", err)
+	}
+	if unflushed != 1 {
+		t.Error("an index cleared the unflushed flag of a memory whose file it could not read")
+	}
+}
+
+// The hand-edit guard compares the file with its stamp. A file it could not
+// read was taken as nothing to compare, and the rewrite replaced whatever a
+// person had put there.
+func TestAMemoryFileThatCannotBeReadIsNotOverwritten(t *testing.T) {
+	db, _, path, _ := storeUnreadable(t)
+	os.Chmod(path, 0o600)
+	before, err := os.ReadFile(path)
+	if err != nil {
+		t.Fatal(err)
+	}
+	os.Chmod(path, 0)
+
+	// The same text again reinforces the memory, which rewrites its file.
+	if _, err := Store(db, nil, "", &Memory{Text: "Deploys go out on Tuesdays", Kind: Fact, Source: "manual"}); err == nil {
+		t.Error("a store rewrote a memory file it could not read, with no error")
+	}
+	os.Chmod(path, 0o600)
+	after, err := os.ReadFile(path)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if !bytes.Equal(before, after) {
+		t.Error("the unreadable memory file was replaced")
+	}
+}