Files
vaultik/internal/cli/entry_failure_once_test.go
T
sneak a23a8fffa3
check / check (push) Successful in 9m35s
Print a failed command's error once on stderr (closes #433)
A command that failed after startup wrote the error twice on stderr:
as an ERROR log record and as the final ERROR: line. The failure
handlers now log the failure at info level, so the record appears only
under --verbose or --debug, next to the records that led up to it.

A failed blob upload is logged at info level for the same reason. A
restore that stops on a file it cannot restore no longer logs that
file's error, which the final line carries; under --skip-errors it is
still logged.

Model: opus-5-5
2026-11-11 05:07:27 +00:00

206 lines
5.8 KiB
Go

package cli //nolint:testpackage // shares the fixtures and capture helpers
import (
"context"
"encoding/json"
"fmt"
"io"
"os"
"path/filepath"
"strings"
"testing"
"filippo.io/age"
"github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require"
"sneak.berlin/go/vaultik/internal/database"
"sneak.berlin/go/vaultik/internal/ui"
)
const (
// errorLinePrefix starts the final line that reports a failed command.
errorLinePrefix = "ERROR: "
flagVerbose = "--verbose"
cmdRestore = "restore"
// blobsDir is the directory of a destination store that holds the
// blobs.
blobsDir = "blobs"
)
// TestEntryFailureIsPrintedOnce runs commands that fail after startup
// against a destination they cannot use. `info` is not among them: it
// cannot fail after startup.
//
//nolint:paralleltest // replaces os.Args, os.Stdout, os.Stderr and the xdg globals
func TestEntryFailureIsPrintedOnce(t *testing.T) {
for _, command := range [][]string{
{cmdSnapshot, cmdCreate},
{cmdSnapshot, cmdRemove, someSnapshotID},
{cmdSnapshot, cmdVerify, someSnapshotID},
{cmdRemote, cmdInfo},
{cmdPrune, flagJSON},
} {
for _, verbose := range []bool{false, true} {
name := fmt.Sprintf("%s verbose=%t", strings.Join(command, " "), verbose)
t.Run(name, func(t *testing.T) {
requireErrorPrintedOnce(t, verbose, append([]string{flagConfig,
writeUnusableDestinationConfig(t)}, command...)...)
})
}
}
}
// TestEntryBlobUploadFailureIsPrintedOnce backs up to a destination
// whose blobs directory is a file, so the blob upload fails.
//
//nolint:paralleltest // replaces os.Args, os.Stdout, os.Stderr and the xdg globals
func TestEntryBlobUploadFailureIsPrintedOnce(t *testing.T) {
for _, verbose := range []bool{false, true} {
t.Run(fmt.Sprintf("verbose=%t", verbose), func(t *testing.T) {
configPath, storeDir := writeBackupConfig(t)
require.NoError(t, os.WriteFile(
filepath.Join(storeDir, blobsDir), nil, 0o600))
requireErrorPrintedOnce(t, verbose,
flagConfig, configPath, cmdSnapshot, cmdCreate)
})
}
}
// TestEntryBlobDownloadFailureIsPrintedOnce backs up, deletes the blobs
// from the destination, and restores, so the blob download fails.
//
//nolint:paralleltest // replaces os.Args, os.Stdout, os.Stderr and the xdg globals
func TestEntryBlobDownloadFailureIsPrintedOnce(t *testing.T) {
for _, verbose := range []bool{false, true} {
t.Run(fmt.Sprintf("verbose=%t", verbose), func(t *testing.T) {
configPath, storeDir := writeBackupConfigWithPrivateKey(t)
code, _, _ := runEntry(t,
flagConfig, configPath, cmdSnapshot, cmdCreate)
require.Equal(t, 0, code)
require.NoError(t, os.RemoveAll(filepath.Join(storeDir, blobsDir)))
requireErrorPrintedOnce(t, verbose, flagConfig, configPath,
cmdSnapshot, cmdRestore, onlySnapshotID(t, configPath), t.TempDir())
})
}
}
// requireErrorPrintedOnce runs Entry with args, adding --verbose when
// verbose is set. The command must fail, and stderr must carry its error
// once, as the final ERROR: line. A log record carrying the same error
// appears only under --verbose.
func requireErrorPrintedOnce(t *testing.T, verbose bool, args ...string) {
t.Helper()
if verbose {
args = append(args, flagVerbose)
}
code, _, stderr := runEntry(t, args...)
require.Equal(t, 1, code)
errorLine, records := failureOutput(t, stderr)
if !verbose {
assert.Zero(t, records,
"without --verbose no log record repeats the error:\n%s", stderr)
return
}
assert.NotZero(t, records,
"--verbose must keep the log record of %q", errorLine)
}
// failureOutput requires stderr to hold exactly one ERROR: line and
// returns it, with the number of log records whose error attribute is
// the error that line reports. stderr is a pipe here, so every log
// record is a JSON object on its own line.
func failureOutput(t *testing.T, stderr string) (string, int) {
t.Helper()
var (
errorLines []string
records []map[string]any
)
for line := range strings.Lines(stderr) {
var record map[string]any
if json.Unmarshal([]byte(line), &record) == nil {
records = append(records, record)
continue
}
if strings.Contains(line, errorLinePrefix) {
errorLines = append(errorLines, strings.TrimSpace(line))
}
}
require.Len(t, errorLines, 1,
"the error must be printed once as an ERROR: line:\n%s", stderr)
// An error can run over several lines; the ERROR: line holds the
// first of them.
repeats := 0
for _, record := range records {
failure, ok := record["error"].(string)
firstLine, _, _ := strings.Cut(failure, "\n")
if ok && strings.Contains(errorLines[0], firstLine) {
repeats++
}
}
return errorLines[0], repeats
}
// writeBackupConfigWithPrivateKey builds what writeBackupConfig builds,
// with a generated key pair in place of its recipient. The config also
// holds the private key, so that restore can decrypt the backup. Returns
// the config path and the store directory.
func writeBackupConfigWithPrivateKey(t *testing.T) (string, string) {
t.Helper()
configPath, storeDir := writeBackupConfig(t)
identity, err := age.GenerateX25519Identity()
require.NoError(t, err)
out := ui.NewWithColor(io.Discard, false)
require.NoError(t, writeConfigSet(out, configPath,
"age_recipients.0", identity.Recipient().String()))
require.NoError(t, writeConfigSet(out, configPath,
"age_secret_key", identity.String()))
return configPath, storeDir
}
// onlySnapshotID returns the ID of the one snapshot in the local index
// that writeBackupConfig puts beside the config file.
func onlySnapshotID(t *testing.T, configPath string) string {
t.Helper()
ctx := context.Background()
db, err := database.New(ctx,
filepath.Join(filepath.Dir(configPath), "index.sqlite"))
require.NoError(t, err)
defer func() { require.NoError(t, db.Close()) }()
backedUp, err := database.NewRepositories(db).Snapshots.GetOnlySnapshot(ctx)
require.NoError(t, err)
return backedUp.ID.String()
}