diff --git a/TODO.md b/TODO.md index 3a362c5..1bb83f7 100644 --- a/TODO.md +++ b/TODO.md @@ -36,8 +36,20 @@ or delete the branch. `reportRemoteDrift` collapsed into the merged view. Every remote manifest read in the codebase now goes through `downloadManifestByKey`, so issue #81 has one call site to change. - Verified with `script/cibuild` and end to end against a `file://` - destination with no secret key present. + Review rework: snapshot timestamps now normalize to UTC in + `scanSnapshotRows`, the one place they enter the domain, so the merged + TIMESTAMP column cannot show local time for a locally tracked row and + UTC for a remote-only row on a non-UTC host; `GetIncompleteByHostname` + was folded onto that same scanner. `--json` now reports the + unreadable-manifest count and the 1000-row truncation on stderr + instead of returning a silently short document (the document's shape + is unchanged). The two per-snapshot `log.Warn` calls on the listing + path now route through the same JSON-aware writer as the existing + workaround, so one corrupt manifest can no longer put a log line on + stdout ahead of the document and break `| jq` — still a local + workaround pending issue #82. Verified with `script/cibuild` and with + an uncached `make check` (`0 issues.`, no cached test packages), plus + end to end against a `file://` destination with no secret key present. - 2026-08-09: Closed the gap between `make lint` and CI (issue #78). `script/lint` now runs the digest-pinned `golangci-lint` image taken from the `Dockerfile` lint stage, which is the single source of truth diff --git a/internal/database/snapshots.go b/internal/database/snapshots.go index 715ab78..97bef66 100644 --- a/internal/database/snapshots.go +++ b/internal/database/snapshots.go @@ -609,43 +609,9 @@ func (r *SnapshotRepository) GetIncompleteByHostname( } }() - var snapshots []*Snapshot - - for rows.Next() { - var ( - snapshot Snapshot - startedAtUnix int64 - completedAtUnix *int64 - ) - - err := rows.Scan( - &snapshot.ID, - &snapshot.Hostname, - &snapshot.VaultikVersion, - &snapshot.VaultikGitRevision, - &startedAtUnix, - &completedAtUnix, - &snapshot.FileCount, - &snapshot.ChunkCount, - &snapshot.BlobCount, - &snapshot.TotalSize, - &snapshot.BlobSize, - &snapshot.CompressionRatio, - ) - if err != nil { - return nil, fmt.Errorf("scanning snapshot: %w", err) - } - - snapshot.StartedAt = time.Unix(startedAtUnix, 0).UTC() - if completedAtUnix != nil { - t := time.Unix(*completedAtUnix, 0).UTC() - snapshot.CompletedAt = &t - } - - snapshots = append(snapshots, &snapshot) - } - - return snapshots, rows.Err() + // Same column set as every other multi-row snapshot query, so the + // shared scanner applies — including its timestamp normalization. + return r.scanSnapshotRows(rows) } // Delete removes a snapshot record @@ -764,9 +730,16 @@ func (r *SnapshotRepository) scanSnapshotRows(rows *sql.Rows) ([]*Snapshot, erro return nil, fmt.Errorf("scanning snapshot: %w", err) } - snapshot.StartedAt = time.Unix(startedAtUnix, 0) + // UTC, matching every other snapshot scanner in this file. The + // column holds a bare Unix second, so the zone is a decode + // choice rather than stored data, and callers render these + // timestamps through zone-less format strings alongside + // timestamps read from remote manifests. Decoding in the host's + // local zone here would put two different wall clocks in one + // column. + snapshot.StartedAt = time.Unix(startedAtUnix, 0).UTC() if completedAtUnix != nil { - t := time.Unix(*completedAtUnix, 0) + t := time.Unix(*completedAtUnix, 0).UTC() snapshot.CompletedAt = &t } diff --git a/internal/database/snapshots_test.go b/internal/database/snapshots_test.go index 5204a61..9d07c8e 100644 --- a/internal/database/snapshots_test.go +++ b/internal/database/snapshots_test.go @@ -191,6 +191,119 @@ func TestSnapshotRepositoryListRecent(t *testing.T) { } } +// TestSnapshotTimestampsDecodeAsUTC pins the zone every snapshot reader +// returns. started_at and completed_at are stored as bare Unix seconds, +// so the zone is a decode choice, and callers (notably `snapshot list`) +// render these timestamps through zone-less format strings in the same +// column as timestamps read from remote manifests, which are always +// UTC. If one reader decodes in the host's local zone, that column +// silently shows two different wall clocks for the same instant. +// +// The assertions compare *time.Location pointers, so this fails on a +// UTC host too: time.Unix returns time.Local, which is never the same +// Location value as time.UTC no matter what the host's offset is. +func TestSnapshotTimestampsDecodeAsUTC(t *testing.T) { + t.Parallel() + + db, cleanup := setupTestDB(t) + defer cleanup() + + ctx := context.Background() + repo := database.NewSnapshotRepository(db) + + startedAt := time.Date(2026, 3, 1, 10, 0, 0, 0, time.UTC) + completedAt := startedAt.Add(time.Minute) + + completed := &database.Snapshot{ + ID: types.SnapshotID("testhost_home_2026-03-01T10:00:00Z"), + Hostname: testHostname, + VaultikVersion: testVersion, + StartedAt: startedAt, + CompletedAt: &completedAt, + } + + err := repo.Create(ctx, nil, completed) + if err != nil { + t.Fatalf("failed to create completed snapshot: %v", err) + } + + // An incomplete row as well, so the scanner shared by the two + // GetIncomplete* readers is covered with a nil completed_at too. + incomplete := &database.Snapshot{ + ID: types.SnapshotID("testhost_home_2026-03-02T10:00:00Z"), + Hostname: testHostname, + VaultikVersion: testVersion, + StartedAt: startedAt.Add(time.Hour), + CompletedAt: nil, + } + + err = repo.Create(ctx, nil, incomplete) + if err != nil { + t.Fatalf("failed to create incomplete snapshot: %v", err) + } + + byID, err := repo.GetByID(ctx, completed.ID.String()) + if err != nil { + t.Fatalf("failed to get snapshot by id: %v", err) + } + + recent, err := repo.ListRecent(ctx, 10) + if err != nil { + t.Fatalf("failed to list recent snapshots: %v", err) + } + + incompletes, err := repo.GetIncompleteSnapshots(ctx) + if err != nil { + t.Fatalf("failed to list incomplete snapshots: %v", err) + } + + byHost, err := repo.GetIncompleteByHostname(ctx, testHostname) + if err != nil { + t.Fatalf("failed to list incomplete snapshots by hostname: %v", err) + } + + read := make([]*database.Snapshot, 0, + 1+len(recent)+len(incompletes)+len(byHost)) + read = append(read, byID) + read = append(read, recent...) + read = append(read, incompletes...) + read = append(read, byHost...) + + if len(read) < 5 { + t.Fatalf("expected every reader to return rows, got %d", len(read)) + } + + assertTimestampsAreUTC(t, read) + + // And the wall clock is the UTC one, not the host's rendering of it. + rendered := byID.StartedAt.Format("2006-01-02 15:04:05") + if rendered != "2026-03-01 10:00:00" { + t.Errorf("started_at rendered as %q, want the UTC wall clock", rendered) + } +} + +// assertTimestampsAreUTC fails for any snapshot whose timestamps did not +// decode in UTC. It compares *time.Location pointers rather than +// offsets, so it is equally strict on a host whose local zone happens to +// be UTC: time.Unix returns time.Local, which is never the same Location +// value as time.UTC. +func assertTimestampsAreUTC(t *testing.T, snapshots []*database.Snapshot) { + t.Helper() + + for _, snapshot := range snapshots { + if snapshot.StartedAt.Location() != time.UTC { + t.Errorf("snapshot %s: started_at decoded in %s, want UTC", + snapshot.ID, snapshot.StartedAt.Location()) + } + + if snapshot.CompletedAt != nil && + snapshot.CompletedAt.Location() != time.UTC { + t.Errorf("snapshot %s: completed_at decoded in %s, want UTC", + snapshot.ID, snapshot.CompletedAt.Location()) + } + } +} + func TestSnapshotRepositoryNotFound(t *testing.T) { t.Parallel() diff --git a/internal/vaultik/snapshot_list.go b/internal/vaultik/snapshot_list.go index 70d228f..f4fcc8c 100644 --- a/internal/vaultik/snapshot_list.go +++ b/internal/vaultik/snapshot_list.go @@ -87,7 +87,7 @@ func (v *Vaultik) ListSnapshots(jsonOutput bool) error { snapshots = append(snapshots, info) } - listing, remoteErr := v.collectRemoteSnapshots(localKeys) + listing, remoteErr := v.collectRemoteSnapshots(localKeys, jsonOutput) if remoteErr != nil { v.warnRemoteListingFailed(remoteErr, jsonOutput) } else { @@ -95,11 +95,19 @@ func (v *Vaultik) ListSnapshots(jsonOutput bool) error { markRemotePresence(snapshots, listing.keys) } - sort.Slice(snapshots, func(i, j int) bool { + // Stable so that rows sharing a timestamp keep the order they were + // merged in, rather than depending on the sort's pivot choices. The + // unparseable-timestamp fallback in remoteSnapshotInfo makes ties + // realistic: every such row carries the zero time. + sort.SliceStable(snapshots, func(i, j int) bool { return snapshots[i].Timestamp.After(snapshots[j].Timestamp) }) if jsonOutput { + if remoteErr == nil { + v.reportJSONListingLimits(listing) + } + encoder := json.NewEncoder(v.Stdout) encoder.SetIndent("", " ") @@ -138,11 +146,79 @@ func (v *Vaultik) warnRemoteListingFailed(err error, jsonOutput bool) { return } - log.Warn("Could not list backup destination store", "error", err) + // Once only: the logger also writes to stdout, so emitting through + // both it and the UI would print the same sentence to the user twice. v.UI.Warningf("Could not list backup destination store: %v.", err) v.UI.Infof("Showing snapshots from the local index only.") } +// reportJSONListingLimits tells a --json consumer that the document it +// is about to read is incomplete: manifests that could not be read, and +// remote-only snapshots dropped by the maxRemoteOnlyRows cap. +// +// Table mode reports both below the table (see reportListDrift). In +// --json mode they cannot go on stdout — the document has to be the +// only thing there for `snapshot list --json | jq` to work — and the +// document's shape is deliberately left alone so existing consumers +// keep parsing. So they go to stderr, the same place the +// unreachable-destination warning already goes. A consumer that must +// react to truncation can treat any output on this stream as "this +// listing is not the whole picture"; silent truncation of a listing +// whose whole purpose is disaster recovery is the worse failure. +func (v *Vaultik) reportJSONListingLimits(listing *remoteSnapshotListing) { + if listing.unreadable > 0 { + _, _ = fmt.Fprintf(v.Stderr, + "Warning: %d remote snapshot(s) could not be described: "+ + "manifest missing or unreadable. They are missing from "+ + "this listing.\n", listing.unreadable) + } + + if listing.omitted > 0 { + _, _ = fmt.Fprintf(v.Stderr, + "Warning: listing truncated: %d further remote-only "+ + "snapshot(s) not shown (limit %d per listing).\n", + listing.omitted, maxRemoteOnlyRows) + } +} + +// kvPairSize is the number of variadic arguments that make up one +// structured logging key/value pair. +const kvPairSize = 2 + +// warnWhileListing reports a per-snapshot problem found while +// describing the destination store, through a writer that is safe for +// the current output mode. +// +// In --json mode it writes to v.Stderr rather than calling log.Warn, +// for the same reason warnRemoteListingFailed does: internal/log builds +// its logger over os.Stdout and defaults to level Warn, so one warning +// there would put a log line on stdout ahead of the JSON document and +// break `snapshot list --json | jq`. A single corrupt manifest is +// precisely the degradation this listing is built to survive, so it +// must not be the thing that corrupts the output. +// +// This is a local workaround. Remove it, and the branch in +// warnRemoteListingFailed, once issue #82 makes the logger's sink +// configurable. +func (v *Vaultik) warnWhileListing(jsonOutput bool, msg string, args ...any) { + if !jsonOutput { + log.Warn(msg, args...) + + return + } + + var line strings.Builder + + _, _ = fmt.Fprintf(&line, "Warning: %s", msg) + + for i := 0; i+kvPairSize <= len(args); i += kvPairSize { + pair := args[i : i+kvPairSize] + _, _ = fmt.Fprintf(&line, " %v=%v", pair[0], pair[1]) + } + + _, _ = fmt.Fprintln(v.Stderr, line.String()) +} + // remoteSnapshotListing is the result of one pass over the destination // store's metadata/ prefix. type remoteSnapshotListing struct { @@ -171,8 +247,11 @@ type remoteSnapshotListing struct { // Manifest reads scale only with the number of snapshots the local // index does not already know about, and are capped at // maxRemoteOnlyRows. +// +// jsonOutput only selects where per-snapshot warnings are written; see +// warnWhileListing. func (v *Vaultik) collectRemoteSnapshots( - localKeys map[string]bool, + localKeys map[string]bool, jsonOutput bool, ) (*remoteSnapshotListing, error) { keys, err := v.listAllRemoteSnapshotKeys() if err != nil { @@ -202,11 +281,23 @@ func (v *Vaultik) collectRemoteSnapshots( unknown = unknown[:maxRemoteOnlyRows] } - listing.remoteOnly, listing.unreadable = v.describeRemoteOnlySnapshots(unknown) + listing.remoteOnly, listing.unreadable = v.describeRemoteOnlySnapshots( + unknown, jsonOutput) return listing, nil } +// listingWarning is a problem found with one remote snapshot, recorded +// rather than emitted on the spot. Manifest reads run concurrently and +// the writer chosen by warnWhileListing is not guaranteed to be safe +// for concurrent use, so warnings are held until every read has +// finished and then emitted in key order from a single goroutine. That +// also makes the warning order deterministic run to run. +type listingWarning struct { + msg string + args []any +} + // describeRemoteOnlySnapshots reads the manifest for each supplied // remote key and turns it into a table row, returning the rows and the // number of keys whose manifest could not be read. @@ -214,9 +305,12 @@ func (v *Vaultik) collectRemoteSnapshots( // A key whose manifest is missing or corrupt is skipped rather than // failing the listing: one bad snapshot directory must not hide every // other snapshot the user has. -func (v *Vaultik) describeRemoteOnlySnapshots(keys []string) ([]SnapshotInfo, int) { +func (v *Vaultik) describeRemoteOnlySnapshots( + keys []string, jsonOutput bool, +) ([]SnapshotInfo, int) { found := make([]SnapshotInfo, len(keys)) ok := make([]bool, len(keys)) + warnings := make([]*listingWarning, len(keys)) var group errgroup.Group @@ -224,15 +318,22 @@ func (v *Vaultik) describeRemoteOnlySnapshots(keys []string) ([]SnapshotInfo, in for i, key := range keys { group.Go(func() error { - info, err := v.remoteSnapshotInfo(key) + info, warning, err := v.remoteSnapshotInfo(key) if err != nil { - log.Warn("Could not describe remote snapshot", - "remote_key", key, "error", err) + warnings[i] = &listingWarning{ + msg: "Could not describe remote snapshot", + args: []any{"remote_key", key, "error", err}, + } - return nil + // Deliberately not returned: the failure is carried in + // warnings/ok and reported as a count. Returning it + // would cancel the group and let one bad snapshot + // directory hide every other snapshot the user has. + return nil //nolint:nilerr // see above } found[i] = info + warnings[i] = warning ok[i] = true return nil @@ -247,6 +348,10 @@ func (v *Vaultik) describeRemoteOnlySnapshots(keys []string) ([]SnapshotInfo, in unreadable := 0 for i := range keys { + if warnings[i] != nil { + v.warnWhileListing(jsonOutput, warnings[i].msg, warnings[i].args...) + } + if !ok[i] { unreadable++ @@ -269,19 +374,34 @@ func (v *Vaultik) describeRemoteOnlySnapshots(keys []string) ([]SnapshotInfo, in // the privacy property that hashing the key exists to provide (see // issue #81). The renderer marks the row as unnamed rather than // guessing. -func (v *Vaultik) remoteSnapshotInfo(remoteKey string) (SnapshotInfo, error) { +// +// The returned warning, when non-nil, is a problem worth telling the +// user about that was not bad enough to drop the row. It is returned +// rather than logged because this runs on a worker goroutine; see +// listingWarning. +func (v *Vaultik) remoteSnapshotInfo( + remoteKey string, +) (SnapshotInfo, *listingWarning, error) { manifest, err := v.downloadManifestByKey(remoteKey) if err != nil { - return SnapshotInfo{}, err + return SnapshotInfo{}, nil, err } + var warning *listingWarning + timestamp, err := time.Parse(time.RFC3339, manifest.Timestamp) if err != nil { // The snapshot is really there; an unparseable timestamp is not // reason enough to hide it. It sorts to the bottom as the zero // time. - log.Warn("Remote manifest has an unparseable timestamp", - "remote_key", remoteKey, "timestamp", manifest.Timestamp, "error", err) + warning = &listingWarning{ + msg: "Remote manifest has an unparseable timestamp", + args: []any{ + "remote_key", remoteKey, + "timestamp", manifest.Timestamp, + "error", err, + }, + } timestamp = time.Time{} } @@ -291,7 +411,7 @@ func (v *Vaultik) remoteSnapshotInfo(remoteKey string) (SnapshotInfo, error) { Timestamp: timestamp.UTC(), CompressedSize: manifest.TotalCompressedSize, LocallyTracked: false, - }, nil + }, warning, nil } // markRemotePresence records, for every row, whether its remote key was @@ -461,14 +581,16 @@ func (v *Vaultik) printSnapshotTable(snapshots []SnapshotInfo) error { } for _, snap := range snapshots { - id := formatRemoteOnlyID(snap.RemoteKey) - uncompressed := remoteOnlyCell - newChunks := remoteOnlyCell + var id, uncompressed, newChunks string if snap.LocallyTracked { id = snap.ID.String() uncompressed = formatBytes(snap.UncompressedSize) newChunks = formatBytes(snap.NewChunkSize) + } else { + id = formatRemoteOnlyID(snap.RemoteKey) + uncompressed = remoteOnlyCell + newChunks = remoteOnlyCell } _, err = fmt.Fprintf(w, "%s\t%s\t%s\t%s\t%s\n", diff --git a/internal/vaultik/snapshot_list_test.go b/internal/vaultik/snapshot_list_test.go index b5280ed..3547e77 100644 --- a/internal/vaultik/snapshot_list_test.go +++ b/internal/vaultik/snapshot_list_test.go @@ -6,7 +6,9 @@ import ( "database/sql" "encoding/json" "errors" + "fmt" "io" + "os" "strings" "sync" "testing" @@ -171,12 +173,24 @@ func (e *listEnv) addRemote( ) string { t.Helper() + return e.addRemoteRawTimestamp(t, snapshotID, + timestamp.UTC().Format(time.RFC3339)) +} + +// addRemoteRawTimestamp is addRemote with the manifest's timestamp field +// written verbatim, so the unparseable-timestamp path can be exercised +// with a value no time.Parse will accept. +func (e *listEnv) addRemoteRawTimestamp( + t *testing.T, snapshotID, timestamp string, +) string { + t.Helper() + remoteKey := snapshot.RemoteSnapshotKey(snapshotID) manifest := &snapshot.Manifest{ // Note: the hashed key, never the human ID. That is precisely // why a remote-only snapshot cannot be named. SnapshotID: remoteKey, - Timestamp: timestamp.UTC().Format(time.RFC3339), + Timestamp: timestamp, BlobCount: 1, TotalCompressedSize: fiveMegabytes, Blobs: []snapshot.BlobInfo{ @@ -431,6 +445,7 @@ func TestListSnapshots_UnreadableManifestDoesNotHideOthers(t *testing.T) { type listJSONRow struct { ID string `json:"id"` RemoteKey string `json:"remote_key"` + Timestamp string `json:"timestamp"` CompressedSize int64 `json:"compressed_size"` LocallyTracked bool `json:"locally_tracked"` RemotePresent *bool `json:"remote_present"` @@ -531,3 +546,256 @@ func TestListSnapshots_JSONUnreachableRemote(t *testing.T) { "could not list backup destination store") assert.Contains(t, env.stderr.String(), "permission denied") } + +// useNonUTCLocalZone points time.Local at a fixed non-UTC zone for the +// duration of the test. +// +// Snapshot timestamps are stored as bare Unix seconds, so the zone a +// reader decodes them in is a decode choice rather than stored data — +// and on a UTC host a wrong choice is invisible. This makes it visible: +// with time.Local at +07:13, a row decoded in local time renders 7h13m +// away from the same instant decoded in UTC. +// +// time.Local is process-global, so a test using this must not call +// t.Parallel. Go runs every non-parallel test to completion before +// resuming any parallel one, so the mutation is not observable from +// another test. +// +//nolint:gosmopolitan // pinning time.Local is the entire point here +func useNonUTCLocalZone(t *testing.T) { + t.Helper() + + const offsetSeconds = 7*60*60 + 13*60 + + previous := time.Local + time.Local = time.FixedZone("VaultikTest", offsetSeconds) + + t.Cleanup(func() { time.Local = previous }) +} + +// TestListSnapshots_TimestampsAreUTCOnNonUTCHost is the regression guard +// for the merged TIMESTAMP column. Local rows come from the index +// database and remote-only rows come from a manifest; both render +// through the same zone-less format string, so both have to be in the +// same zone or the column silently shows two different wall clocks for +// the same instant. +// +// This test fails on any host if either source stops normalizing to UTC, +// because it pins time.Local to a zone that is not UTC. +// +//nolint:paralleltest // pins process-global time.Local; see useNonUTCLocalZone +func TestListSnapshots_TimestampsAreUTCOnNonUTCHost(t *testing.T) { + log.Initialize(log.Config{}) + useNonUTCLocalZone(t) + + // One instant, rendered twice: once through a locally tracked + // snapshot and once through a snapshot only the destination store + // knows about. + instant := time.Date(2026, 3, 1, 10, 0, 0, 0, time.UTC) + + const wallClock = "2026-03-01 10:00:00" + + env := newListEnv(t) + env.addLocal(t, listLocalID, instant) + env.addRemote(t, listLocalID, instant) + remoteKey := env.addRemote(t, listRemoteID, instant) + + err := env.v.ListSnapshots(false) + require.NoError(t, err) + + out := env.stdout.String() + + assert.Contains(t, findTableRow(t, out, listLocalID), wallClock, + "a locally tracked row must render in UTC like every other row") + assert.Contains(t, + findTableRow(t, out, ""), wallClock) + + // The --json timestamp carries its zone explicitly, so rows from the + // two sources must be string-comparable as well. + jsonEnv := newListEnv(t) + jsonEnv.addLocal(t, listLocalID, instant) + jsonEnv.addRemote(t, listLocalID, instant) + jsonEnv.addRemote(t, listRemoteID, instant) + + err = jsonEnv.v.ListSnapshots(true) + require.NoError(t, err) + + rows := decodeListJSON(t, jsonEnv.stdout.String()) + require.Len(t, rows, 2) + + for _, row := range rows { + assert.Equal(t, "2026-03-01T10:00:00Z", row.Timestamp, + "--json timestamps must be comparable between row types") + } +} + +// TestListSnapshots_JSONReportsUnreadableManifests checks that a +// snapshot missing from the JSON document because its manifest could not +// be read is still announced. Table mode says so below the table; a +// machine consumer would otherwise see no difference between "that +// snapshot is not on the destination" and "that snapshot could not be +// read". +func TestListSnapshots_JSONReportsUnreadableManifests(t *testing.T) { + log.Initialize(log.Config{}) + t.Parallel() + + env := newListEnv(t) + + goodKey := env.addRemote(t, listRemoteID, + time.Date(2026, 3, 2, 11, 22, 33, 0, time.UTC)) + + badKey := snapshot.RemoteSnapshotKey("testhost_broken_2026-03-03T00:00:00Z") + err := env.store.Put(context.Background(), + "metadata/"+badKey+"/manifest.json.zst", + strings.NewReader("this is not a zstd stream")) + require.NoError(t, err) + + err = env.v.ListSnapshots(true) + require.NoError(t, err) + + rows := decodeListJSON(t, env.stdout.String()) + require.Len(t, rows, 1) + assert.Equal(t, goodKey, rows[0].RemoteKey) + + assert.Contains(t, env.stderr.String(), + "1 remote snapshot(s) could not be described", + "a row dropped from the JSON document must be announced somewhere") +} + +// maxRemoteOnlyRowsForTest mirrors the maxRemoteOnlyRows cap in the +// package under test, which is unexported. +const maxRemoteOnlyRowsForTest = 1000 + +// TestListSnapshots_JSONReportsTruncation covers the row cap in --json +// mode. Past the cap the document is a partial listing, and silent +// truncation of a listing whose whole purpose is disaster recovery is +// the wrong failure mode: the consumer least able to notice is exactly +// the one reading JSON. +func TestListSnapshots_JSONReportsTruncation(t *testing.T) { + log.Initialize(log.Config{}) + t.Parallel() + + env := newListEnv(t) + + timestamp := time.Date(2026, 3, 2, 11, 22, 33, 0, time.UTC) + + // One past the cap, so exactly one snapshot is omitted. + for i := range maxRemoteOnlyRowsForTest + 1 { + env.addRemote(t, fmt.Sprintf("otherhost_bulk_%04d", i), timestamp) + } + + err := env.v.ListSnapshots(true) + require.NoError(t, err) + + rows := decodeListJSON(t, env.stdout.String()) + assert.Len(t, rows, maxRemoteOnlyRowsForTest) + + assert.Contains(t, env.stderr.String(), "listing truncated") + assert.Contains(t, env.stderr.String(), "1 further remote-only") +} + +// captureProcessStdout redirects the process's own stdout to a pipe, +// rebuilds the global logger over it, runs fn, and returns everything +// written. +// +// internal/log builds its logger over os.Stdout at construction time and +// offers no injectable sink (issue #82), so a warning logged during a +// --json listing lands on the process's real stdout, not on any writer a +// test can inject. Capturing the file descriptor is therefore the only +// way a test can see what `snapshot list --json | jq` would see. +// +// Not parallel-safe: os.Stdout and the logger are process-global. +func captureProcessStdout(t *testing.T, fn func(stdout io.Writer)) string { + t.Helper() + + reader, writer, err := os.Pipe() + require.NoError(t, err) + + previous := os.Stdout + os.Stdout = writer + + // Rebuild the logger so it writes to the pipe rather than to the + // real stdout the test process was started with. + log.Initialize(log.Config{}) + + drained := make(chan string, 1) + + go func() { + var buf bytes.Buffer + + _, _ = io.Copy(&buf, reader) + + drained <- buf.String() + }() + + fn(writer) + + os.Stdout = previous + + require.NoError(t, writer.Close()) + + captured := <-drained + + require.NoError(t, reader.Close()) + + // Put the logger back on the restored stdout. + log.Initialize(log.Config{}) + + return captured +} + +// TestListSnapshots_JSONStdoutIsOnlyTheDocument is the regression guard +// for `snapshot list --json | jq` surviving a damaged destination store. +// +// Every stdout writer the command has — the JSON encoder, the UI, and +// the global logger — is pointed at one pipe here, exactly as they are +// pointed at one file descriptor in production. A single log line about +// a corrupt manifest ahead of the array is enough to break the parse, +// and that is what this asserts cannot happen. +// +//nolint:paralleltest // replaces os.Stdout and the global logger +func TestListSnapshots_JSONStdoutIsOnlyTheDocument(t *testing.T) { + env := newListEnv(t) + + goodKey := env.addRemote(t, listRemoteID, + time.Date(2026, 3, 2, 11, 22, 33, 0, time.UTC)) + + // A manifest that is not even a zstd stream. + badKey := snapshot.RemoteSnapshotKey("testhost_broken_2026-03-03T00:00:00Z") + err := env.store.Put(context.Background(), + "metadata/"+badKey+"/manifest.json.zst", + strings.NewReader("this is not a zstd stream")) + require.NoError(t, err) + + // And a manifest that decodes but carries a timestamp no parser will + // accept: the second warning on this path. + oddKey := env.addRemoteRawTimestamp(t, + "testhost_odd_2026-03-04T00:00:00Z", "the day before yesterday") + + captured := captureProcessStdout(t, func(stdout io.Writer) { + env.v.Stdout = stdout + env.v.UI = ui.NewWithColor(stdout, false) + + require.NoError(t, env.v.ListSnapshots(true)) + }) + + rows := decodeListJSON(t, captured) + require.Len(t, rows, 2, "the readable snapshots must both be listed") + + byKey := make(map[string]listJSONRow, len(rows)) + for _, row := range rows { + byKey[row.RemoteKey] = row + } + + assert.Contains(t, byKey, goodKey) + assert.Contains(t, byKey, oddKey, + "an unparseable timestamp must not hide the snapshot itself") + assert.NotContains(t, byKey, badKey) + + // Both warnings were emitted, on the stream that cannot corrupt the + // document. + stderr := env.stderr.String() + assert.Contains(t, stderr, "Could not describe remote snapshot") + assert.Contains(t, stderr, "Remote manifest has an unparseable timestamp") + assert.Contains(t, stderr, "1 remote snapshot(s) could not be described") +}