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

internal/cli/config.go

@@ -49,8 +49,14 @@ var (
 	errWouldNotLoad     = errors.New(
 		"vaultik would not load the config after this change, " +
 			"so the file was not changed")
+	errSetS3KeysFirst = errors.New(
+		"set s3.access_key_id and s3.secret_access_key first, " +
+			"then storage_url")
 )
 
+// storageURLKey is the config key that selects the storage backend.
+const storageURLKey = "storage_url"
+
 // macOS is the value of runtime.GOOS on macOS.
 const macOS = "darwin"
 
@@ -513,7 +519,7 @@ func writeConfigSet(out *ui.Writer, path, key, value string) error {
 
 	err = checkConfigChange(oldData, data, settingData)
 	if err != nil {
-		return fmt.Errorf("%w: %w", errWouldNotLoad, err)
+		return wouldNotLoadError(key, err)
 	}
 
 	err = os.WriteFile(path, data, configFileMode)
@@ -537,6 +543,21 @@ func writeConfigSet(out *ui.Writer, path, key, value string) error {
 	return nil
 }
 
+// wouldNotLoadError returns the refusal of a change to key that vaultik
+// would not load for reason. When storage_url moves to s3:// before the S3
+// credentials are set, it says to set them first: they can be set while
+// the old storage_url is still in place.
+func wouldNotLoadError(key string, reason error) error {
+	if key == storageURLKey &&
+		(errors.Is(reason, config.ErrS3KeyIDRequired) ||
+			errors.Is(reason, config.ErrS3SecretRequired)) {
+		return fmt.Errorf("%w: %w; %w", errWouldNotLoad, reason,
+			errSetS3KeysFirst)
+	}
+
+	return fmt.Errorf("%w: %w", errWouldNotLoad, reason)
+}
+
 // checkConfigChange returns the reason vaultik would not load newData, the
 // config after a change, if the change brings that failure in. If oldData,
 // the config before it, loads, the new one must load too. A config that

internal/cli/config_test.go

@@ -2,6 +2,7 @@ package cli //nolint:testpackage // exercises unexported yamlPathGet/yamlPathSet
 
 import (
 	"bytes"
+	"errors"
 	"os"
 	"path/filepath"
 	"strconv"
@@ -152,6 +153,21 @@ snapshots:
       - "~"
 `
 
+// testS3URL is an S3 storage_url, which needs credentials to load.
+const testS3URL = "s3://bucket/prefix?endpoint=https://s3.example.com"
+
+// configWithS3Keys loads: its storage_url is testS3URL and both S3 keys are
+// set.
+const configWithS3Keys = storageURLKey + ": " + testS3URL + `
+s3:
+  access_key_id: AKIAEXAMPLE
+  secret_access_key: example-secret
+snapshots:
+  home:
+    paths:
+      - "~"
+`
+
 // configWithUnsetReference loads only where VAULTIK_TEST_UNSET_SECRET is
 // set, as a backup job's environment might set it. No test sets it.
 const configWithUnsetReference = configWithoutRecipients + `s3:
@@ -252,12 +268,20 @@ func TestConfigSetKeepsFileThatWouldNotLoad(t *testing.T) {
 		{configWithoutRecipients, "snapshots.home.paths", "/srv",
 			"into []string"},
 		{configWithoutRecipients, "chunk_size", "fast",
-			"invalid size format"},
+			`chunk_size: "fast" is not a size`},
 		// Values of the right type that fail validation.
 		{configWithoutRecipients, "compression_level", "99",
 			"compression_level must be between 1 and 19"},
 		{configWithoutRecipients, "chunk_size", "1KB",
 			"chunk_size must be at least 1MB"},
+		// An s3:// URL before its credentials names them.
+		{configWithoutRecipients, storageURLKey, testS3URL,
+			"s3.access_key_id is required for s3:// URLs; " +
+				"set s3.access_key_id and s3.secret_access_key first"},
+		{configWithoutRecipients + "s3:\n  access_key_id: AKIAEXAMPLE\n",
+			storageURLKey, testS3URL,
+			"s3.secret_access_key is required for s3:// URLs; " +
+				"set s3.access_key_id and s3.secret_access_key first"},
 		// With its reference filled in, the config loads.
 		{levelReference, "blob_size_limit", "1MB",
 			"blob_size_limit must be at least"},
@@ -343,6 +367,76 @@ func TestConfigSetRefusesOnlyItsOwnFailure(t *testing.T) {
 	}
 }
 
+// TestConfigSetS3KeysBeforeStorageURL checks that the order the refusal
+// gives works on a config that loads with a file:// storage_url.
+func TestConfigSetS3KeysBeforeStorageURL(t *testing.T) {
+	t.Parallel()
+
+	path := filepath.Join(t.TempDir(), "config.yml")
+
+	err := os.WriteFile(path, []byte(configWithoutRecipients), configFileMode)
+	if err != nil {
+		t.Fatalf("write config: %v", err)
+	}
+
+	for _, set := range [][2]string{
+		{"s3.access_key_id", "AKIAEXAMPLE"},
+		{"s3.secret_access_key", "example-secret"},
+		{storageURLKey, testS3URL},
+	} {
+		err = writeConfigSet(ui.NewWithColor(&bytes.Buffer{}, false),
+			path, set[0], set[1])
+		if err != nil {
+			t.Fatalf("config set %s: %v", set[0], err)
+		}
+	}
+
+	data, err := os.ReadFile(path) //nolint:gosec // G304: test-controlled path
+	if err != nil {
+		t.Fatalf("read config: %v", err)
+	}
+
+	if !strings.Contains(string(data), storageURLKey+": "+testS3URL) {
+		t.Errorf("config set storage_url wrote:\n%s", data)
+	}
+}
+
+// TestConfigSetRefusesClearingS3Key checks that clearing s3.access_key_id on
+// a config with an s3:// storage_url is refused without saying to set the
+// S3 keys first. That advice is only for a change to storage_url.
+func TestConfigSetRefusesClearingS3Key(t *testing.T) {
+	t.Parallel()
+
+	const key = "s3.access_key_id"
+
+	path := filepath.Join(t.TempDir(), "config.yml")
+
+	err := os.WriteFile(path, []byte(configWithS3Keys), configFileMode)
+	if err != nil {
+		t.Fatalf("write config: %v", err)
+	}
+
+	err = writeConfigSet(ui.NewWithColor(&bytes.Buffer{}, false), path, key, "")
+	if !errors.Is(err, errWouldNotLoad) {
+		t.Errorf("clearing %s gives error %v, want one saying %q",
+			key, err, errWouldNotLoad)
+	}
+
+	if errors.Is(err, errSetS3KeysFirst) {
+		t.Errorf("clearing %s gives error %v, want one not saying %q",
+			key, err, errSetS3KeysFirst)
+	}
+
+	data, err := os.ReadFile(path) //nolint:gosec // G304: test-controlled path
+	if err != nil {
+		t.Fatalf("read config: %v", err)
+	}
+
+	if string(data) != configWithS3Keys {
+		t.Errorf("clearing %s changed the file to:\n%s", key, data)
+	}
+}
+
 // TestConfigSetWritesEnvSection checks that config set writes a key under
 // the top-level env section, whose keys are not settings, on a config that
 // loads.

internal/cli/entry_snapshot_create_prune_test.go

@@ -61,8 +61,8 @@ func TestEntrySnapshotCreateRejectsKeepNewerThanBeforeBackup(t *testing.T) {
 
 // TestEntrySnapshotCreateReportsPostBackupPruneFailure makes the
 // post-backup prune fail after a good backup, by planting a manifest
-// that cannot be decoded, and checks that the failure is reported as the
-// prune's and not as a failed snapshot creation.
+// that cannot be decoded, and checks that the failure is reported once,
+// as the prune's and not as a failed snapshot creation.
 //
 //nolint:paralleltest // replaces os.Args, os.Stdout, os.Stderr and the xdg globals
 func TestEntrySnapshotCreateReportsPostBackupPruneFailure(t *testing.T) {
@@ -83,6 +83,9 @@ func TestEntrySnapshotCreateReportsPostBackupPruneFailure(t *testing.T) {
 	assert.Contains(t, stderr, "Backup completed, but post-backup prune failed")
 	assert.NotContains(t, stderr, "Snapshot creation failed")
 
+	_, repeats := failureOutput(t, stderr)
+	assert.Zero(t, repeats, "no log record may repeat the error:\n%s", stderr)
+
 	snapshots, err := os.ReadDir(filepath.Join(storeDir, "metadata"))
 	require.NoError(t, err)
 	assert.Len(t, snapshots, 2,
@@ -93,7 +96,8 @@ func TestEntrySnapshotCreateReportsPostBackupPruneFailure(t *testing.T) {
 // empties the source directory, as a volume that is not mounted leaves
 // its mount point, and runs `snapshot create --prune`. The command exits
 // non-zero and reports the backup as completed, not as a failed snapshot
-// creation. See https://git.eeqj.de/sneak/vaultik/issues/388.
+// creation. The error is printed once. See
+// https://git.eeqj.de/sneak/vaultik/issues/388.
 //
 //nolint:paralleltest // replaces os.Args, os.Stdout, os.Stderr and the xdg globals
 func TestEntrySnapshotCreatePruneExitsNonZeroWhenSourceIsEmpty(t *testing.T) {
@@ -114,6 +118,9 @@ func TestEntrySnapshotCreatePruneExitsNonZeroWhenSourceIsEmpty(t *testing.T) {
 		"Backup completed, but 1 source path(s) were empty")
 	assert.NotContains(t, stderr, "Snapshot creation failed")
 
+	_, repeats := failureOutput(t, stderr)
+	assert.Zero(t, repeats, "no log record may repeat the error:\n%s", stderr)
+
 	snapshots, err := os.ReadDir(filepath.Join(storeDir, "metadata"))
 	require.NoError(t, err)
 	assert.Len(t, snapshots, 2, "the older snapshot is kept")
@@ -124,7 +131,8 @@ func TestEntrySnapshotCreatePruneExitsNonZeroWhenSourceIsEmpty(t *testing.T) {
 // directory as a mount point, and runs `snapshot create --prune`, which
 // does not find it as one. The command exits non-zero, reports the
 // backup as completed, not as a failed snapshot creation, and keeps the
-// older snapshot. See https://git.eeqj.de/sneak/vaultik/issues/395.
+// older snapshot. The error is printed once. See
+// https://git.eeqj.de/sneak/vaultik/issues/395.
 //
 //nolint:paralleltest // replaces os.Args, os.Stdout, os.Stderr and the xdg globals
 func TestEntrySnapshotCreatePruneExitsNonZeroWhenMountPointIsMissing(
@@ -159,6 +167,9 @@ func TestEntrySnapshotCreatePruneExitsNonZeroWhenMountPointIsMissing(
 		"an earlier snapshot recorded were not found")
 	assert.NotContains(t, stderr, "Snapshot creation failed")
 
+	_, repeats := failureOutput(t, stderr)
+	assert.Zero(t, repeats, "no log record may repeat the error:\n%s", stderr)
+
 	snapshots, err := os.ReadDir(filepath.Join(storeDir, "metadata"))
 	require.NoError(t, err)
 	assert.Len(t, snapshots, 2, "the older snapshot is kept")

internal/config/config.go

@@ -79,8 +79,13 @@ var (
 		"storage not configured; set storage_url or provide s3.endpoint + " +
 			"s3.bucket + credentials")
 	errS3BucketRequired = errors.New("s3.bucket is required (or set storage_url)")
-	errS3KeyIDRequired  = errors.New("s3.access_key_id is required")
-	errS3SecretRequired = errors.New("s3.secret_access_key is required")
+)
+
+// Validate returns these when S3 storage is configured without its
+// credentials.
+var (
+	ErrS3KeyIDRequired  = errors.New("s3.access_key_id is required")
+	ErrS3SecretRequired = errors.New("s3.secret_access_key is required")
 )
 
 // expandTilde expands ~ at the start of a path to the user's home directory.
@@ -290,7 +295,8 @@ func Load(path string) (*Config, error) {
 }
 
 // Parse reads YAML config data as Load does, without validating it. It
-// refuses a key that no setting has, applies default values for optional
+// refuses a key that no setting has and a size setting whose value is not a
+// size, naming the setting. It applies default values for optional
 // fields, fills in ${...} references using smartconfig, and expands ~ in
 // paths.
 func Parse(data []byte) (*Config, error) {
@@ -315,8 +321,9 @@ func Parse(data []byte) (*Config, error) {
 		return nil, fmt.Errorf("failed to load config file: %w", err)
 	}
 
-	// A ${...} reference can bring in keys that are not in the file.
-	err = checkFilledKeys(sc.Data())
+	// A ${...} reference can bring in keys that are not in the file, and
+	// is the value of a size setting only once it is filled in.
+	err = checkFilledConfig(sc.Data())
 	if err != nil {
 		return nil, err
 	}
@@ -522,11 +529,11 @@ func (c *Config) validateStorage() error {
 	}
 
 	if c.S3.AccessKeyID == "" {
-		return errS3KeyIDRequired
+		return ErrS3KeyIDRequired
 	}
 
 	if c.S3.SecretAccessKey == "" {
-		return errS3SecretRequired
+		return ErrS3SecretRequired
 	}
 
 	return nil
@@ -553,11 +560,11 @@ func (c *Config) validateStorageURL() error {
 	case strings.HasPrefix(c.StorageURL, "s3://"):
 		// S3 storage needs credentials
 		if c.S3.AccessKeyID == "" {
-			return fmt.Errorf("%w for s3:// URLs", errS3KeyIDRequired)
+			return fmt.Errorf("%w for s3:// URLs", ErrS3KeyIDRequired)
 		}
 
 		if c.S3.SecretAccessKey == "" {
-			return fmt.Errorf("%w for s3:// URLs", errS3SecretRequired)
+			return fmt.Errorf("%w for s3:// URLs", ErrS3SecretRequired)
 		}
 
 		return nil

internal/config/keys.go

@@ -129,10 +129,11 @@ func checkKeys(node *yaml.Node, typ reflect.Type, path string,
 	return nil
 }
 
-// checkFilledKeys is checkKeys for data, the config after smartconfig has
-// filled in its ${...} references. A key that a reference brings in is not
-// in the file, and the copy that Encode makes has no line numbers.
-func checkFilledKeys(data map[string]any) error {
+// checkFilledConfig checks data, the config after smartconfig has filled in
+// its ${...} references: its keys with checkKeys, then its size settings
+// with checkSizes. A key that a reference brings in is not in the file, and
+// the copy that Encode makes has no line numbers.
+func checkFilledConfig(data map[string]any) error {
 	var filled yaml.Node
 
 	err := filled.Encode(data)
@@ -140,8 +141,13 @@ func checkFilledKeys(data map[string]any) error {
 		return fmt.Errorf("failed to marshal config data: %w", err)
 	}
 
-	return checkKeys(&filled, reflect.TypeFor[Config](), "",
+	err = checkKeys(&filled, reflect.TypeFor[Config](), "",
 		map[*yaml.Node]bool{}, map[nodeAndType]bool{})
+	if err != nil {
+		return err
+	}
+
+	return checkSizes(&filled, nil)
 }
 
 // checkMappingKeys is checkKeys for a map.

internal/config/size.go

@@ -4,13 +4,20 @@ import (
 	"errors"
 	"fmt"
 	"math"
+	"reflect"
+	"slices"
+	"strconv"
+	"strings"
 
 	"github.com/dustin/go-humanize"
+	"gopkg.in/yaml.v3"
 )
 
 var (
 	errSizeType     = errors.New("size must be a number or string")
 	errSizeTooLarge = errors.New("size exceeds maximum supported value")
+	errNotASize     = errors.New(
+		"is not a size; use a number of bytes or a unit such as 10MB")
 )
 
 // Size represents a byte size that can be specified in configuration files.
@@ -32,6 +39,15 @@ func (s *Size) UnmarshalYAML(unmarshal func(any) error) error {
 		return nil
 	}
 
+	// A number too large for an int64 decodes as a float64. Its text can be
+	// 1e+20, which is not a size string.
+	var floatVal float64
+
+	err = unmarshal(&floatVal)
+	if err == nil && floatVal > math.MaxInt64 {
+		return errSizeTooLarge
+	}
+
 	// Try to unmarshal as string
 	var strVal string
 
@@ -40,17 +56,66 @@ func (s *Size) UnmarshalYAML(unmarshal func(any) error) error {
 		return errSizeType
 	}
 
-	// Parse the string using go-humanize
-	bytes, err := humanize.ParseBytes(strVal)
+	size, err := ParseSize(strVal)
 	if err != nil {
-		return fmt.Errorf("invalid size format: %w", err)
+		return err
 	}
 
-	if bytes > math.MaxInt64 {
-		return fmt.Errorf("%w: %s", errSizeTooLarge, strVal)
+	*s = size
+
+	return nil
+}
+
+// checkSizes returns an error naming the first size setting in node whose
+// value is not a size. node is the config, or the part of it at the dotted
+// keys, after smartconfig has filled in its ${...} references.
+func checkSizes(node *yaml.Node, keys []string) error {
+	typ, err := SettingType(keys)
+	if err != nil {
+		// Unknown keys are refused before this check, so keys is in one of
+		// two places. The env section holds no settings. A value of the
+		// wrong shape, such as a map given for hostname or inside exclude,
+		// is reported later by the YAML decoder.
+		return nil //nolint:nilerr // not an error here
 	}
 
-	*s = Size(bytes)
+	if typ == reflect.TypeFor[Size]() {
+		var size Size
+
+		err = node.Decode(&size)
+		if err != nil {
+			return fmt.Errorf("%s: %w", strings.Join(keys, "."), err)
+		}
+
+		return nil
+	}
+
+	switch node.Kind {
+	case yaml.DocumentNode:
+		for _, child := range node.Content {
+			err = checkSizes(child, keys)
+			if err != nil {
+				return err
+			}
+		}
+	case yaml.MappingNode:
+		for i := 0; i+1 < len(node.Content); i += 2 {
+			err = checkSizes(node.Content[i+1],
+				slices.Concat(keys, []string{node.Content[i].Value}))
+			if err != nil {
+				return err
+			}
+		}
+	case yaml.SequenceNode:
+		for i, child := range node.Content {
+			err = checkSizes(child, slices.Concat(keys, []string{strconv.Itoa(i)}))
+			if err != nil {
+				return err
+			}
+		}
+	case yaml.ScalarNode, yaml.AliasNode:
+		// A scalar holds no settings, and the filled config has no aliases.
+	}
 
 	return nil
 }
@@ -70,16 +135,17 @@ func (s Size) String() string {
 	return humanize.Bytes(uint64(s))
 }
 
-// ParseSize parses a size string into a Size value
+// ParseSize parses a size string, such as "10MB", into a Size value. An
+// error quotes s.
 func ParseSize(s string) (Size, error) {
-	bytes, err := humanize.ParseBytes(s)
+	bytes, err := humanize.ParseBigBytes(s)
 	if err != nil {
-		return 0, fmt.Errorf("invalid size format: %w", err)
+		return 0, fmt.Errorf("%q %w", s, errNotASize)
 	}
 
-	if bytes > math.MaxInt64 {
+	if !bytes.IsInt64() {
 		return 0, fmt.Errorf("%w: %s", errSizeTooLarge, s)
 	}
 
-	return Size(bytes), nil
+	return Size(bytes.Int64()), nil
 }

internal/config/size_test.go

@@ -0,0 +1,120 @@
+package config //nolint:testpackage // checks errNotASize and errSizeTooLarge
+
+import (
+	"errors"
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+)
+
+// TestParseRefusesValueThatIsNotASize checks that a size setting whose
+// value is not a size fails the parse with an error naming the setting and
+// quoting the value, also when a ${...} reference fills the value in.
+func TestParseRefusesValueThatIsNotASize(t *testing.T) {
+	t.Parallel()
+
+	sizePath := filepath.Join(t.TempDir(), "size")
+
+	err := os.WriteFile(sizePath, []byte("lots"), 0o600)
+	if err != nil {
+		t.Fatalf("write size: %v", err)
+	}
+
+	tests := []struct {
+		name string
+		yaml string
+		want string
+	}{
+		{"chunk_size", keysTestConfig + "chunk_size: banana\n",
+			`chunk_size: "banana" is not a size; ` +
+				"use a number of bytes or a unit such as 10MB"},
+		{"blob_size_limit", keysTestConfig + "blob_size_limit: 10XB\n",
+			`blob_size_limit: "10XB" is not a size; ` +
+				"use a number of bytes or a unit such as 10MB"},
+		{"s3.part_size", strings.Replace(keysTestConfig, "  region:",
+			"  part_size: big\n  region:", 1),
+			`s3.part_size: "big" is not a size; ` +
+				"use a number of bytes or a unit such as 10MB"},
+		{"from a reference",
+			keysTestConfig + "chunk_size: ${FILE:" + sizePath + "}\n",
+			`chunk_size: "lots" is not a size; ` +
+				"use a number of bytes or a unit such as 10MB"},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			t.Parallel()
+
+			_, err := Parse([]byte(tt.yaml))
+			if !errors.Is(err, errNotASize) {
+				t.Fatalf("Parse() error = %v, want errNotASize", err)
+			}
+
+			if err.Error() != tt.want {
+				t.Errorf("Parse() error = %q, want %q", err.Error(), tt.want)
+			}
+		})
+	}
+}
+
+// TestParseRefusesSizeTooLarge checks that a size setting whose value is
+// too large for a size fails the parse with an error naming the setting.
+// YAML reads the second value as a float.
+func TestParseRefusesSizeTooLarge(t *testing.T) {
+	t.Parallel()
+
+	tests := []struct {
+		value string
+		want  string
+	}{
+		{"100EB", "chunk_size: size exceeds maximum supported value: 100EB"},
+		{"99999999999999999999",
+			"chunk_size: size exceeds maximum supported value"},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.value, func(t *testing.T) {
+			t.Parallel()
+
+			_, err := Parse([]byte(keysTestConfig + "chunk_size: " + tt.value + "\n"))
+			if !errors.Is(err, errSizeTooLarge) {
+				t.Fatalf("Parse() error = %v, want errSizeTooLarge", err)
+			}
+
+			if err.Error() != tt.want {
+				t.Errorf("Parse() error = %q, want %q", err.Error(), tt.want)
+			}
+		})
+	}
+}
+
+// TestParseAcceptsSizes checks that size settings given as a number of
+// bytes, as a unit, and through a ${...} reference still parse.
+func TestParseAcceptsSizes(t *testing.T) {
+	t.Parallel()
+
+	sizePath := filepath.Join(t.TempDir(), "size")
+
+	err := os.WriteFile(sizePath, []byte("20MB"), 0o600)
+	if err != nil {
+		t.Fatalf("write size: %v", err)
+	}
+
+	data := strings.Replace(keysTestConfig, "  region:",
+		"  part_size: 6000000\n  region:", 1) +
+		"chunk_size: ${FILE:" + sizePath + "}\n" +
+		"blob_size_limit: 1GB\n"
+
+	cfg, err := Parse([]byte(data))
+	if err != nil {
+		t.Fatalf("Parse() unexpected error: %v", err)
+	}
+
+	if cfg.ChunkSize != 20_000_000 || cfg.BlobSizeLimit != 1_000_000_000 ||
+		cfg.S3.PartSize != 6_000_000 {
+		t.Errorf("chunk_size, blob_size_limit, s3.part_size = %d, %d, %d, "+
+			"want 20000000, 1000000000, 6000000",
+			cfg.ChunkSize, cfg.BlobSizeLimit, cfg.S3.PartSize)
+	}
+}