package main import ( "bytes" "os" "path/filepath" "strings" "testing" "time" "github.com/runbear-io/beardrive/internal/config" ) // The reported bug was read off `bdrive log`'s own output, so assert on that // output: every printed timestamp descends, the file's edit time still reaches // the reader (files written minutes apart don't collapse onto one), and -n // keeps the newest by that stamp rather than the highest lamport. // // The first column is now when the change was journaled, so the edit time it // used to carry is asserted where it is now printed — the appended // `written ...` field. That is BEA-40's guarantee, moved, not dropped. func TestLogPrintsNewestFirstByEditTime(t *testing.T) { t.Setenv("BDRIVE_HOME", t.TempDir()) folder := t.TempDir() folder, _ = filepath.EvalSymlinks(folder) if _, err := config.SaveProject(folder, config.Project{ Volume: "wiki", Remote: "https://hub.example.com/p/p-12345678", // unreachable: the cycle degrades offline }); err != nil { t.Fatal(err) } if _, _, err := config.EnrollMount(folder); err != nil { // enroll, as `bdrive init` would t.Fatal(err) } // Written in one scan, edited at three different times — and the newest // edit is deliberately not the one the walk sees last. now := time.Now() files := map[string]time.Duration{ "a-oldest.md": -30 * time.Minute, "b-newest.md": -1 * time.Minute, "c-middle.md": -10 * time.Minute, } for rel, age := range files { abs := filepath.Join(folder, rel) if err := os.WriteFile(abs, []byte("content of "+rel), 0o644); err != nil { t.Fatal(err) } when := now.Add(age) if err := os.Chtimes(abs, when, when); err != nil { t.Fatal(err) } } sync := syncCmd() sync.SetOut(&bytes.Buffer{}) sync.SetArgs([]string{folder}) if err := sync.Execute(); err != nil { t.Fatalf("sync: %v", err) } rows := runLog(t, folder) if len(rows) != 3 { t.Fatalf("got %d rows, want 3:\n%v", len(rows), paths(rows)) } if want := []string{"b-newest.md", "c-middle.md", "a-oldest.md"}; !equal(paths(rows), want) { t.Fatalf("row order = %v, want %v", paths(rows), want) } for i := 1; i < len(rows); i++ { if rows[i].stamp.After(rows[i-1].stamp) { t.Fatalf("printed stamps are not newest-first: %v then %v", rows[i-1].stamp, rows[i].stamp) } } // Three edits minutes apart must still reach the reader as three distinct // write times; before BEA-40 one scan stamped them all with its own time. for i, r := range rows { if r.written.IsZero() { t.Fatalf("row %d (%s) dropped the file's write time", i, r.path) } } if rows[0].written.Equal(rows[1].written) || rows[1].written.Equal(rows[2].written) { t.Fatalf("write times collapsed onto the sync time: %v %v %v", rows[0].written, rows[1].written, rows[2].written) } // -n truncates after the display sort. top := runLog(t, folder, "-n", "2") if want := []string{"b-newest.md", "c-middle.md"}; !equal(paths(top), want) { t.Fatalf("-n 2 = %v, want %v", paths(top), want) } // -p still filters to one path. only := runLog(t, folder, "-p", "c-middle.md") if want := []string{"c-middle.md"}; !equal(paths(only), want) { t.Fatalf("-p = %v, want %v", paths(only), want) } } // A rename is one change, and `mv` preserves mtime — so before this, the put // half was stamped with the original file's write time and sorted away from // its own delete, which is how a file that appeared seconds ago falls below // the fold of "what changed since yesterday". func TestLogKeepsARenameTogether(t *testing.T) { folder := logFixture(t) old := filepath.Join(folder, "architecture.md") if err := os.WriteFile(old, []byte("# architecture"), 0o644); err != nil { t.Fatal(err) } // Written well before the rename: the gap is the bug. long := time.Now().Add(-90 * time.Minute) if err := os.Chtimes(old, long, long); err != nil { t.Fatal(err) } // Filler, so "adjacent at the top" is a real claim and not the only rows. for _, rel := range []string{"notes.md", "todo.md"} { if err := os.WriteFile(filepath.Join(folder, rel), []byte(rel), 0o644); err != nil { t.Fatal(err) } } runSync(t, folder) if err := os.Rename(old, filepath.Join(folder, "arch-v2.md")); err != nil { t.Fatal(err) } runSync(t, folder) rows := runLog(t, folder) if len(rows) < 2 { t.Fatalf("got %d rows, want the rename plus fillers: %v", len(rows), paths(rows)) } // The two halves are one change and sit together at the top. The delete // leads: it has no file left to stat, so it sorts on the commit time while // the put still carries its 90-minute-old write time as the tie-break. got := []string{rows[0].kind + " " + rows[0].path, rows[1].kind + " " + rows[1].path} want := []string{"delete architecture.md", "put arch-v2.md"} if !equal(got, want) { t.Fatalf("top two rows = %v, want the rename's two halves %v\nall: %v", got, want, paths(rows)) } if !rows[0].stamp.Equal(rows[1].stamp) { t.Fatalf("one rename printed two stamps: %v and %v", rows[0].stamp, rows[1].stamp) } // The write time is what makes the 90-minute gap legible instead of silent. if rows[1].written.IsZero() { t.Fatal("the put half dropped the file's write time") } if gap := rows[1].stamp.Sub(rows[1].written); gap < time.Hour { t.Fatalf("put half's write time = %v, stamp = %v: the original mtime was lost", rows[1].written, rows[1].stamp) } // A delete has no file left to stat, so it never carries the field. if !rows[0].written.IsZero() { t.Fatalf("delete row carried a write time: %v", rows[0].written) } } // An old document dropped into the project today is a change today. It used to // sort by its own mtime, i.e. below everything journaled since it was written. func TestLogSortsAnOldFileByWhenItArrived(t *testing.T) { folder := logFixture(t) recent := filepath.Join(folder, "recent.md") if err := os.WriteFile(recent, []byte("edited a minute ago"), 0o644); err != nil { t.Fatal(err) } fresh := time.Now().Add(-2 * time.Minute) if err := os.Chtimes(recent, fresh, fresh); err != nil { t.Fatal(err) } runSync(t, folder) // Journaled second, written days before the file above it. ancient := filepath.Join(folder, "ancient.md") if err := os.WriteFile(ancient, []byte("from the archive"), 0o644); err != nil { t.Fatal(err) } old := time.Now().Add(-72 * time.Hour) if err := os.Chtimes(ancient, old, old); err != nil { t.Fatal(err) } runSync(t, folder) rows := runLog(t, folder) if want := []string{"ancient.md", "recent.md"}; !equal(paths(rows), want) { t.Fatalf("row order = %v, want %v — the newly arrived file sorts first", paths(rows), want) } if rows[0].written.IsZero() || rows[0].stamp.Sub(rows[0].written) < 24*time.Hour { t.Fatalf("ancient.md lost its write time: stamp %v, written %v", rows[0].stamp, rows[0].written) } } // logFixture is an enrolled folder pointed at an unreachable hub, so the cycle // degrades offline and the journal is all local. func logFixture(t *testing.T) string { t.Helper() t.Setenv("BDRIVE_HOME", t.TempDir()) folder := t.TempDir() folder, _ = filepath.EvalSymlinks(folder) if _, err := config.SaveProject(folder, config.Project{ Volume: "wiki", Remote: "https://hub.example.com/p/p-12345678", }); err != nil { t.Fatal(err) } if _, _, err := config.EnrollMount(folder); err != nil { t.Fatal(err) } return folder } func runSync(t *testing.T, folder string) { t.Helper() c := syncCmd() c.SetOut(&bytes.Buffer{}) c.SetArgs([]string{folder}) if err := c.Execute(); err != nil { t.Fatalf("sync: %v", err) } } // logRow is one parsed `bdrive log` line: the leading stamp (when the change // was journaled), the kind and path columns, and the appended write time when // the row carries one. type logRow struct { stamp time.Time written time.Time kind string path string } // runLog runs `bdrive log` and parses its rows. func runLog(t *testing.T, folder string, extra ...string) []logRow { t.Helper() c := logCmd() var out bytes.Buffer c.SetOut(&out) c.SetArgs(append([]string{folder}, extra...)) if err := c.Execute(); err != nil { t.Fatalf("log: %v", err) } const stampFmt = "2006-01-02 15:04:05" var rows []logRow for _, line := range strings.Split(strings.TrimSpace(out.String()), "\n") { if line == "" { continue } ts, err := time.ParseInLocation(stampFmt, line[:19], time.Local) if err != nil { t.Fatalf("unparsable log row %q: %v", line, err) } fields := strings.Fields(line[19:]) row := logRow{stamp: ts, kind: fields[0], path: fields[1]} if _, rest, ok := strings.Cut(line, "(written "); ok { stamp, _, _ := strings.Cut(rest, ")") w, err := time.ParseInLocation(stampFmt, stamp, time.Local) if err != nil { t.Fatalf("unparsable write time in %q: %v", line, err) } row.written = w } rows = append(rows, row) } return rows } func paths(rows []logRow) []string { out := make([]string, len(rows)) for i, r := range rows { out[i] = r.path } return out } func equal(a, b []string) bool { if len(a) != len(b) { return false } for i := range a { if a[i] != b[i] { return false } } return true }