check / check (push) Failing after 15m58s
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
206 lines
5.8 KiB
Go
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()
|
|
}
|