Compare commits

...
Author SHA1 Message Date
clawbot 005927a7fc Print snapshot list and purge sizes like every other command (closes #312)
check / check (push) Waiting to run
`snapshot list`, the `snapshot purge` listing and the `bytes` value in
terminal log lines divided by 1024 while labelling the result KB or MB,
so 6,329,198 bytes read 6.0 MB there and 6.3 MB in every other command.
All three now use humanize.Bytes, as the rest of the program does, and
the 1024-based helper in internal/vaultik is removed.

The size shared by the list tests is now 5,000,000 bytes, which the two
ways of counting print differently.

Judgement call: the log handler's copy of the formatter is changed too,
since the issue asks that every command print a byte count the same way.

Model: opus-5-5
2026-10-13 16:22:03 +02:00
clawbot 09a0c01c43 Stop a stalled blob read when restore or deep verify is interrupted (closes #325)
check / check (push) Waiting to run
Restore and deep verify looked for a cancel only between blobs, and the
file backend's reader ignores the context. A blob read stalled on a
slow USB stick or network share outlasted the 30-second shutdown
timeout, so the process exited before removing the decrypted snapshot
database and blob cache from the temp directory.

FetchBlob, through which both read every blob, now closes the storage
reader as soon as the context is cancelled, ending a blocked read on
any backend; Read then returns the context's error, not the closed
reader's.

Limitation: a read stuck in the kernel that closing cannot interrupt,
such as one on an unresponsive hard NFS mount, still cannot be stopped.

Model: opus-5-5
2026-10-13 15:48:00 +02:00
8 changed files with 223 additions and 39 deletions
+7 -10
View File
@@ -10,6 +10,8 @@ import (
"sync"
"time"
"unicode"
"github.com/dustin/go-humanize"
)
// groupSeparator joins an open group path to an attribute key. This
@@ -304,18 +306,13 @@ func formatDuration(d time.Duration) string {
}
}
// formatBytes formats bytes in a human-readable way
// formatBytes formats a byte count with humanize.Bytes, as every command
// prints one. humanize.Bytes takes no negative count, so one is printed
// as it is.
func formatBytes(b int64) string {
const unit = 1024
if b < unit {
if b < 0 {
return fmt.Sprintf("%d B", b)
}
div, exp := int64(unit), 0
for n := b / unit; n >= unit; n /= unit {
div *= unit
exp++
}
return fmt.Sprintf("%.1f %cB", float64(b)/float64(div), "KMGTPE"[exp])
return humanize.Bytes(uint64(b))
}
+5 -4
View File
@@ -200,7 +200,8 @@ func TestTTYHandlerWithGroupQualifiesKeys(t *testing.T) {
func TestTTYHandlerByteFormattingSurvivesGrouping(t *testing.T) {
t.Parallel()
const oneAndAHalfKiB = 1536
// Printed as "1.0 MB", in powers of 1000 like every other byte count.
const oneMegabyte = 1_000_000
for name, testCase := range map[string]struct {
derive func(*slog.Logger) *slog.Logger
@@ -223,13 +224,13 @@ func TestTTYHandlerByteFormattingSurvivesGrouping(t *testing.T) {
var buf bytes.Buffer
logger := slog.New(log.NewTTYHandler(&buf, debugHandlerOptions()))
testCase.derive(logger).Info("uploaded", "bytes", oneAndAHalfKiB)
testCase.derive(logger).Info("uploaded", "bytes", oneMegabyte)
line := ansiEscape.ReplaceAllString(buf.String(), "")
assert.Contains(t, line, testCase.key+"=1.5 KB",
assert.Contains(t, line, testCase.key+"=1.0 MB",
"a byte count must be human-readable however it is qualified")
assert.NotContains(t, line, strconv.Itoa(oneAndAHalfKiB),
assert.NotContains(t, line, strconv.Itoa(oneMegabyte),
"the raw number must not survive the formatting")
})
}
+45 -1
View File
@@ -103,6 +103,8 @@ func (v *Vaultik) FetchAndDecryptBlob(
}
// FetchBlob downloads a blob and returns a reader for the encrypted data.
// The reader is closed as soon as ctx is cancelled, which ends a read
// blocked inside it.
func (v *Vaultik) FetchBlob(
ctx context.Context, blobHash string,
) (io.ReadCloser, error) {
@@ -120,5 +122,47 @@ func (v *Vaultik) FetchBlob(
return nil, fmt.Errorf("downloading blob %s: %w", shortHash(blobHash), err)
}
return rc, nil
return newCloseOnCancelReader(ctx, rc), nil
}
// closeOnCancelReader closes the reader it wraps when ctx is cancelled.
// Not every backend's reader stops on cancel by itself (the file
// backend's does not), and a read stalled on a slow or hung source would
// otherwise outlast the shutdown timeout, so the process would exit
// before restore or deep verify removed its decrypted temporary files.
type closeOnCancelReader struct {
io.ReadCloser
ctx context.Context //nolint:containedctx // Read reports its error
stop func() bool
}
func newCloseOnCancelReader(
ctx context.Context, rc io.ReadCloser,
) *closeOnCancelReader {
return &closeOnCancelReader{
ReadCloser: rc,
ctx: ctx,
stop: context.AfterFunc(ctx, func() { _ = rc.Close() }),
}
}
// Read returns the context's error, not the closed reader's, once ctx
// has been cancelled.
func (r *closeOnCancelReader) Read(p []byte) (int, error) {
n, err := r.ReadCloser.Read(p)
if err != nil && r.ctx.Err() != nil {
return n, r.ctx.Err()
}
return n, err
}
// Close closes the wrapped reader, unless the cancel already closed it.
func (r *closeOnCancelReader) Close() error {
if !r.stop() {
return nil
}
return r.ReadCloser.Close()
}
-16
View File
@@ -89,22 +89,6 @@ type SnapshotInfo struct {
RemotePresent *bool `json:"remote_present"`
}
// formatBytes formats bytes in a human-readable format
func formatBytes(bytes int64) string {
const unit = 1024
if bytes < unit {
return fmt.Sprintf("%d B", bytes)
}
div, exp := int64(unit), 0
for n := bytes / unit; n >= unit; n /= unit {
div *= unit
exp++
}
return fmt.Sprintf("%.1f %cB", float64(bytes)/float64(div), "KMGTPE"[exp])
}
// parseSnapshotTimestamp extracts the timestamp from a snapshot ID
// Format: hostname_snapshotname_2026-01-12T14:41:15Z
func parseSnapshotTimestamp(snapshotID string) (time.Time, error) {
+118 -2
View File
@@ -142,14 +142,14 @@ func TestRestoreCleansTempDirOnInterrupt(t *testing.T) {
}
// scratchEntries returns the vaultik blob-cache and snapshot-database
// scratch entries currently present in dir.
// scratch entries (restore's and deep verify's) currently present in dir.
func scratchEntries(t *testing.T, dir string) []string {
t.Helper()
var matches []string
for _, pattern := range []string{
"vaultik-blobcache-*", "vaultik-restore-*",
"vaultik-blobcache-*", "vaultik-restore-*", "vaultik-verify-*",
} {
found, err := filepath.Glob(filepath.Join(dir, pattern))
require.NoError(t, err)
@@ -206,3 +206,119 @@ func TestRestoreSkipErrorsCancelDuringBlobDownload(t *testing.T) {
assert.NotContains(t, out.String(), srcPath,
"the cancel was reported as a failed file")
}
// stallingBlobStorer wraps a Storer so that every blob download hands
// over the first half of the blob and then stalls, ignoring the context,
// as a file:// blob on a hung USB stick or network share does. Only
// closing the returned reader ends the stall.
type stallingBlobStorer struct {
storage.Storer
once sync.Once
stalled chan struct{}
}
func newStallingBlobStorer(inner storage.Storer) *stallingBlobStorer {
return &stallingBlobStorer{Storer: inner, stalled: make(chan struct{})}
}
func (s *stallingBlobStorer) Get(
ctx context.Context, key string,
) (io.ReadCloser, error) {
rc, err := s.Storer.Get(ctx, key)
if err != nil || !strings.HasPrefix(key, "blobs/") {
return rc, err
}
blob, err := io.ReadAll(rc)
_ = rc.Close()
if err != nil {
return nil, err
}
// The writer is never closed, so once the first half has been read
// the next Read blocks until the reader is closed.
pr, pw := io.Pipe()
go func() {
_, _ = pw.Write(blob[:len(blob)/2])
s.once.Do(func() { close(s.stalled) })
}()
return pr, nil
}
// TestInterruptDuringStalledBlobReadCleansTempDir stops a restore and a
// deep verify while a blob read is stalled on a source that ignores the
// context. Stopping must end that read, so the operation unwinds and
// removes its decrypted scratch files well within the shutdown timeout
// (issue #325).
//
// Not parallel: it points TMPDIR at a private directory (via t.Setenv)
// so it can assert on exactly the scratch files the operation created.
func TestInterruptDuringStalledBlobReadCleansTempDir(t *testing.T) {
log.Initialize(log.Config{})
operations := map[string]func(v *Vaultik, snapshotID, targetDir string) error{
"restore": func(v *Vaultik, snapshotID, targetDir string) error {
return v.Restore(&RestoreOptions{
SnapshotID: snapshotID,
TargetDir: targetDir,
})
},
"deep verify": func(v *Vaultik, snapshotID, _ string) error {
return v.RunDeepVerify(snapshotID, &VerifyOptions{Deep: true})
},
}
for name, op := range operations {
t.Run(name, func(t *testing.T) {
fs := afero.NewOsFs()
root := t.TempDir()
// Random content, so the blob stays large enough to stall
// part-way through its compressed, encrypted body.
cfg, storer, snapshotID, _ := backupOneFile(context.Background(),
t, fs, root, "a.bin", randomBytes(t, 256*1024), 0o644)
scratch := filepath.Join(root, "scratch")
require.NoError(t, fs.MkdirAll(scratch, 0o755))
t.Setenv("TMPDIR", scratch)
stalling := newStallingBlobStorer(storer)
ctx, cancel := context.WithCancel(context.Background())
defer cancel()
v := newRestoreVaultik(ctx, cfg, stalling, fs)
v.cancel = cancel
var opErr error
stop := v.StartOperation(func() {
opErr = op(v, snapshotID, filepath.Join(root, "restored"))
})
select {
case <-stalling.stalled:
case <-time.After(30 * time.Second):
t.Fatal("the operation never reached a blob read")
}
require.NotEmpty(t, scratchEntries(t, scratch),
"expected decrypted scratch files to exist mid-read")
stopCtx, stopCancel := context.WithTimeout(
context.Background(), 10*time.Second)
defer stopCancel()
require.True(t, stop(stopCtx),
"stop timed out; the stalled blob read was not interrupted")
require.ErrorIs(t, opErr, context.Canceled)
require.Empty(t, scratchEntries(t, scratch),
"decrypted scratch files remained after the interrupt")
})
}
}
+1 -1
View File
@@ -633,7 +633,7 @@ func (v *Vaultik) confirmAndExecutePurge(
v.stdoutf(" %s (%s, %s)\n",
snap.ID,
snap.Timestamp.Format("2006-01-02 15:04:05"),
formatBytes(snap.CompressedSize))
ubytes(snap.CompressedSize))
}
}
+3 -3
View File
@@ -553,8 +553,8 @@ func (v *Vaultik) printSnapshotTable(snapshots []SnapshotInfo) error {
if snap.LocallyTracked {
id = snap.ID.String()
uncompressed = formatBytes(snap.UncompressedSize)
newChunks = formatBytes(snap.NewChunkSize)
uncompressed = ubytes(snap.UncompressedSize)
newChunks = ubytes(snap.NewChunkSize)
} else {
id = formatRemoteOnlyID(snap.RemoteKey)
uncompressed = remoteOnlyCell
@@ -564,7 +564,7 @@ func (v *Vaultik) printSnapshotTable(snapshots []SnapshotInfo) error {
_, err = fmt.Fprintf(w, "%s\t%s\t%s\t%s\t%s\n",
id,
snap.Timestamp.Format("2006-01-02 15:04:05"),
formatBytes(snap.CompressedSize),
ubytes(snap.CompressedSize),
uncompressed,
newChunks)
if err != nil {
+44 -2
View File
@@ -212,8 +212,8 @@ const (
listConfiguredName = "home"
listLocalID = "testhost_home_2026-03-01T10:00:00Z"
listRemoteID = "otherhost_media_2026-03-02T11:22:33Z"
// fiveMegabytes formats as "5.0 MB" through formatBytes.
fiveMegabytes = 5 * 1024 * 1024
// fiveMegabytes is printed as "5.0 MB" by every command.
fiveMegabytes = 5_000_000
)
// TestListSnapshots_RemoteWithoutSecretKey is the regression guard for
@@ -306,6 +306,48 @@ func TestListSnapshots_RemoteOnlyRowRendering(t *testing.T) {
"are not in the local index")
}
// TestSnapshotListAndPurgePrintSizesLikeRemoteInfo checks that the
// `snapshot list` table and the purge listing print a byte count the way
// `remote info` does: in powers of 1000, as the MB label says.
func TestSnapshotListAndPurgePrintSizesLikeRemoteInfo(t *testing.T) {
log.Initialize(log.Config{})
t.Parallel()
const wantSize = "5.0 MB" // fiveMegabytes
env := newListEnv(t)
// A remote-only snapshot: `snapshot list` and `remote info` both take
// its size from the manifest.
remoteKey := env.addRemote(t, listRemoteID,
time.Date(2026, 3, 2, 11, 22, 33, 0, time.UTC))
// A locally tracked snapshot of the same size for the purge to list.
// The purge prints the snapshot's blob size, the last argument here.
start := time.Date(2026, 3, 1, 10, 0, 0, 0, time.UTC)
env.addLocal(t, listLocalID, start)
env.addRemote(t, listLocalID, start)
require.NoError(t, env.v.Repositories.Snapshots.UpdateCounts(
context.Background(), nil, listLocalID, 0, 0, 0, 0, fiveMegabytes))
require.NoError(t, env.v.RemoteInfo(false))
assert.Contains(t, findTableRow(t, env.stdout.String(), remoteKey[:16]),
wantSize, "remote info")
env.stdout.Reset()
require.NoError(t, env.v.ListSnapshots(false))
assert.Contains(t, findTableRow(t, env.stdout.String(),
"<remote only:"+remoteKey[:12]+">"), wantSize, "snapshot list")
// Without --force and with nothing on stdin the purge lists what it
// would delete, reads no confirmation, and deletes nothing.
env.stdout.Reset()
require.NoError(t, env.v.PurgeSnapshotsWithOptions(
&vaultik.SnapshotPurgeOptions{OlderThan: "1d"}))
assert.Contains(t, findTableRow(t, env.stdout.String(), listLocalID),
wantSize, "snapshot purge")
}
// findTableRow returns the single output line containing needle.
func findTableRow(t *testing.T, out, needle string) string {
t.Helper()