From 3f8679be9373ee7508d512dfdfc1dda0839c7f90 Mon Sep 17 00:00:00 2001 From: Lukasz Kasprzak Date: Sat, 12 Sep 2026 20:14:47 +0200 Subject: krino: acting — trash, journal, apply, lock, review, undo MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- internal/journal/journal.go | 162 +++++++++++++++ internal/journal/journal_test.go | 150 ++++++++++++++ internal/journal/read.go | 344 ++++++++++++++++++++++++++++++++ internal/journal/read_test.go | 413 +++++++++++++++++++++++++++++++++++++++ 4 files changed, 1069 insertions(+) create mode 100644 internal/journal/journal.go create mode 100644 internal/journal/journal_test.go create mode 100644 internal/journal/read.go create mode 100644 internal/journal/read_test.go (limited to 'internal/journal') diff --git a/internal/journal/journal.go b/internal/journal/journal.go new file mode 100644 index 0000000..465cd51 --- /dev/null +++ b/internal/journal/journal.go @@ -0,0 +1,162 @@ +// SPDX-License-Identifier: GPL-3.0-or-later + +// Package journal is the append-only log every krino action is recorded in, +// and the only record krino undo reads back. See docs/design.md §9. +package journal + +import ( + "crypto/rand" + "encoding/hex" + "fmt" + "os" + "path/filepath" + "strconv" + "strings" + "time" + "unicode/utf8" +) + +// Entry is one logged event. Field order here IS the column order in the +// file; never reorder it. +type Entry struct { + Time time.Time // RFC 3339 with offset + Run string // e.g. "20260911T100203-4f2a" + Dir string // the directory's name from krino.conf + File string // the file's Rel within that directory + Step int // 1-based index within the file's chain; 0 for run-start/run-end + Action string // run-start mkdir copy move rename trash delete displace run-end, and undo- forms + Status string // ok failed skipped declined + Rule string + Src string + Dst string + Size int64 // of the file at Dst after the step + ModTime time.Time // of the file at Dst after the step + Detail string +} + +// NewRunID returns "-<4 hex>": a run identifier that +// sorts lexically by start time and does not collide across runs started in +// the same second. +func NewRunID(t time.Time) string { + var b [2]byte + _, _ = rand.Read(b[:]) // crypto/rand.Read never fails on supported platforms + return t.Format("20060102T150405") + "-" + hex.EncodeToString(b[:]) +} + +// Writer appends entries to a log file, one line per Append call. +type Writer struct { + f *os.File +} + +// Open opens the log at path for appending, creating its parent directories +// and the file itself if necessary. It never truncates an existing log. +func Open(path string) (*Writer, error) { + if err := os.MkdirAll(filepath.Dir(path), 0o755); err != nil { + return nil, fmt.Errorf("journal: %w", err) + } + f, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644) + if err != nil { + return nil, fmt.Errorf("journal: %w", err) + } + return &Writer{f: f}, nil +} + +// Append writes e as one line and flushes it before returning. The whole +// line is written with a single Write call so that two concurrent runs +// appending to the same file cannot interleave a partial line. +// +// Time and ModTime are formatted with RFC3339Nano, not RFC3339: spec §9 +// asks for "RFC 3339 with offset", which RFC3339Nano still is (it only adds +// an optional fractional-second field; a zero-nanosecond time formats +// identically under both). Task 5's undo needs the fractional seconds: a +// refusal check comparing a file's current mtime against the mtime this +// line records must not be fooled by a file rewritten within the same +// whole second. read.go's parser already accepts fractional seconds under +// either constant (a documented time.Parse special case for RFC3339), so +// only this side needed to change. +func (w *Writer) Append(e Entry) error { + line := strings.Join([]string{ + e.Time.Format(time.RFC3339Nano), + escape(e.Run), + escape(e.Dir), + escape(e.File), + strconv.Itoa(e.Step), + escape(e.Action), + escape(e.Status), + escape(e.Rule), + escape(e.Src), + escape(e.Dst), + strconv.FormatInt(e.Size, 10), + e.ModTime.Format(time.RFC3339Nano), + escape(e.Detail), + }, "\t") + "\n" + if _, err := w.f.Write([]byte(line)); err != nil { + return fmt.Errorf("journal: %w", err) + } + return nil +} + +// Close closes the underlying file. +func (w *Writer) Close() error { + if err := w.f.Close(); err != nil { + return fmt.Errorf("journal: %w", err) + } + return nil +} + +// escape encodes s so it can never contain a tab or a newline, and so every +// byte round-trips exactly: \t, \n, \\ are backslash-escaped, and every +// other control byte or byte that is not part of valid UTF-8 becomes \xNN. +// A byte loop is used rather than strconv.Quote, which would also escape +// non-ASCII text and make names like "zażółć" unreadable in the log. +func escape(s string) string { + if !needsEscape(s) { + return s + } + var b strings.Builder + b.Grow(len(s) + 8) + i := 0 + for i < len(s) { + c := s[i] + switch c { + case '\t': + b.WriteString(`\t`) + i++ + continue + case '\n': + b.WriteString(`\n`) + i++ + continue + case '\\': + b.WriteString(`\\`) + i++ + continue + } + if c < 0x20 || c == 0x7f { + fmt.Fprintf(&b, `\x%02x`, c) + i++ + continue + } + r, size := utf8.DecodeRuneInString(s[i:]) + if r == utf8.RuneError && size <= 1 { + fmt.Fprintf(&b, `\x%02x`, c) + i++ + continue + } + b.WriteString(s[i : i+size]) + i += size + } + return b.String() +} + +// needsEscape reports whether s contains anything escape would change, so +// the common case (a plain name) avoids allocating a builder. +func needsEscape(s string) bool { + for i := 0; i < len(s); i++ { + c := s[i] + if c == '\t' || c == '\n' || c == '\\' || c < 0x20 || c == 0x7f || c >= 0x80 { + return true + } + } + return false +} diff --git a/internal/journal/journal_test.go b/internal/journal/journal_test.go new file mode 100644 index 0000000..a95bb05 --- /dev/null +++ b/internal/journal/journal_test.go @@ -0,0 +1,150 @@ +// SPDX-License-Identifier: GPL-3.0-or-later + +package journal + +import ( + "os" + "path/filepath" + "strings" + "testing" + "time" +) + +func TestNewRunID(t *testing.T) { + at := time.Date(2026, 9, 11, 10, 2, 3, 0, time.UTC) + id := NewRunID(at) + if !strings.HasPrefix(id, "20260911T100203-") || len(id) != len("20260911T100203-")+4 { + t.Fatalf("run id = %q", id) + } + if NewRunID(at) == id { + t.Error("two run ids for the same instant collided; the suffix is not random") + } +} + +// TestRoundTripsAwkwardNames is the point of the escaping: a file name with a +// tab, a newline, a backslash, a control byte or invalid UTF-8 must come back +// byte-for-byte, and must not break the line or column structure awk sees. +func TestRoundTripsAwkwardNames(t *testing.T) { + names := []string{ + "plain.pdf", + "with\ttab.pdf", + "with\nnewline.pdf", + "back\\slash.pdf", + "bell\a.pdf", + "invalid\xff\xfeutf8.pdf", + "zażółć gęślą jaźń.pdf", + } + path := filepath.Join(t.TempDir(), "state", "krino.log") + w, err := Open(path) + if err != nil { + t.Fatal(err) + } + at := time.Date(2026, 9, 11, 10, 2, 3, 0, time.FixedZone("CEST", 2*3600)) + if err := w.Append(Entry{Time: at, Run: "R", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + for i, n := range names { + e := Entry{Time: at, Run: "R", Dir: "dl", File: n, Step: i + 1, + Action: "move", Status: "ok", Rule: "acme", Src: "/a/" + n, Dst: "/b/" + n, + Size: int64(i), ModTime: at, Detail: ""} + if err := w.Append(e); err != nil { + t.Fatal(err) + } + } + if err := w.Close(); err != nil { + t.Fatal(err) + } + + raw, err := os.ReadFile(path) + if err != nil { + t.Fatal(err) + } + if got := strings.Count(string(raw), "\n"); got != len(names)+1 { + t.Errorf("file has %d lines, want %d: a field broke the line structure", got, len(names)+1) + } + for _, line := range strings.Split(strings.TrimRight(string(raw), "\n"), "\n") { + if n := strings.Count(line, "\t"); n != 12 { + t.Errorf("line has %d tabs, want 12 (13 columns): %q", n, line) + } + } + + got, err := Entries(path, "R") + if err != nil { + t.Fatal(err) + } + if len(got) != len(names)+1 { + t.Fatalf("read %d entries, want %d", len(got), len(names)+1) + } + for i, n := range names { + if got[i+1].File != n { + t.Errorf("entry %d: File = %q, want %q", i, got[i+1].File, n) + } + if got[i+1].Src != "/a/"+n || got[i+1].Dst != "/b/"+n { + t.Errorf("entry %d: paths did not round-trip: %q %q", i, got[i+1].Src, got[i+1].Dst) + } + if !got[i+1].Time.Equal(at) { + t.Errorf("entry %d: Time = %v, want %v", i, got[i+1].Time, at) + } + } +} + +// TestAppendWritesRFC3339WithOffsetAndKeepsNanoseconds is item 13, promoted +// to before-commit by the plan 4 final review: nothing anywhere pinned the +// journal's on-disk time format - RFC3339Nano appears in no test file, and +// every timestamp assertion round-trips through krino's own Writer and +// Entries, so a change to something no other tool could parse would pass +// silently. The journal is the only record undo has. This reads the RAW +// bytes of a written line - not Entries, which would launder the format +// through krino's own parser - and asserts column 1 parses as RFC 3339 with +// a real numeric offset (not just "Z"), and that a time carrying +// nanoseconds keeps them. +func TestAppendWritesRFC3339WithOffsetAndKeepsNanoseconds(t *testing.T) { + path := filepath.Join(t.TempDir(), "state", "krino.log") + w, err := Open(path) + if err != nil { + t.Fatal(err) + } + at := time.Date(2026, 9, 11, 10, 2, 3, 123456789, time.FixedZone("", 2*3600)) + if err := w.Append(Entry{Time: at, Run: "R", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Close(); err != nil { + t.Fatal(err) + } + + raw, err := os.ReadFile(path) + if err != nil { + t.Fatal(err) + } + line := strings.TrimSuffix(string(raw), "\n") + col1 := strings.SplitN(line, "\t", 2)[0] + + parsed, err := time.Parse(time.RFC3339, col1) + if err != nil { + t.Fatalf("column 1 %q does not parse as RFC 3339: %v", col1, err) + } + if _, offset := parsed.Zone(); offset != 2*3600 { + t.Errorf("offset = %ds, want %ds: the written column must carry a real offset, not just a bare local time", offset, 2*3600) + } + if parsed.Nanosecond() != 123456789 { + t.Errorf("nanoseconds = %d, want 123456789: a nanosecond-precision time must not be truncated on the wire", parsed.Nanosecond()) + } +} + +func TestAppendIsAppendOnly(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + for i := 0; i < 2; i++ { + w, err := Open(path) + if err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: time.Now(), Run: "R", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + w.Close() + } + raw, _ := os.ReadFile(path) + if got := strings.Count(string(raw), "\n"); got != 2 { + t.Errorf("%d lines after two Open/Append/Close cycles, want 2: the second Open truncated", got) + } +} diff --git a/internal/journal/read.go b/internal/journal/read.go new file mode 100644 index 0000000..3de15d2 --- /dev/null +++ b/internal/journal/read.go @@ -0,0 +1,344 @@ +// SPDX-License-Identifier: GPL-3.0-or-later + +package journal + +import ( + "fmt" + "os" + "sort" + "strconv" + "strings" + "time" +) + +// wantFields is the number of tab-separated columns a well-formed line has. +const wantFields = 13 + +// undoOfPrefix is the exact, single-source convention linking an undo run +// back to the run it reverses: an undo run's run-start entry carries +// Detail = undoOfPrefix + the original run's ID, verbatim, and nowhere +// else - never repeated on the undo-* step entries, so there is only one +// place to write it and one place that can drift. A log truncated before +// its run-start line loses the link; the accepted cost is that `krino undo` +// may then re-offer an already-reversed run, whose per-file refusal checks +// decline every file because they are already back in place. +const undoOfPrefix = "undo of " + +// UndoOf returns the Detail value an undo run's run-start entry carries to +// record which run it reverses (see undoOfPrefix). Fix wave item 2 / +// final-wave item 17: before this, internal/engine wrote the same text as +// a bare string literal with nothing tying it to undoOfPrefix, so a typo in +// either would silently break Runs' Undone marking while every test stayed +// green. This is the one place that string is built; internal/engine calls +// it rather than keeping its own copy. +func UndoOf(run string) string { + return undoOfPrefix + run +} + +// Run summarises one logged run, for `krino log` and for choosing what +// `krino undo` reverses. +type Run struct { + ID string + Start time.Time + Dirs []string + Counts map[string]int // action -> count of status "ok" + Undone bool // a later run reversed this one +} + +// Entries returns every entry belonging to runID, in file order. A line +// that fails to parse is skipped, but Entries fails closed within the run's +// own window - from its run-start line to its run-end line, or to end of +// file when there is no run-end (a crashed run, which is precisely when +// corruption is likely): any unparsable line found inside that window sets +// the returned error, whether or not the line's own Run column can still be +// read back. The mere possibility that it belonged to this run is enough, +// because an incomplete chain must refuse the whole run rather than let an +// undo reverse it partway (spec §10). A line outside the window is ignored +// even when unparsable, since it cannot belong to this run. +// +// The residual risk this leaves is a false refusal, not a false success: +// krino's lock is per directory, not global, so two processes could in +// principle write to the log at once, and an unattributable corrupt line +// that falls inside this run's window might really belong to the other +// run - this run would then be refused unnecessarily. That is the safe +// direction, and it is rare. A nil error is what proves the run's chain +// parsed completely; a non-nil error is proof only that it cannot be +// trusted as complete, not that the run itself is corrupt. +// +// A run also fails closed if it has no readable run-start: every run Apply +// writes begins with one, so once at least one entry for the run has +// parsed, a missing run-start means either corruption or a log truncated +// at the front, and either way the chain cannot be trusted. The same rule +// does not apply to run-end - a crashed run legitimately has none, and the +// window rule above already covers that case correctly. The cost is +// symmetric with the one above: if the log's front were ever trimmed, the +// oldest surviving run would refuse to undo. krino never trims the log - +// it is append-only with no rotation - so this only bites a hand-edited +// file, which is exactly the case where refusing is right. +func Entries(path, runID string) ([]Entry, error) { + lines, err := readLines(path) + if err != nil { + return nil, err + } + var out []Entry + badLine := 0 + inWindow := false + sawRunStart := false + for i, line := range lines { + e, ok := parseLine(line) + if ok { + if e.Run != runID { + continue + } + out = append(out, e) + switch e.Action { + case "run-start": + inWindow = true + sawRunStart = true + case "run-end": + inWindow = false + } + continue + } + if badLine != 0 { + continue + } + if inWindow { + badLine = i + 1 + continue + } + if run, found := runFieldOf(line); found && run == runID { + badLine = i + 1 + } + } + if badLine != 0 { + return out, fmt.Errorf("journal: entries: run %s: unparsable line %d", runID, badLine) + } + if len(out) > 0 && !sawRunStart { + return out, fmt.Errorf("journal: entries: run %s: no readable run-start", runID) + } + return out, nil +} + +// runFieldOf best-effort extracts a line's Run column even when the line +// otherwise fails to parse, so Entries can tell whether an unparsable line +// belonged to the run it was asked for. +func runFieldOf(line string) (string, bool) { + f := strings.SplitN(line, "\t", 3) + if len(f) < 2 { + return "", false + } + return unescape(f[1]), true +} + +// Runs summarises every run found in the log, newest first. n <= 0 means +// all. As with Entries, an unparsable line is skipped rather than failing +// the read - here silently and always, even when it belonged to the run +// being summarised: a listing that refuses to print anything because one +// old line is corrupt is worse than one that just omits it. +// +// A run is marked Undone when a later run's run-start entry's Detail is +// undoOfPrefix followed by this run's ID, AND that later run actually +// reversed something (fix wave item 2): a fully declined undo - every file +// the reviewer chose not to reverse - still opens with that same run-start +// (ApplyUndo logs a declined file exactly as spec §9 asks the forward path +// to), so the Detail alone is not proof anything happened. Reproduced by +// the reviewer: `krino undo` with every file declined left `krino log` +// reporting the original run "(undone)" regardless. What actually happened +// is provable from the same file: at least one "ok" undo-* entry. +func Runs(path string, n int) ([]Run, error) { + lines, err := readLines(path) + if err != nil { + return nil, err + } + + order := make([]string, 0) + byID := make(map[string]*Run) + pendingUndo := make(map[string]string) // undo run ID -> the run ID it claims to undo + + for _, line := range lines { + e, ok := parseLine(line) + if !ok { + continue + } + r, seen := byID[e.Run] + if !seen { + r = &Run{ID: e.Run, Start: e.Time, Counts: make(map[string]int)} + byID[e.Run] = r + order = append(order, e.Run) + } + if e.Dir != "" && !contains(r.Dirs, e.Dir) { + r.Dirs = append(r.Dirs, e.Dir) + } + if e.Status == "ok" { + r.Counts[e.Action]++ + } + if e.Action == "run-start" { + if orig, ok := strings.CutPrefix(e.Detail, undoOfPrefix); ok && orig != "" { + pendingUndo[e.Run] = orig + } + } + } + + // Resolved only once the whole file has been scanned: an undo run's + // run-start line - and therefore its claim on pendingUndo - is always + // written before its own step entries, so whether it actually reversed + // anything cannot be known until its Counts are complete. + undoes := make(map[string]bool) // run IDs actually reversed by some later run + for undoRun, orig := range pendingUndo { + if r, ok := byID[undoRun]; ok && ranAnyUndoStep(r.Counts) { + undoes[orig] = true + } + } + + runs := make([]Run, len(order)) + for i, id := range order { + runs[i] = *byID[id] + } + sort.SliceStable(runs, func(i, j int) bool { return runs[i].Start.After(runs[j].Start) }) + for i := range runs { + runs[i].Undone = undoes[runs[i].ID] + } + + if n > 0 && n < len(runs) { + runs = runs[:n] + } + return runs, nil +} + +// ranAnyUndoStep reports whether counts - a run's own tally of "ok" actions, +// by action name - includes at least one undo- action that actually +// restored something, as opposed to merely having been started and then +// declining every file (Important 2), or having failed to restore anything +// while a wholly unrelated undo-mkdir still happened to succeed (the +// coordinator's tightening of that same fix): "undo-mkdir" is deliberately +// excluded, the one undo- action package journal cannot help but name +// directly (this package must not import internal/engine to reuse its +// isFileAffecting predicate - journal is the lower layer), but which draws +// exactly the same line that predicate does. Removing a directory once it +// turns out empty is tidiness, not a restoration: a file's own chain stops +// after a failed file-affecting reversal, but a failed or refused +// undo-mkdir never stops anything (see internal/engine's isFileAffecting +// and undoFile), so it can succeed for one file while every file-affecting +// reversal in the whole run failed - and marking the original run Undone +// from that alone would be Important 2's bug again, by a narrower route. +func ranAnyUndoStep(counts map[string]int) bool { + for action, n := range counts { + if n > 0 && action != "undo-mkdir" && strings.HasPrefix(action, "undo-") { + return true + } + } + return false +} + +func contains(ss []string, s string) bool { + for _, x := range ss { + if x == s { + return true + } + } + return false +} + +// readLines reads path and splits it into lines, dropping the single +// trailing empty element a final newline produces. It does not itself +// validate line structure; parseLine does that per line. +func readLines(path string) ([]string, error) { + data, err := os.ReadFile(path) + if err != nil { + return nil, fmt.Errorf("journal: %w", err) + } + if len(data) == 0 { + return nil, nil + } + lines := strings.Split(string(data), "\n") + if lines[len(lines)-1] == "" { + lines = lines[:len(lines)-1] + } + return lines, nil +} + +// parseLine parses one log line into an Entry. It reports false for +// anything that does not look like a complete, well-formed line: wrong +// column count, or a time/step/size column that does not parse. That is the +// only contract a crash mid-write needs: the truncated final line always +// fails one of these checks, and everything before it still parses. +func parseLine(line string) (Entry, bool) { + f := strings.Split(line, "\t") + if len(f) != wantFields { + return Entry{}, false + } + t, err := time.Parse(time.RFC3339, f[0]) + if err != nil { + return Entry{}, false + } + step, err := strconv.Atoi(f[4]) + if err != nil { + return Entry{}, false + } + size, err := strconv.ParseInt(f[10], 10, 64) + if err != nil { + return Entry{}, false + } + mtime, err := time.Parse(time.RFC3339, f[11]) + if err != nil { + return Entry{}, false + } + return Entry{ + Time: t, + Run: unescape(f[1]), + Dir: unescape(f[2]), + File: unescape(f[3]), + Step: step, + Action: unescape(f[5]), + Status: unescape(f[6]), + Rule: unescape(f[7]), + Src: unescape(f[8]), + Dst: unescape(f[9]), + Size: size, + ModTime: mtime, + Detail: unescape(f[12]), + }, true +} + +// unescape reverses escape: \t, \n, \\ and \xNN. Any other backslash +// sequence - which a well-formed log never contains - is left as a literal +// backslash rather than silently eaten, so a hand-edited line does not lose +// data. +func unescape(s string) string { + if !strings.Contains(s, `\`) { + return s + } + var b strings.Builder + b.Grow(len(s)) + for i := 0; i < len(s); i++ { + c := s[i] + if c != '\\' || i+1 >= len(s) { + b.WriteByte(c) + continue + } + switch s[i+1] { + case 't': + b.WriteByte('\t') + i++ + case 'n': + b.WriteByte('\n') + i++ + case '\\': + b.WriteByte('\\') + i++ + case 'x': + if i+3 < len(s) { + if v, err := strconv.ParseUint(s[i+2:i+4], 16, 8); err == nil { + b.WriteByte(byte(v)) + i += 3 + continue + } + } + b.WriteByte(c) + default: + b.WriteByte(c) + } + } + return b.String() +} diff --git a/internal/journal/read_test.go b/internal/journal/read_test.go new file mode 100644 index 0000000..3ffa14d --- /dev/null +++ b/internal/journal/read_test.go @@ -0,0 +1,413 @@ +// SPDX-License-Identifier: GPL-3.0-or-later + +package journal + +import ( + "os" + "path/filepath" + "strings" + "testing" + "time" +) + +func TestRunsListsNewestFirst(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + t0 := time.Date(2026, 9, 11, 9, 0, 0, 0, time.UTC) + t1 := t0.Add(time.Hour) + for _, r := range []struct { + id string + at time.Time + dirs []string + }{{"A", t0, []string{"dl"}}, {"B", t1, []string{"dl", "docs"}}} { + w.Append(Entry{Time: r.at, Run: r.id, Action: "run-start", Status: "ok"}) + for _, d := range r.dirs { + w.Append(Entry{Time: r.at, Run: r.id, Dir: d, File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}) + } + w.Append(Entry{Time: r.at, Run: r.id, Action: "run-end", Status: "ok"}) + } + w.Close() + + runs, err := Runs(path, 0) + if err != nil { + t.Fatal(err) + } + if len(runs) != 2 || runs[0].ID != "B" || runs[1].ID != "A" { + t.Fatalf("runs = %+v; want B then A", runs) + } + if len(runs[0].Dirs) != 2 || runs[0].Dirs[0] != "dl" || runs[0].Dirs[1] != "docs" { + t.Errorf("run B dirs = %v, want [dl docs] in first-seen order", runs[0].Dirs) + } + if runs[0].Counts["move"] != 2 { + t.Errorf("run B move count = %d, want 2", runs[0].Counts["move"]) + } + if !runs[0].Start.Equal(t1) { + t.Errorf("run B start = %v, want %v", runs[0].Start, t1) + } + if runs, err = Runs(path, 1); err != nil || len(runs) != 1 || runs[0].ID != "B" { + t.Errorf("Runs(path, 1) = %+v, %v", runs, err) + } +} + +// TestTruncatedLastLineIsSkipped: a crash mid-write must not make the log +// unreadable - everything before the broken line still parses. +func TestTruncatedLastLineIsSkipped(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + w.Append(Entry{Time: time.Now(), Run: "A", Action: "run-start", Status: "ok"}) + w.Close() + f, _ := os.OpenFile(path, os.O_APPEND|os.O_WRONLY, 0o644) + f.WriteString("2026-09-11T10:02:03+02:00\tA\tdl\thalf-written") + f.Close() + + runs, err := Runs(path, 0) + if err != nil { + t.Fatalf("a truncated final line made the whole log unreadable: %v", err) + } + if len(runs) != 1 || runs[0].ID != "A" { + t.Errorf("runs = %+v; want the complete run A", runs) + } +} + +// TestRunsMarksAnUndoneRun: an undo run's run-start Detail names the run it +// reverses, in the exact format "undo of ". Runs must mark that +// earlier run Undone, and must not mark the undo run itself. +func TestRunsMarksAnUndoneRun(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + t0 := time.Date(2026, 9, 11, 9, 0, 0, 0, time.UTC) + t1 := t0.Add(time.Hour) + w.Append(Entry{Time: t0, Run: "A", Action: "run-start", Status: "ok"}) + w.Append(Entry{Time: t0, Run: "A", Dir: "dl", File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}) + w.Append(Entry{Time: t0, Run: "A", Action: "run-end", Status: "ok"}) + w.Append(Entry{Time: t1, Run: "B", Action: "run-start", Status: "ok", Detail: "undo of A"}) + w.Append(Entry{Time: t1, Run: "B", Dir: "dl", File: "x.pdf", Step: 1, + Action: "undo-move", Status: "ok", Src: "/b/x.pdf", Dst: "/a/x.pdf"}) + w.Append(Entry{Time: t1, Run: "B", Action: "run-end", Status: "ok"}) + w.Close() + + runs, err := Runs(path, 0) + if err != nil { + t.Fatal(err) + } + byID := map[string]Run{} + for _, r := range runs { + byID[r.ID] = r + } + if !byID["A"].Undone { + t.Errorf("run A = %+v, want Undone", byID["A"]) + } + if byID["B"].Undone { + t.Errorf("run B (the undo run itself) = %+v, want not Undone", byID["B"]) + } +} + +// TestRunsDoesNotMarkUndoneWhenEveryFileWasDeclined is fix wave item 2 +// (Important) / final-wave item 17: an undo run's run-start Detail alone +// used to be enough for Runs to mark the original run Undone, even when the +// undo run went on to decline every file (spec §9's "declined files are +// logged even though nothing happens to them", extended to undo) and +// reversed nothing at all. Reproduced by the reviewer via pty: `krino log` +// told the user a run had been undone when the file was still filed. Run B +// here carries the same run-start Detail as TestRunsMarksAnUndoneRun's, but +// every one of its file-scoped entries is "declined", never "ok" - the +// shape ApplyUndo logs when the front end's own review declines everything +// - so run A must come back exactly as untouched. +func TestRunsDoesNotMarkUndoneWhenEveryFileWasDeclined(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + t0 := time.Date(2026, 9, 11, 9, 0, 0, 0, time.UTC) + t1 := t0.Add(time.Hour) + w.Append(Entry{Time: t0, Run: "A", Action: "run-start", Status: "ok"}) + w.Append(Entry{Time: t0, Run: "A", Dir: "dl", File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}) + w.Append(Entry{Time: t0, Run: "A", Action: "run-end", Status: "ok"}) + w.Append(Entry{Time: t1, Run: "B", Action: "run-start", Status: "ok", Detail: "undo of A"}) + w.Append(Entry{Time: t1, Run: "B", Dir: "dl", File: "x.pdf", Step: 1, + Action: "undo-move", Status: "declined", Src: "/b/x.pdf", Dst: "/a/x.pdf"}) + w.Append(Entry{Time: t1, Run: "B", Action: "run-end", Status: "ok"}) + w.Close() + + runs, err := Runs(path, 0) + if err != nil { + t.Fatal(err) + } + byID := map[string]Run{} + for _, r := range runs { + byID[r.ID] = r + } + if byID["A"].Undone { + t.Errorf("run A = %+v, want NOT Undone - the undo run declined every file and reversed nothing", byID["A"]) + } + if byID["B"].Undone { + t.Errorf("run B (the undo run itself) = %+v, want not Undone", byID["B"]) + } +} + +// TestRunsDoesNotMarkUndoneWhenOnlyOkEntryIsMkdir is the coordinator's +// tightening of fix wave item 2: "at least one ok undo-* entry" is still +// too loose, by the same shape as the bug it fixes. A file's own chain +// stops after a failed file-affecting reversal, but a failed or refused +// undo-mkdir deliberately does not stop anything (internal/engine's +// isFileAffecting draws exactly this line, and undoFile's stop-on-failure +// check shares it) - so an undo-mkdir belonging to one file can still +// succeed even though every file-affecting reversal in the whole run +// failed. Here x.pdf's own undo-move fails, y.pdf's own undo-move also +// fails, and z.pdf's undo-mkdir - tidying up a directory that turned out +// empty, not restoring anything - is the run's only "ok" entry. Marking +// the original run Undone from that alone would be exactly Important 2's +// bug again, by a narrower route. +func TestRunsDoesNotMarkUndoneWhenOnlyOkEntryIsMkdir(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + t0 := time.Date(2026, 9, 11, 9, 0, 0, 0, time.UTC) + t1 := t0.Add(time.Hour) + w.Append(Entry{Time: t0, Run: "A", Action: "run-start", Status: "ok"}) + w.Append(Entry{Time: t0, Run: "A", Dir: "dl", File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}) + w.Append(Entry{Time: t0, Run: "A", Dir: "dl", File: "y.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/y.pdf", Dst: "/b/y.pdf"}) + w.Append(Entry{Time: t0, Run: "A", Action: "run-end", Status: "ok"}) + w.Append(Entry{Time: t1, Run: "B", Action: "run-start", Status: "ok", Detail: "undo of A"}) + w.Append(Entry{Time: t1, Run: "B", Dir: "dl", File: "x.pdf", Step: 1, + Action: "undo-move", Status: "failed", Src: "/b/x.pdf", Dst: "/a/x.pdf"}) + w.Append(Entry{Time: t1, Run: "B", Dir: "dl", File: "y.pdf", Step: 1, + Action: "undo-move", Status: "failed", Src: "/b/y.pdf", Dst: "/a/y.pdf"}) + // z.pdf's own file-affecting reversal is unrelated to x.pdf/y.pdf's + // failures; only its cleanup mkdir is shown here, since that mkdir is + // the one entry this test is about - the run's only "ok" line. + w.Append(Entry{Time: t1, Run: "B", Dir: "dl", File: "z.pdf", Step: 2, + Action: "undo-mkdir", Status: "ok", Src: "/a/Work"}) + w.Append(Entry{Time: t1, Run: "B", Action: "run-end", Status: "ok"}) + w.Close() + + runs, err := Runs(path, 0) + if err != nil { + t.Fatal(err) + } + byID := map[string]Run{} + for _, r := range runs { + byID[r.ID] = r + } + if byID["A"].Undone { + t.Errorf("run A = %+v, want NOT Undone - the run's only ok entry is an undo-mkdir (tidiness, not a restoration), and every file-affecting reversal failed", byID["A"]) + } +} + +// TestEntriesReportsAMangledLine: a corrupt line that is not the log's +// final line must not be silently dropped by Entries the way Runs drops it +// - PlanUndo needs to know a step went missing so it can refuse the whole +// run rather than half-undo a file (spec §10). +func TestEntriesReportsAMangledLine(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + at := time.Date(2026, 9, 11, 10, 2, 3, 0, time.UTC) + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Dir: "dl", File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-end", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Close(); err != nil { + t.Fatal(err) + } + + // Mangle line 2 (the move step) in place: corrupt its Step column so it + // fails to parse, without touching the line or column count of the + // file otherwise - the point is a bad line in the middle, not at EOF. + raw, err := os.ReadFile(path) + if err != nil { + t.Fatal(err) + } + lines := strings.Split(strings.TrimRight(string(raw), "\n"), "\n") + if len(lines) != 3 { + t.Fatalf("fixture has %d lines, want 3", len(lines)) + } + fields := strings.Split(lines[1], "\t") + fields[4] = "not-a-number" // the step column + lines[1] = strings.Join(fields, "\t") + if err := os.WriteFile(path, []byte(strings.Join(lines, "\n")+"\n"), 0o644); err != nil { + t.Fatal(err) + } + + got, err := Entries(path, "A") + if err == nil { + t.Fatal("Entries did not report the mangled line") + } + if !strings.Contains(err.Error(), "line 2") { + t.Errorf("error %q does not name line 2", err) + } + if len(got) != 2 { + t.Fatalf("got %d entries, want the 2 surviving (run-start, run-end): %+v", len(got), got) + } + if got[0].Action != "run-start" || got[1].Action != "run-end" { + t.Errorf("entries = %+v", got) + } +} + +// TestEntriesFailsClosedOnUnattributableCorruptionInsideWindow: when a +// line's own Run column is destroyed, Entries cannot attribute it by +// content - but if it falls inside runID's own window (between its +// run-start and run-end), that possibility alone must be enough to refuse +// rather than silently return an incomplete chain (spec §10). +func TestEntriesFailsClosedOnUnattributableCorruptionInsideWindow(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + at := time.Date(2026, 9, 11, 10, 2, 3, 0, time.UTC) + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Dir: "dl", File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-end", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Close(); err != nil { + t.Fatal(err) + } + + // Insert a line with no tabs at all - its Run column is unrecoverable - + // between the move step and run-end, i.e. inside A's window. + raw, err := os.ReadFile(path) + if err != nil { + t.Fatal(err) + } + lines := strings.Split(strings.TrimRight(string(raw), "\n"), "\n") + if len(lines) != 3 { + t.Fatalf("fixture has %d lines, want 3", len(lines)) + } + inserted := make([]string, 0, len(lines)+1) + inserted = append(inserted, lines[:2]...) + inserted = append(inserted, "totally-mangled-no-tabs-here") + inserted = append(inserted, lines[2:]...) + if err := os.WriteFile(path, []byte(strings.Join(inserted, "\n")+"\n"), 0o644); err != nil { + t.Fatal(err) + } + + got, err := Entries(path, "A") + if err == nil { + t.Fatal("Entries did not fail closed on unattributable corruption inside the run's window") + } + if !strings.Contains(err.Error(), "line 3") { + t.Errorf("error %q does not name line 3", err) + } + if len(got) != 3 { + t.Fatalf("got %d entries, want the 3 surviving (run-start, move, run-end): %+v", len(got), got) + } +} + +// TestEntriesIgnoresUnattributableCorruptionOutsideWindow: the same +// corruption shape, placed after A's run-end inside a later run B's own +// window, must not poison A - the window scoping keeps it out. +func TestEntriesIgnoresUnattributableCorruptionOutsideWindow(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + at := time.Date(2026, 9, 11, 10, 2, 3, 0, time.UTC) + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Dir: "dl", File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-end", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "B", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "B", Action: "run-end", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Close(); err != nil { + t.Fatal(err) + } + + // Insert the same unattributable corruption, now inside B's window + // (between B's run-start and run-end), not A's. + raw, err := os.ReadFile(path) + if err != nil { + t.Fatal(err) + } + lines := strings.Split(strings.TrimRight(string(raw), "\n"), "\n") + if len(lines) != 5 { + t.Fatalf("fixture has %d lines, want 5", len(lines)) + } + inserted := make([]string, 0, len(lines)+1) + inserted = append(inserted, lines[:4]...) + inserted = append(inserted, "totally-mangled-no-tabs-here") + inserted = append(inserted, lines[4:]...) + if err := os.WriteFile(path, []byte(strings.Join(inserted, "\n")+"\n"), 0o644); err != nil { + t.Fatal(err) + } + + got, err := Entries(path, "A") + if err != nil { + t.Fatalf("corruption outside A's window poisoned A: %v", err) + } + if len(got) != 3 { + t.Fatalf("got %d entries, want A's 3: %+v", len(got), got) + } +} + +// TestEntriesFailsClosedOnMissingRunStart: run-start is not an optional +// marker - every run Apply writes begins with one, so its absence, once +// other entries for the run did parse, means either corruption or a log +// truncated at the front. Either way the chain cannot be trusted, even +// though the window logic alone sees nothing wrong (it never opens without +// a parsed run-start, so it never flags anything inside the gap). +func TestEntriesFailsClosedOnMissingRunStart(t *testing.T) { + path := filepath.Join(t.TempDir(), "krino.log") + w, _ := Open(path) + at := time.Date(2026, 9, 11, 10, 2, 3, 0, time.UTC) + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-start", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Dir: "dl", File: "x.pdf", Step: 1, + Action: "move", Status: "ok", Src: "/a/x.pdf", Dst: "/b/x.pdf"}); err != nil { + t.Fatal(err) + } + if err := w.Append(Entry{Time: at, Run: "A", Action: "run-end", Status: "ok"}); err != nil { + t.Fatal(err) + } + if err := w.Close(); err != nil { + t.Fatal(err) + } + + // Replace A's run-start line (line 1) with a line with no tabs at all - + // unrecoverable, like the round-1 fixtures. + raw, err := os.ReadFile(path) + if err != nil { + t.Fatal(err) + } + lines := strings.Split(strings.TrimRight(string(raw), "\n"), "\n") + if len(lines) != 3 { + t.Fatalf("fixture has %d lines, want 3", len(lines)) + } + lines[0] = "totally-mangled-no-tabs-here" + if err := os.WriteFile(path, []byte(strings.Join(lines, "\n")+"\n"), 0o644); err != nil { + t.Fatal(err) + } + + got, err := Entries(path, "A") + if err == nil { + t.Fatal("Entries did not fail closed on a missing run-start") + } + if !strings.Contains(err.Error(), "run-start") { + t.Errorf("error %q does not name the missing run-start", err) + } + if len(got) != 2 { + t.Fatalf("got %d entries, want the 2 surviving (move, run-end): %+v", len(got), got) + } + if got[0].Action != "move" || got[1].Action != "run-end" { + t.Errorf("entries = %+v", got) + } +} -- cgit v1.3