Fix timezone drift and --json truncation in snapshot list (closes #64)
All checks were successful
check / check (pull_request) Successful in 2m24s

Three defects in the merged listing path, all found in review.

1. The TIMESTAMP column mixed two timezones. Remote-only rows render
   timestamp.UTC(); local rows come from ListRecent, whose scanner
   decoded Unix seconds in the host's local zone, unlike the two other
   snapshot scanners in that file. Both render through the same
   zone-less format string, so on a non-UTC host the same snapshot
   showed one time when locally tracked and another when remote-only,
   in the same column, with nothing to indicate why.

   Normalized at the point the timestamp enters the domain rather than
   at the display layer: scanSnapshotRows now decodes in UTC like its
   siblings, and GetIncompleteByHostname's copy of that loop was folded
   onto the shared scanner so the three call sites cannot drift apart
   again.

2. --json silently truncated. The early return skipped reportListDrift,
   so neither the 1000-row cap nor the unreadable-manifest count reached
   a machine consumer: past the cap the document was short with no
   signal at all. Both counts now go to stderr, where the
   unreachable-destination warning already goes. The document's shape is
   deliberately unchanged, so existing consumers keep parsing.

3. The --json stderr workaround was half-applied. Two per-snapshot
   log.Warn calls on the same new path were left unguarded, and the
   logger writes to stdout at default level, so one corrupt manifest put
   a log line ahead of the document and broke `| jq`. Both now route
   through the same JSON-aware writer. They are also collected during
   the concurrent manifest reads and emitted afterwards in key order,
   since that writer is not safe for concurrent use. Still a local
   workaround; the logger itself is issue #82.

Also from review, non-blocking: the destination-listing failure is no
longer printed twice in table mode, the identifier cell is no longer
computed and discarded for locally tracked rows, and the merge sort is
stable so that rows sharing the zero-timestamp fallback keep a
deterministic order.

Tests: each fix has a test that fails without it. The timezone tests
pin time.Local to a non-UTC zone and assert Location identity, so they
would have caught this on the UTC host where it was missed. The JSON
stdout test redirects the process's own stdout to a pipe and rebuilds
the logger over it, so it can actually observe a log line landing on
stdout ahead of the document rather than asserting on an injected
buffer the log never reaches.
This commit is contained in:
2026-08-09 05:21:43 +00:00
parent 0e2929d75d
commit 9a45221b79
5 changed files with 548 additions and 60 deletions

16
TODO.md
View File

@@ -36,8 +36,20 @@ or delete the branch.
`reportRemoteDrift` collapsed into the merged view. Every remote `reportRemoteDrift` collapsed into the merged view. Every remote
manifest read in the codebase now goes through manifest read in the codebase now goes through
`downloadManifestByKey`, so issue #81 has one call site to change. `downloadManifestByKey`, so issue #81 has one call site to change.
Verified with `script/cibuild` and end to end against a `file://` Review rework: snapshot timestamps now normalize to UTC in
destination with no secret key present. `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). - 2026-08-09: Closed the gap between `make lint` and CI (issue #78).
`script/lint` now runs the digest-pinned `golangci-lint` image taken `script/lint` now runs the digest-pinned `golangci-lint` image taken
from the `Dockerfile` lint stage, which is the single source of truth from the `Dockerfile` lint stage, which is the single source of truth

View File

@@ -609,43 +609,9 @@ func (r *SnapshotRepository) GetIncompleteByHostname(
} }
}() }()
var snapshots []*Snapshot // Same column set as every other multi-row snapshot query, so the
// shared scanner applies — including its timestamp normalization.
for rows.Next() { return r.scanSnapshotRows(rows)
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()
} }
// Delete removes a snapshot record // 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) 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 { if completedAtUnix != nil {
t := time.Unix(*completedAtUnix, 0) t := time.Unix(*completedAtUnix, 0).UTC()
snapshot.CompletedAt = &t snapshot.CompletedAt = &t
} }

View File

@@ -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) { func TestSnapshotRepositoryNotFound(t *testing.T) {
t.Parallel() t.Parallel()

View File

@@ -87,7 +87,7 @@ func (v *Vaultik) ListSnapshots(jsonOutput bool) error {
snapshots = append(snapshots, info) snapshots = append(snapshots, info)
} }
listing, remoteErr := v.collectRemoteSnapshots(localKeys) listing, remoteErr := v.collectRemoteSnapshots(localKeys, jsonOutput)
if remoteErr != nil { if remoteErr != nil {
v.warnRemoteListingFailed(remoteErr, jsonOutput) v.warnRemoteListingFailed(remoteErr, jsonOutput)
} else { } else {
@@ -95,11 +95,19 @@ func (v *Vaultik) ListSnapshots(jsonOutput bool) error {
markRemotePresence(snapshots, listing.keys) 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) return snapshots[i].Timestamp.After(snapshots[j].Timestamp)
}) })
if jsonOutput { if jsonOutput {
if remoteErr == nil {
v.reportJSONListingLimits(listing)
}
encoder := json.NewEncoder(v.Stdout) encoder := json.NewEncoder(v.Stdout)
encoder.SetIndent("", " ") encoder.SetIndent("", " ")
@@ -138,11 +146,79 @@ func (v *Vaultik) warnRemoteListingFailed(err error, jsonOutput bool) {
return 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.Warningf("Could not list backup destination store: %v.", err)
v.UI.Infof("Showing snapshots from the local index only.") 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 // remoteSnapshotListing is the result of one pass over the destination
// store's metadata/ prefix. // store's metadata/ prefix.
type remoteSnapshotListing struct { type remoteSnapshotListing struct {
@@ -171,8 +247,11 @@ type remoteSnapshotListing struct {
// Manifest reads scale only with the number of snapshots the local // Manifest reads scale only with the number of snapshots the local
// index does not already know about, and are capped at // index does not already know about, and are capped at
// maxRemoteOnlyRows. // maxRemoteOnlyRows.
//
// jsonOutput only selects where per-snapshot warnings are written; see
// warnWhileListing.
func (v *Vaultik) collectRemoteSnapshots( func (v *Vaultik) collectRemoteSnapshots(
localKeys map[string]bool, localKeys map[string]bool, jsonOutput bool,
) (*remoteSnapshotListing, error) { ) (*remoteSnapshotListing, error) {
keys, err := v.listAllRemoteSnapshotKeys() keys, err := v.listAllRemoteSnapshotKeys()
if err != nil { if err != nil {
@@ -202,11 +281,23 @@ func (v *Vaultik) collectRemoteSnapshots(
unknown = unknown[:maxRemoteOnlyRows] unknown = unknown[:maxRemoteOnlyRows]
} }
listing.remoteOnly, listing.unreadable = v.describeRemoteOnlySnapshots(unknown) listing.remoteOnly, listing.unreadable = v.describeRemoteOnlySnapshots(
unknown, jsonOutput)
return listing, nil 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 // describeRemoteOnlySnapshots reads the manifest for each supplied
// remote key and turns it into a table row, returning the rows and the // remote key and turns it into a table row, returning the rows and the
// number of keys whose manifest could not be read. // 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 // A key whose manifest is missing or corrupt is skipped rather than
// failing the listing: one bad snapshot directory must not hide every // failing the listing: one bad snapshot directory must not hide every
// other snapshot the user has. // 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)) found := make([]SnapshotInfo, len(keys))
ok := make([]bool, len(keys)) ok := make([]bool, len(keys))
warnings := make([]*listingWarning, len(keys))
var group errgroup.Group var group errgroup.Group
@@ -224,15 +318,22 @@ func (v *Vaultik) describeRemoteOnlySnapshots(keys []string) ([]SnapshotInfo, in
for i, key := range keys { for i, key := range keys {
group.Go(func() error { group.Go(func() error {
info, err := v.remoteSnapshotInfo(key) info, warning, err := v.remoteSnapshotInfo(key)
if err != nil { if err != nil {
log.Warn("Could not describe remote snapshot", warnings[i] = &listingWarning{
"remote_key", key, "error", err) 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 found[i] = info
warnings[i] = warning
ok[i] = true ok[i] = true
return nil return nil
@@ -247,6 +348,10 @@ func (v *Vaultik) describeRemoteOnlySnapshots(keys []string) ([]SnapshotInfo, in
unreadable := 0 unreadable := 0
for i := range keys { for i := range keys {
if warnings[i] != nil {
v.warnWhileListing(jsonOutput, warnings[i].msg, warnings[i].args...)
}
if !ok[i] { if !ok[i] {
unreadable++ unreadable++
@@ -269,19 +374,34 @@ func (v *Vaultik) describeRemoteOnlySnapshots(keys []string) ([]SnapshotInfo, in
// the privacy property that hashing the key exists to provide (see // the privacy property that hashing the key exists to provide (see
// issue #81). The renderer marks the row as unnamed rather than // issue #81). The renderer marks the row as unnamed rather than
// guessing. // 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) manifest, err := v.downloadManifestByKey(remoteKey)
if err != nil { if err != nil {
return SnapshotInfo{}, err return SnapshotInfo{}, nil, err
} }
var warning *listingWarning
timestamp, err := time.Parse(time.RFC3339, manifest.Timestamp) timestamp, err := time.Parse(time.RFC3339, manifest.Timestamp)
if err != nil { if err != nil {
// The snapshot is really there; an unparseable timestamp is not // The snapshot is really there; an unparseable timestamp is not
// reason enough to hide it. It sorts to the bottom as the zero // reason enough to hide it. It sorts to the bottom as the zero
// time. // time.
log.Warn("Remote manifest has an unparseable timestamp", warning = &listingWarning{
"remote_key", remoteKey, "timestamp", manifest.Timestamp, "error", err) msg: "Remote manifest has an unparseable timestamp",
args: []any{
"remote_key", remoteKey,
"timestamp", manifest.Timestamp,
"error", err,
},
}
timestamp = time.Time{} timestamp = time.Time{}
} }
@@ -291,7 +411,7 @@ func (v *Vaultik) remoteSnapshotInfo(remoteKey string) (SnapshotInfo, error) {
Timestamp: timestamp.UTC(), Timestamp: timestamp.UTC(),
CompressedSize: manifest.TotalCompressedSize, CompressedSize: manifest.TotalCompressedSize,
LocallyTracked: false, LocallyTracked: false,
}, nil }, warning, nil
} }
// markRemotePresence records, for every row, whether its remote key was // 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 { for _, snap := range snapshots {
id := formatRemoteOnlyID(snap.RemoteKey) var id, uncompressed, newChunks string
uncompressed := remoteOnlyCell
newChunks := remoteOnlyCell
if snap.LocallyTracked { if snap.LocallyTracked {
id = snap.ID.String() id = snap.ID.String()
uncompressed = formatBytes(snap.UncompressedSize) uncompressed = formatBytes(snap.UncompressedSize)
newChunks = formatBytes(snap.NewChunkSize) 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", _, err = fmt.Fprintf(w, "%s\t%s\t%s\t%s\t%s\n",

View File

@@ -6,7 +6,9 @@ import (
"database/sql" "database/sql"
"encoding/json" "encoding/json"
"errors" "errors"
"fmt"
"io" "io"
"os"
"strings" "strings"
"sync" "sync"
"testing" "testing"
@@ -171,12 +173,24 @@ func (e *listEnv) addRemote(
) string { ) string {
t.Helper() 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) remoteKey := snapshot.RemoteSnapshotKey(snapshotID)
manifest := &snapshot.Manifest{ manifest := &snapshot.Manifest{
// Note: the hashed key, never the human ID. That is precisely // Note: the hashed key, never the human ID. That is precisely
// why a remote-only snapshot cannot be named. // why a remote-only snapshot cannot be named.
SnapshotID: remoteKey, SnapshotID: remoteKey,
Timestamp: timestamp.UTC().Format(time.RFC3339), Timestamp: timestamp,
BlobCount: 1, BlobCount: 1,
TotalCompressedSize: fiveMegabytes, TotalCompressedSize: fiveMegabytes,
Blobs: []snapshot.BlobInfo{ Blobs: []snapshot.BlobInfo{
@@ -431,6 +445,7 @@ func TestListSnapshots_UnreadableManifestDoesNotHideOthers(t *testing.T) {
type listJSONRow struct { type listJSONRow struct {
ID string `json:"id"` ID string `json:"id"`
RemoteKey string `json:"remote_key"` RemoteKey string `json:"remote_key"`
Timestamp string `json:"timestamp"`
CompressedSize int64 `json:"compressed_size"` CompressedSize int64 `json:"compressed_size"`
LocallyTracked bool `json:"locally_tracked"` LocallyTracked bool `json:"locally_tracked"`
RemotePresent *bool `json:"remote_present"` RemotePresent *bool `json:"remote_present"`
@@ -531,3 +546,256 @@ func TestListSnapshots_JSONUnreachableRemote(t *testing.T) {
"could not list backup destination store") "could not list backup destination store")
assert.Contains(t, env.stderr.String(), "permission denied") 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, "<remote only:"+remoteKey[:12]+">"), 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")
}