Compare commits

...
2 Commits
Author SHA1 Message Date
sneak 1adb856599 Report unknown blob figures for a snapshot whose manifest cannot be read (closes #272)
check / check (push) Canceled after 0s
When remote info could not read a snapshot's manifest, the orphan
figures were unknown but the snapshot's row still gave 0 blobs and 0 B,
in the table and in --json. The row's blob count and blob size are now
unknown, and null in --json.

A directory with no manifest, as an interrupted backup leaves, still
shows 0: the orphan figures count its blobs as orphaned, so it
references none.

The constant holding the "unknown" text is renamed from countUnknown to
unknownText, since it now also stands for a size.

Model: opus-5-5
2026-10-08 05:46:45 +00:00
clawbot c06c4d201b Keep the progress line of a multi-path snapshot within 100% (closes #271)
check / check (push) Canceled after 0s
One progress reporter spans every path of a snapshot. Its counts of
files and bytes processed run across all the paths, while the totals
they were divided by were reset to each path's own, so a second path
smaller than the first showed more than 100% and an ETA of `unknown`.
The totals now add up over the paths scanned so far. The rate behind
the ETA restarts when each path's scan phase ends, so that phase does
not lower the rate while the path is processed; until then the rate is
the previous path's. SetTotalSize is renamed AddTotalSize because it
now adds.

The issue says the ETA went negative; it was computed negative and
printed as `unknown`.

Model: opus-5-5
2026-10-08 07:29:11 +02:00
10 changed files with 340 additions and 68 deletions
+2 -1
View File
@@ -398,7 +398,8 @@ key is skipped with a warning and is not printed. If a listed
orphaned blob figures are reported as unknown; `--json` gives them as
`null`, lists the remote key of each unreadable manifest in
`unreadable_manifests` and counts the manifests under skipped names in
`skipped_manifest_count`.
`skipped_manifest_count`. An unreadable manifest also leaves its
snapshot's blob count and blob size unknown, `null` in `--json`.
* `--json`: Output as JSON
**`remote nuke`**: Delete every snapshot's metadata and every blob from the
+20
View File
@@ -22,6 +22,26 @@ the tag exists and is exercised; what is left is merging `next` to
# Completed Steps
- 2026-10-08: Made `remote info` report a snapshot's blob count and
blob size as unknown when its manifest cannot be read
([issue #272](https://git.eeqj.de/sneak/vaultik/issues/272)). The
orphan figures were already unknown in that case, but the snapshot's
row still gave 0 blobs and 0 B, in the table and in `--json`. The row
now reads `unknown` and `--json` gives `null`. A directory with no
manifest still shows 0, since the orphan figures count its blobs as
orphaned.
- 2026-10-08: Kept the progress line of a snapshot with more than one
path within 100%
([issue #271](https://git.eeqj.de/sneak/vaultik/issues/271)). The
bytes and files processed counted every path, but the totals they
were divided by held only the current path's, so a second path
smaller than the first showed more than 100% and an ETA of `unknown`.
The totals now add up over the paths scanned so far. The rate behind
the ETA restarts when each path's scan phase ends, so that phase does
not lower the rate while the path is processed; until then the rate
is the previous path's.
- 2026-10-08: Made a second `snapshot create` of one name succeed when
it starts in the same second as the first
([issue #270](https://git.eeqj.de/sneak/vaultik/issues/270)). The
+42 -26
View File
@@ -67,13 +67,17 @@ type ProgressStats struct {
BlobsUploaded atomic.Int64
BytesUploaded atomic.Int64
CurrentFile atomic.Value // stores string
TotalSize atomic.Int64 // Total size to process (set after scan phase)
TotalFiles atomic.Int64 // Total files to process in phase 2
ProcessStartTime atomic.Value // stores time.Time when processing starts
TotalSize atomic.Int64 // Size to process in the paths scanned so far
TotalFiles atomic.Int64 // Files to process in the paths scanned so far
StartTime time.Time
mu sync.RWMutex
lastDetailTime time.Time
// Guarded by mu: when the last scan phase ended, and
// BytesProcessed at that moment.
processStartTime time.Time
processStartBytes int64
// Upload tracking
CurrentUpload atomic.Value // stores *UploadInfo
lastChunkingTime time.Time // Track when we last showed chunking progress
@@ -148,10 +152,36 @@ func (pr *ProgressReporter) GetStats() *ProgressStats {
return pr.stats
}
// SetTotalSize sets the total size to process (after scan phase)
func (pr *ProgressReporter) SetTotalSize(size int64) {
pr.stats.TotalSize.Store(size)
pr.stats.ProcessStartTime.Store(time.Now().UTC())
// AddTotalSize adds the size one path of the snapshot has to process to
// the total, once that path's scan phase is done, and starts measuring
// the processing rate again. The processed counts run across every path,
// so the total does too. Restarting the rate keeps a path's scan phase,
// which processes nothing, out of the rate while that path is processed.
// During a later path's scan phase the rate is still the previous
// path's, and falls as that scan goes on.
func (pr *ProgressReporter) AddTotalSize(size int64) {
pr.stats.TotalSize.Add(size)
pr.stats.mu.Lock()
defer pr.stats.mu.Unlock()
pr.stats.processStartTime = time.Now().UTC()
pr.stats.processStartBytes = pr.stats.BytesProcessed.Load()
}
// processRate returns the bytes processed per second since the last scan
// phase ended, or 0 before the first path's scan phase is done.
func (s *ProgressStats) processRate() float64 {
s.mu.RLock()
defer s.mu.RUnlock()
if s.processStartTime.IsZero() {
return 0
}
processed := s.BytesProcessed.Load() - s.processStartBytes
return float64(processed) / time.Since(s.processStartTime).Seconds()
}
// Helper functions
@@ -357,20 +387,13 @@ func (pr *ProgressReporter) printSummaryStatus() {
// Calculate ETA if we have total size and are processing
etaStr := ""
if totalSize > 0 && bytesProcessed > 0 {
processStart, ok := pr.stats.ProcessStartTime.Load().(time.Time)
if ok && !processStart.IsZero() {
processElapsed := time.Since(processStart)
rate := float64(bytesProcessed) / processElapsed.Seconds()
if rate > 0 {
processRate := pr.stats.processRate()
if totalSize > 0 && processRate > 0 {
remainingBytes := totalSize - bytesProcessed
remainingSeconds := float64(remainingBytes) / rate
remainingSeconds := float64(remainingBytes) / processRate
eta := time.Duration(remainingSeconds * float64(time.Second))
etaStr = " | ETA: " + formatDuration(eta)
}
}
}
rate := float64(bytesScanned+bytesSkipped) / elapsed.Seconds()
@@ -421,13 +444,8 @@ func (pr *ProgressReporter) printDetailedStatus() {
log.Info("Elapsed time", "duration", formatDuration(elapsed))
// Calculate and show ETA if we have data
if totalSize > 0 && bytesProcessed > 0 {
processStart, ok := pr.stats.ProcessStartTime.Load().(time.Time)
if ok && !processStart.IsZero() {
processElapsed := time.Since(processStart)
processRate := float64(bytesProcessed) / processElapsed.Seconds()
if processRate > 0 {
processRate := pr.stats.processRate()
if totalSize > 0 && processRate > 0 {
remainingBytes := totalSize - bytesProcessed
remainingSeconds := float64(remainingBytes) / processRate
eta := time.Duration(remainingSeconds * float64(time.Second))
@@ -439,8 +457,6 @@ func (pr *ProgressReporter) printDetailedStatus() {
"rate", humanize.Bytes(uint64(processRate))+"/s",
"eta", formatDuration(eta))
}
}
}
log.Info("Files processed",
"scanned", filesScanned,
+54
View File
@@ -0,0 +1,54 @@
//nolint:testpackage // exercises the unexported processRate helper
package snapshot
import (
"testing"
"time"
)
// TestProcessRateNotLoweredByLaterScanPhase feeds the reporter two paths
// that each take 10 seconds to process, the second after a 30-second scan
// phase. That scan phase processes nothing, so the rate while the second
// path is processed must be that path's own.
func TestProcessRateNotLoweredByLaterScanPhase(t *testing.T) {
t.Parallel()
const (
pathSize = 1000
processingTime = 10 * time.Second
scanTime = 30 * time.Second
)
// Never started, but Stop releases its tickers and signal handler.
progress := NewProgressReporter()
defer progress.Stop()
stats := progress.GetStats()
// Moves the processing start time back instead of sleeping.
elapse := func(d time.Duration) {
stats.mu.Lock()
defer stats.mu.Unlock()
stats.processStartTime = stats.processStartTime.Add(-d)
}
progress.AddTotalSize(pathSize)
stats.BytesProcessed.Add(pathSize)
elapse(processingTime)
elapse(scanTime)
progress.AddTotalSize(pathSize)
stats.BytesProcessed.Add(pathSize)
elapse(processingTime)
want := pathSize / processingTime.Seconds()
got := stats.processRate()
// The test's own run time adds to the elapsed time, so got is a hair
// under want.
if got > want || got < want*0.99 {
t.Errorf("rate while the second path is processed is %.1f bytes/s, "+
"want %.1f", got, want)
}
}
+94
View File
@@ -0,0 +1,94 @@
package snapshot_test
import (
"context"
"path/filepath"
"strings"
"testing"
"github.com/spf13/afero"
"sneak.berlin/go/vaultik/internal/database"
"sneak.berlin/go/vaultik/internal/snapshot"
)
// TestProgressPercentWithSecondPathSmaller backs up two paths with one
// scanner, as a snapshot with two paths does, the second path smaller
// than the first. The progress line divides the bytes processed by the
// total size, so both must count both paths to stay within 100%.
func TestProgressPercentWithSecondPathSmaller(t *testing.T) {
t.Parallel()
fs := afero.NewMemMapFs()
files := map[string]string{
"/large/one.txt": strings.Repeat("1", 4000),
"/large/two.txt": strings.Repeat("2", 4000),
"/small/three.txt": strings.Repeat("3", 1000),
}
for path, content := range files {
err := fs.MkdirAll(filepath.Dir(path), 0755)
if err != nil {
t.Fatalf("mkdir: %v", err)
}
err = afero.WriteFile(fs, path, []byte(content), 0644)
if err != nil {
t.Fatalf("write %s: %v", path, err)
}
}
db, err := database.NewTestDB()
if err != nil {
t.Fatalf("create test db: %v", err)
}
t.Cleanup(func() {
cerr := db.Close()
if cerr != nil {
t.Errorf("close db: %v", cerr)
}
})
repos := database.NewRepositories(db)
scanner := snapshot.NewScanner(snapshot.ScannerConfig{
FS: fs,
ChunkSize: int64(1024 * 16),
Repositories: repos,
MaxBlobSize: int64(1024 * 1024),
CompressionLevel: 3,
AgeRecipients: []string{testAgePublicKey},
EnableProgress: true,
})
// Never started, but Stop releases its tickers and signal handler.
progress := scanner.GetProgress()
defer progress.Stop()
ctx := context.Background()
snapshotID := "test-snapshot-progress"
createTestSnapshotRecord(ctx, t, repos, snapshotID)
for _, path := range []string{"/large", "/small"} {
_, err := scanner.Scan(ctx, path, snapshotID)
if err != nil {
t.Fatalf("scanning %s: %v", path, err)
}
}
stats := progress.GetStats()
// Directories count toward the total size but produce no chunks, so
// the percentage ends just under 100%.
percent := float64(stats.BytesProcessed.Load()) /
float64(stats.TotalSize.Load()) * 100
if percent > 100 {
t.Errorf("progress after both paths is %.1f%%, want at most 100%%",
percent)
}
if stats.FilesProcessed.Load() != stats.TotalFiles.Load() {
t.Errorf("progress after both paths is %d of %d files, want all",
stats.FilesProcessed.Load(), stats.TotalFiles.Load())
}
}
+2 -2
View File
@@ -407,8 +407,8 @@ func (s *Scanner) summarizeScanPhase(
}
if s.progress != nil {
s.progress.SetTotalSize(totalSizeToProcess)
s.progress.GetStats().TotalFiles.Store(int64(len(filesToProcess)))
s.progress.AddTotalSize(totalSizeToProcess)
s.progress.GetStats().TotalFiles.Add(int64(len(filesToProcess)))
}
log.Info("Phase 1 complete",
+24 -6
View File
@@ -181,8 +181,11 @@ type SnapshotMetadataInfo struct {
ManifestSize int64 `json:"manifest_size"`
DatabaseSize int64 `json:"database_size"`
TotalSize int64 `json:"total_size"`
BlobCount int `json:"blob_count"`
BlobsSize int64 `json:"blobs_size"`
// Both stay nil (null in the JSON) when the snapshot's manifest was
// listed but could not be read.
BlobCount *int `json:"blob_count"`
BlobsSize *int64 `json:"blobs_size"`
// Set when the listing holds this snapshot's manifest.json.zst. A
// backup interrupted before its manifest upload leaves a directory
@@ -380,6 +383,10 @@ func (v *Vaultik) collectReferencedBlobsFromManifests(
for _, snapshotID := range snapshotIDs {
info := snapshotMetadata[snapshotID]
if !info.hasManifest {
// The orphan figures count this directory's blobs as
// orphaned, so it references none.
info.BlobCount, info.BlobsSize = new(int), new(int64)
continue
}
@@ -395,7 +402,7 @@ func (v *Vaultik) collectReferencedBlobsFromManifests(
continue
}
info.BlobCount = manifest.BlobCount
blobCount := manifest.BlobCount
var blobsSize int64
@@ -404,7 +411,8 @@ func (v *Vaultik) collectReferencedBlobsFromManifests(
blobsSize += blob.CompressedSize
}
info.BlobsSize = blobsSize
info.BlobCount = &blobCount
info.BlobsSize = &blobsSize
}
return referencedBlobs, unreadable
@@ -516,13 +524,23 @@ func (v *Vaultik) printRemoteInfoTable(result *RemoteInfoResult) {
v.stdoutf("%s", separator)
for _, info := range result.Snapshots {
blobCount := unknownText
if info.BlobCount != nil {
blobCount = humanize.Comma(int64(*info.BlobCount))
}
blobsSize := unknownText
if info.BlobsSize != nil {
blobsSize = ubytes(*info.BlobsSize)
}
v.stdoutf(rowFormat,
truncateString(info.SnapshotID, snapshotIDColWidth),
ubytes(info.ManifestSize),
ubytes(info.DatabaseSize),
ubytes(info.TotalSize),
humanize.Comma(int64(info.BlobCount)),
ubytes(info.BlobsSize),
blobCount,
blobsSize,
)
}
+2 -2
View File
@@ -42,7 +42,7 @@ func TestTableCountForReportSurfacesReadFailure(t *testing.T) {
assert.Nil(t, missing, "a failed read is unknown, not a count")
// The rendered count for a failed read must say unknown, never 0.
assert.Equal(t, countUnknown, countText(missing))
assert.Equal(t, unknownText, countText(missing))
assert.NotEqual(t, "0", countText(missing))
}
@@ -57,7 +57,7 @@ func TestCountTextDistinguishesEmptyFromUnknown(t *testing.T) {
assert.Equal(t, "0", countText(&zero))
assert.Equal(t, "7", countText(&seven))
assert.Equal(t, countUnknown, countText(nil))
assert.Equal(t, unknownText, countText(nil))
}
// TestCountDiffUnknownWhenEitherSideUnknown checks that a delta computed
+69
View File
@@ -4,6 +4,7 @@ import (
"bytes"
"context"
"encoding/json"
"strings"
"testing"
"time"
@@ -69,6 +70,74 @@ func TestRemoteInfo_UnreadableManifestLeavesOrphansUnknown(t *testing.T) {
assert.Equal(t, []any{unreadableKey}, doc["unreadable_manifests"])
}
// TestRemoteInfo_UnreadableManifestLeavesSnapshotBlobsUnknown checks
// that the row of a snapshot whose manifest cannot be read gives its
// blob count and blob size as unknown in the table and as null in
// --json, not as 0. A directory without a manifest still shows 0: the
// orphan figures count its blobs as orphaned, so it references none.
func TestRemoteInfo_UnreadableManifestLeavesSnapshotBlobsUnknown(t *testing.T) {
log.Initialize(log.Config{})
t.Parallel()
env := newListEnv(t)
readableKey := env.addRemote(t, listRemoteID,
time.Date(2026, 3, 2, 0, 0, 0, 0, time.UTC))
unreadableKey := snapshot.RemoteSnapshotKey(listLocalID)
require.NoError(t, env.store.Put(context.Background(),
"metadata/"+unreadableKey+"/manifest.json.zst",
bytes.NewReader([]byte("not a valid manifest"))))
noManifestKey := snapshot.RemoteSnapshotKey("testhost_home_2026-03-03T10:00:00Z")
require.NoError(t, env.store.Put(context.Background(),
"metadata/"+noManifestKey+"/db.zst.age",
bytes.NewReader([]byte("not a valid database"))))
require.NoError(t, env.v.RemoteInfo(false))
// The table truncates the remote key, so a row is found by a prefix.
wantUnknown := map[string]int{readableKey: 0, unreadableKey: 2, noManifestKey: 0}
for key, want := range wantUnknown {
var row string
for line := range strings.SplitSeq(env.stdout.String(), "\n") {
if strings.HasPrefix(line, key[:16]) {
row = line
}
}
require.NotEmpty(t, row, "no table row for %s", key)
assert.Equal(t, want, strings.Count(row, "unknown"), "row: %q", row)
}
env.stdout.Reset()
require.NoError(t, env.v.RemoteInfo(true))
var doc struct {
Snapshots []map[string]any `json:"snapshots"`
}
require.NoError(t, json.Unmarshal(env.stdout.Bytes(), &doc))
require.Len(t, doc.Snapshots, len(wantUnknown))
for _, entry := range doc.Snapshots {
switch entry["snapshot_id"] {
case readableKey:
assert.InDelta(t, 1, entry["blob_count"], 0)
assert.InDelta(t, fiveMegabytes, entry["blobs_size"], 0)
case noManifestKey:
assert.InDelta(t, 0, entry["blob_count"], 0)
assert.InDelta(t, 0, entry["blobs_size"], 0)
default:
assert.Equal(t, unreadableKey, entry["snapshot_id"])
assert.Contains(t, entry, "blob_count")
assert.Nil(t, entry["blob_count"])
assert.Contains(t, entry, "blobs_size")
assert.Nil(t, entry["blobs_size"])
}
}
}
// TestRemoteInfo_SkipsNonConformingMetadataName checks that a directory
// under metadata/ whose name is not a remote key is left out of the
// report, and that the orphan figures are unknown when it holds a
+4 -4
View File
@@ -1756,9 +1756,9 @@ func (v *Vaultik) PruneDatabase() (*PruneResult, error) {
return result, nil
}
// countUnknown is what a count reads as when its query could not be run,
// distinct from "0", which means the table really was empty.
const countUnknown = "unknown"
// unknownText is what a count or size reads as when it could not be
// determined, distinct from "0", which is a real zero.
const unknownText = "unknown"
// tableCountForReport returns the row count of a table for the prune
// summary, or nil if the count could not be read. A read failure is
@@ -1795,7 +1795,7 @@ func countDiff(before, after *int64) *int64 {
// one that could not be queried.
func countText(count *int64) string {
if count == nil {
return countUnknown
return unknownText
}
return strconv.FormatInt(*count, 10)