README.md

@@ -113,11 +113,32 @@ vaultik version
 ### global flags
 
 * `--config <path>`: Path to config file (default: `$VAULTIK_CONFIG`, then platform config dir, then `/etc/vaultik/config.yml`)
-* `--verbose`, `-v`: Enable verbose output
+* `--verbose`, `-v`: Enable verbose output (on stderr — see below)
-* `--debug`: Enable debug output
+* `--debug`: Enable debug output (on stderr — see below)
 * `--quiet`, `-q`: Suppress non-error output (also suppresses startup banner)
 * `--skip-errors`: Continue past per-file errors instead of aborting (applies to `snapshot create` and `restore`)
 
+### stdout and stderr
+
+Log output — everything from `--verbose` and `--debug`, and every
+warning and error the logger emits — goes to **stderr**. stdout carries
+the output you asked for: tables, and the documents produced by `--json`.
+
+This means `vaultik snapshot list --verbose > out.txt` captures the
+listing and leaves the diagnostics on your terminal. To capture both,
+redirect stderr as well (`> out.txt 2> log.txt`, or `> out.txt 2>&1` to
+interleave them).
+
+The split is what makes `--json` usable from a script. Warnings and
+errors are never suppressed — not by `--quiet`, not by `--cron` — so a
+logger on stdout would eventually land a log line inside a JSON
+document and break the parse. A config file with group- or
+world-readable permissions is enough to trigger it.
+
+Format follows the stream: when stderr is a terminal the records are
+colorized one-liners, and when it is redirected or piped they are
+JSON, one object per line.
+
 ### environment variables
 
 * `VAULTIK_AGE_SECRET_KEY`: Age private key for decryption (required for `snapshot restore` and `snapshot verify --deep`)
@@ -208,8 +229,9 @@ local index alone, and still exits zero.
   (whether the snapshot is in the local index), `remote_key` (the full
   64-character storage key), and `remote_present` (whether it was seen
   on the destination store, or `null` if the destination could not be
-  listed). The warning about an unlistable destination goes to stderr
+  listed). Warnings about an unlistable destination, unreadable
-  so stdout stays a single parseable document.
+  manifests, and a truncated listing all go to stderr through the
+  logger, so stdout stays a single parseable document.
 
 **`snapshot verify`**: Verify snapshot integrity.
 * Default (shallow): checks that all blobs referenced in the manifest exist in storage
@@ -504,6 +526,10 @@ All user-facing output goes through helpers in `internal/ui` and conforms
 to a uniform style. Color is enabled when stdout is a TTY and the
 `NO_COLOR` environment variable is unset (https://no-color.org/).
 
+`internal/ui` writes to stdout; it is the output the user asked for.
+Structured log records are a different thing and go through
+`internal/log`, which writes to stderr (see "stdout and stderr" above).
+
 Message classes:
 
 | Class | Marker | Alignment | Use for |

TODO.md

@@ -25,6 +25,45 @@ release" is exactly the contradiction
 
 # Completed Steps
 
+- 2026-08-09: Moved the logger to stderr and fixed `TTYHandler`'s
+  discarded attributes
+  ([issue #82](https://git.eeqj.de/sneak/vaultik/issues/82),
+  [issue #97](https://git.eeqj.de/sneak/vaultik/issues/97)). Two defects
+  in `internal/log`, fixed together because both live in the handler
+  construction path. The first: both handlers were built over
+  `os.Stdout`, and `WARN`/`ERROR` are never suppressed, so a config file
+  with group- or world-readable permissions was enough to put a log
+  record inside a `--json` document and break `jq`. Diagnostics now go
+  to stderr, and the TTY/JSON format choice follows stderr rather than
+  stdout — testing the wrong stream would colorize records on a
+  redirected stderr whenever stdout happened to be a terminal. This is
+  user-visible: `--verbose` and `--debug` output moves to stderr too,
+  which is documented in `README.md` under "stdout and stderr". It also
+  let the local workaround in `internal/vaultik/snapshot_list.go` go:
+  `warnWhileListing` had been hand-rolling structured-log formatting to
+  reach a non-stdout writer, and the `jsonOutput` parameter threaded
+  through the remote-listing helpers existed only to choose between the
+  two writers. The collect-then-emit machinery around `listingWarning`
+  stays, but on its remaining merit — warnings emitted in key order
+  after `group.Wait()` are deterministic run to run, where emitting from
+  the fetch workers would order them by network timing. The second
+  defect: `TTYHandler.WithAttrs` and `WithGroup` discarded their
+  arguments and returned the receiver while their doc comments claimed
+  otherwise, so `log.With` attributes vanished on a terminal and
+  appeared correctly in CI — failing precisely when someone is debugging
+  interactively. Both now return a new handler (the receiver is never
+  written to, since `slog` permits concurrent derivation), attributes
+  persist across records, and grouping is implemented as dotted key
+  prefixes, which is the only honest rendering for a format with nowhere
+  to nest. New tests cover both, including one that feeds the same
+  derivation chain to the TTY and JSON handlers and compares the
+  attribute sets, so the two paths cannot drift apart again. Found and
+  filed while verifying: the startup banner is written to stdout and
+  `--json` does not suppress it
+  ([issue #106](https://git.eeqj.de/sneak/vaultik/issues/106)), which is
+  a separate writer on a separate path and the remaining source of
+  stdout contamination.
+
 - 2026-08-09: Made the tagged-release path actually work on Gitea
   ([issue #65](https://git.eeqj.de/sneak/vaultik/issues/65)). Three
   independent blockers, one of which was the whole

internal/log/log.go

@@ -1,5 +1,9 @@
 // Package log provides the application-wide structured logger: slog
-// with a colorized TTY handler on terminals and JSON output otherwise.
+// writing to stderr, with a colorized TTY handler when stderr is a
+// terminal and JSON output otherwise.
+//
+// Everything this package emits is a diagnostic, so it all goes to
+// stderr. stdout belongs to the output the user asked for.
 package log //nolint:revive,nolintlint // stdlib log unused here; see #76
 
 import (
@@ -69,13 +73,27 @@ func Initialize(cfg Config) {
 		Level: level,
 	}
 
-	// Check if stdout is a TTY.
+	// Diagnostics go to stderr, never to stdout. stdout is reserved for
-	if term.IsTerminal(int(os.Stdout.Fd())) {
+	// the output the user asked for: every --json subcommand writes its
+	// document there, and WARN/ERROR are never suppressed, so a logger
+	// on stdout puts log records inside that document and makes it
+	// unparseable. A config file with group- or world-readable
+	// permissions is enough to trigger it (see internal/config), so this
+	// was not a theoretical collision.
+	//
+	// The format is chosen by the TTY-ness of the stream the records
+	// actually land on. AGENTS.md policy 9 says "if stdout is not a
+	// terminal, emit jsonl"; it says stdout because that is where logs
+	// used to go, and the property it is really asking for is that
+	// output nobody is watching be machine-readable. Testing stdout here
+	// would colorize records on a redirected stderr whenever stdout
+	// happened to be a terminal, and vice versa.
+	if term.IsTerminal(int(os.Stderr.Fd())) {
 		// Use colorized TTY handler
-		logger = slog.New(NewTTYHandler(os.Stdout, opts))
+		logger = slog.New(NewTTYHandler(os.Stderr, opts))
 	} else {
 		// Use JSON format for non-TTY output
-		logger = slog.New(slog.NewJSONHandler(os.Stdout, opts))
+		logger = slog.New(slog.NewJSONHandler(os.Stderr, opts))
 	}
 
 	// Set as default logger

internal/log/tty_handler.go

@@ -5,10 +5,20 @@ import (
 	"fmt"
 	"io"
 	"log/slog"
+	"strings"
 	"sync"
 	"time"
 )
 
+// groupSeparator joins an open group path to an attribute key. This
+// format has no nesting, so a group becomes a dotted key prefix:
+// slog.New(h).WithGroup("db").With("rows", 3) renders "db.rows=3".
+const groupSeparator = "."
+
+// bytesAttrKey is the attribute key whose int64 value is rendered as a
+// human-readable byte count rather than a bare number.
+const bytesAttrKey = "bytes"
+
 // ANSI color codes
 const (
 	colorReset  = "\033[0m"
@@ -22,10 +32,26 @@ const (
 )
 
 // TTYHandler is a custom slog handler for TTY output with colors.
+//
+// A handler and the handlers derived from it via WithAttrs/WithGroup
+// all write to the same stream, so they share one mutex; that is why mu
+// is a pointer. A value mutex would give every derived handler its own
+// lock and stop serializing writes to the stream they have in common.
 type TTYHandler struct {
 	opts slog.HandlerOptions
-	mu   sync.Mutex
+	mu   *sync.Mutex
 	out  io.Writer
+
+	// attrs are the attributes accumulated through WithAttrs, emitted
+	// ahead of each record's own attributes. Their keys already carry
+	// the group path that was open when they were added, so no
+	// qualification happens at write time.
+	attrs []slog.Attr
+
+	// groups is the group path opened by WithGroup, applied as a key
+	// prefix to attributes that arrive later — both on a record and
+	// through a further WithAttrs.
+	groups []string
 }
 
 // NewTTYHandler creates a new TTY handler with colored output.
@@ -37,6 +63,7 @@ func NewTTYHandler(out io.Writer, opts *slog.HandlerOptions) *TTYHandler {
 	return &TTYHandler{
 		out:  out,
 		opts: *opts,
+		mu:   &sync.Mutex{},
 	}
 }
 
@@ -81,8 +108,126 @@ func (h *TTYHandler) Handle(_ context.Context, r slog.Record) error {
 		levelColor, level, colorReset,
 		colorBold, r.Message, colorReset)
 
-	// Print attributes
+	// Attributes carried by the handler come first, then the record's
+	// own. Handler attributes were qualified when they were added; the
+	// record's are qualified now, against whatever group path is open.
+	for _, a := range h.attrs {
+		h.writeAttr(a)
+	}
+
+	prefix := strings.Join(h.groups, groupSeparator)
+
 	r.Attrs(func(a slog.Attr) bool {
+		for _, flat := range appendAttr(nil, prefix, a) {
+			h.writeAttr(flat)
+		}
+
+		return true
+	})
+
+	_, _ = fmt.Fprintln(h.out)
+
+	return nil
+}
+
+// appendAttr flattens a into dst, folding prefix into its key and
+// expanding group values into further dotted keys. Following the
+// slog.Handler contract: an empty Attr is dropped, a group with no
+// attributes is dropped, and a group with an empty key is inlined into
+// its parent rather than contributing a level.
+func appendAttr(dst []slog.Attr, prefix string, a slog.Attr) []slog.Attr {
+	a.Value = a.Value.Resolve()
+
+	if a.Equal(slog.Attr{}) {
+		return dst
+	}
+
+	key := a.Key
+
+	switch {
+	case prefix == "":
+		// key stands alone.
+	case key == "":
+		key = prefix
+	default:
+		key = prefix + groupSeparator + key
+	}
+
+	if a.Value.Kind() != slog.KindGroup {
+		return append(dst, slog.Attr{Key: key, Value: a.Value})
+	}
+
+	for _, member := range a.Value.Group() {
+		dst = appendAttr(dst, key, member)
+	}
+
+	return dst
+}
+
+// WithAttrs returns a new handler that emits attrs on every record it
+// handles, in addition to whatever the handler already carried. Keys
+// are qualified by the group path open at the time of the call, so
+// WithGroup("db").WithAttrs(rows=3) later renders "db.rows=3".
+//
+// The receiver is not modified.
+func (h *TTYHandler) WithAttrs(attrs []slog.Attr) slog.Handler {
+	if len(attrs) == 0 {
+		return h
+	}
+
+	prefix := strings.Join(h.groups, groupSeparator)
+	next := h.clone()
+
+	for _, a := range attrs {
+		next.attrs = appendAttr(next.attrs, prefix, a)
+	}
+
+	return next
+}
+
+// WithGroup returns a new handler that qualifies every subsequent
+// attribute key with name. This format is a single line with nowhere to
+// nest, so grouping is rendered as a dotted key prefix: after
+// WithGroup("db"), an attribute "rows" is emitted as "db.rows".
+//
+// An empty name returns the receiver unchanged, per the slog.Handler
+// contract. The receiver is not modified.
+func (h *TTYHandler) WithGroup(name string) slog.Handler {
+	if name == "" {
+		return h
+	}
+
+	next := h.clone()
+	next.groups = append(next.groups, name)
+
+	return next
+}
+
+// clone returns a copy of h that shares its output stream and mutex but
+// owns its attribute and group slices.
+//
+// The slices are copied rather than resliced on purpose. slog permits
+// one handler to be derived from concurrently, and two derivations that
+// appended into a shared backing array would each overwrite the other's
+// attribute — a data race with a silent wrong-output failure mode.
+func (h *TTYHandler) clone() *TTYHandler {
+	next := &TTYHandler{
+		opts:   h.opts,
+		mu:     h.mu,
+		out:    h.out,
+		attrs:  make([]slog.Attr, len(h.attrs), len(h.attrs)+1),
+		groups: make([]string, len(h.groups), len(h.groups)+1),
+	}
+
+	copy(next.attrs, h.attrs)
+	copy(next.groups, h.groups)
+
+	return next
+}
+
+// writeAttr renders one already-flattened, already-qualified attribute
+// as " key=value". Callers hold h.mu.
+func (h *TTYHandler) writeAttr(a slog.Attr) {
 	value := a.Value.String()
 	// Special handling for certain attribute types
 	switch a.Value.Kind() {
@@ -91,7 +236,7 @@ func (h *TTYHandler) Handle(_ context.Context, r slog.Record) error {
 			value = formatDuration(d)
 		}
 	case slog.KindInt64:
-			if a.Key == "bytes" {
+		if a.Key == bytesAttrKey {
 			value = formatBytes(a.Value.Int64())
 		}
 	case slog.KindAny, slog.KindBool, slog.KindFloat64, slog.KindString,
@@ -104,23 +249,6 @@ func (h *TTYHandler) Handle(_ context.Context, r slog.Record) error {
 	_, _ = fmt.Fprintf(h.out, " %s%s%s=%s%s%s",
 		colorCyan, a.Key, colorReset,
 		colorBlue, value, colorReset)
-
-		return true
-	})
-
-	_, _ = fmt.Fprintln(h.out)
-
-	return nil
-}
-
-// WithAttrs returns a new handler with the given attributes.
-func (h *TTYHandler) WithAttrs(_ []slog.Attr) slog.Handler {
-	return h // Simplified for now
-}
-
-// WithGroup returns a new handler with the given group name.
-func (h *TTYHandler) WithGroup(_ string) slog.Handler {
-	return h // Simplified for now
 }
 
 // formatDuration formats a duration in a human-readable way

internal/log/tty_handler_test.go

@@ -0,0 +1,377 @@
+package log_test
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"fmt"
+	"log/slog"
+	"math"
+	"regexp"
+	"sort"
+	"strconv"
+	"strings"
+	"sync"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"sneak.berlin/go/vaultik/internal/log"
+)
+
+// ansiEscape matches the SGR sequences TTYHandler wraps every field in.
+// Stripping them is what lets a test compare TTYHandler's rendering with
+// slog.JSONHandler's.
+var ansiEscape = regexp.MustCompile(`\x1b\[[0-9;]*m`)
+
+// countKey is an attribute key reused across the comparison cases.
+const countKey = "count"
+
+// debugHandlerOptions enables every level, so a test never has to reason
+// about the default level while reasoning about attributes.
+func debugHandlerOptions() *slog.HandlerOptions {
+	return &slog.HandlerOptions{Level: slog.LevelDebug}
+}
+
+// ttyAttrs renders one record through a TTYHandler and returns its
+// attributes as key -> value, with color stripped.
+//
+// TTYHandler emits " key=value" per attribute after the message, and the
+// message itself is the last thing before the first attribute, so
+// splitting on spaces and keeping the tokens containing "=" recovers the
+// attribute set. Test values below therefore avoid spaces and "=".
+func ttyAttrs(t *testing.T, derive func(*slog.Logger) *slog.Logger,
+	msg string, args ...any,
+) map[string]string {
+	t.Helper()
+
+	var buf bytes.Buffer
+
+	logger := slog.New(log.NewTTYHandler(&buf, debugHandlerOptions()))
+	derive(logger).Info(msg, args...)
+
+	line := ansiEscape.ReplaceAllString(buf.String(), "")
+	attrs := make(map[string]string)
+
+	for token := range strings.FieldsSeq(line) {
+		key, value, found := strings.Cut(token, "=")
+		if !found {
+			continue
+		}
+
+		attrs[key] = value
+	}
+
+	return attrs
+}
+
+// jsonAttrs renders one record through slog.JSONHandler and returns its
+// attributes flattened to the same dotted-key form TTYHandler uses, so
+// the two are directly comparable. The built-in time/level/msg fields
+// are dropped: they are the record, not its attributes.
+func jsonAttrs(t *testing.T, derive func(*slog.Logger) *slog.Logger,
+	msg string, args ...any,
+) map[string]string {
+	t.Helper()
+
+	var buf bytes.Buffer
+
+	logger := slog.New(slog.NewJSONHandler(&buf, debugHandlerOptions()))
+	derive(logger).Info(msg, args...)
+
+	var decoded map[string]any
+
+	require.NoError(t, json.Unmarshal(buf.Bytes(), &decoded))
+
+	delete(decoded, slog.TimeKey)
+	delete(decoded, slog.LevelKey)
+	delete(decoded, slog.MessageKey)
+
+	attrs := make(map[string]string)
+	flattenJSON(attrs, "", decoded)
+
+	return attrs
+}
+
+// flattenJSON turns JSONHandler's nested group objects into the dotted
+// keys TTYHandler writes.
+func flattenJSON(dst map[string]string, prefix string, src map[string]any) {
+	for key, value := range src {
+		full := key
+		if prefix != "" {
+			full = prefix + "." + key
+		}
+
+		nested, ok := value.(map[string]any)
+		if ok {
+			flattenJSON(dst, full, nested)
+
+			continue
+		}
+
+		dst[full] = valueString(value)
+	}
+}
+
+// valueString renders a decoded JSON scalar the way slog.Value.String
+// renders the corresponding Go value, so the two handlers' outputs can
+// be compared as strings. encoding/json decodes every number as
+// float64, so an integral one is rendered back as an integer — which is
+// what the Go value that produced it was.
+func valueString(v any) string {
+	switch typed := v.(type) {
+	case string:
+		return typed
+	case bool:
+		return strconv.FormatBool(typed)
+	case float64:
+		if typed == math.Trunc(typed) {
+			return strconv.FormatInt(int64(typed), 10)
+		}
+
+		return strconv.FormatFloat(typed, 'g', -1, 64)
+	default:
+		return fmt.Sprint(v)
+	}
+}
+
+// TestTTYHandlerWithAttrsEmitsAttributes is the direct regression test
+// for the reported defect: WithAttrs discarded its argument, so an
+// attribute attached to a logger never reached the output.
+func TestTTYHandlerWithAttrsEmitsAttributes(t *testing.T) {
+	t.Parallel()
+
+	attrs := ttyAttrs(t, func(l *slog.Logger) *slog.Logger {
+		return l.With("key", "value")
+	}, "hello")
+
+	assert.Equal(t, "value", attrs["key"],
+		"an attribute attached with With must appear on every record")
+}
+
+// TestTTYHandlerWithAttrsPersistsAcrossRecords checks that the
+// attributes are retained rather than emitted once. A handler that
+// stored them but consumed them would pass the test above.
+func TestTTYHandlerWithAttrsPersistsAcrossRecords(t *testing.T) {
+	t.Parallel()
+
+	var buf bytes.Buffer
+
+	logger := slog.New(log.NewTTYHandler(&buf, debugHandlerOptions())).
+		With("request", "abc123")
+
+	logger.Info("first")
+	logger.Info("second")
+
+	plain := ansiEscape.ReplaceAllString(buf.String(), "")
+	lines := strings.Split(strings.TrimSuffix(plain, "\n"), "\n")
+
+	require.Len(t, lines, 2)
+
+	for _, line := range lines {
+		assert.Contains(t, line, "request=abc123")
+	}
+}
+
+// TestTTYHandlerWithGroupQualifiesKeys checks that WithGroup does
+// something real rather than being discarded. This format has no
+// nesting, so grouping shows up as a dotted key prefix.
+func TestTTYHandlerWithGroupQualifiesKeys(t *testing.T) {
+	t.Parallel()
+
+	attrs := ttyAttrs(t, func(l *slog.Logger) *slog.Logger {
+		return l.WithGroup("db").With("rows", 3)
+	}, "queried", "table", "chunks")
+
+	assert.Equal(t, "3", attrs["db.rows"],
+		"an attribute added under a group must be qualified by it")
+	assert.Equal(t, "chunks", attrs["db.table"],
+		"a record attribute must also be qualified by the open group")
+	assert.NotContains(t, attrs, "rows")
+}
+
+// TestTTYHandlerMatchesJSONHandlerAttributes is the drift guard. The
+// handler is chosen by TTY-ness, so a difference between these two is
+// invisible in whichever environment the developer is not in — which is
+// how the original defect survived: attributes vanished on a terminal
+// and were correct in CI.
+func TestTTYHandlerMatchesJSONHandlerAttributes(t *testing.T) {
+	t.Parallel()
+
+	cases := []struct {
+		name   string
+		derive func(*slog.Logger) *slog.Logger
+		args   []any
+	}{
+		{
+			name:   "record attributes only",
+			derive: func(l *slog.Logger) *slog.Logger { return l },
+			args:   []any{"path", "/etc/vaultik", countKey, 7},
+		},
+		{
+			name: "handler attributes",
+			derive: func(l *slog.Logger) *slog.Logger {
+				return l.With("host", "alpha")
+			},
+			args: []any{countKey, 7},
+		},
+		{
+			name: "handler attributes accumulate",
+			derive: func(l *slog.Logger) *slog.Logger {
+				return l.With("host", "alpha").With("snapshot", "s1")
+			},
+			args: []any{countKey, 7},
+		},
+		{
+			name: "group qualifies later attributes",
+			derive: func(l *slog.Logger) *slog.Logger {
+				return l.WithGroup("db").With("rows", 3)
+			},
+			args: []any{"table", "chunks"},
+		},
+		{
+			name: "nested groups",
+			derive: func(l *slog.Logger) *slog.Logger {
+				return l.WithGroup("outer").WithGroup("inner").
+					With("leaf", "v")
+			},
+			args: []any{"other", "w"},
+		},
+		{
+			name: "attributes before and after a group",
+			derive: func(l *slog.Logger) *slog.Logger {
+				return l.With("top", "t").WithGroup("g").With("in", "i")
+			},
+			args: []any{"rec", "r"},
+		},
+		{
+			name:   "inline group value on the record",
+			derive: func(l *slog.Logger) *slog.Logger { return l },
+			args: []any{slog.Group("net",
+				slog.String("proto", "s3"), slog.Int("retries", 2))},
+		},
+	}
+
+	for _, testCase := range cases {
+		t.Run(testCase.name, func(t *testing.T) {
+			t.Parallel()
+
+			tty := ttyAttrs(t, testCase.derive, "message", testCase.args...)
+			js := jsonAttrs(t, testCase.derive, "message", testCase.args...)
+
+			assert.Equal(t, sortedKeys(js), sortedKeys(tty),
+				"TTY and JSON handlers must emit the same attribute keys")
+			assert.Equal(t, js, tty,
+				"TTY and JSON handlers must emit the same attribute values")
+		})
+	}
+}
+
+// sortedKeys returns m's keys in order, for a stable comparison message.
+func sortedKeys(m map[string]string) []string {
+	keys := make([]string, 0, len(m))
+	for key := range m {
+		keys = append(keys, key)
+	}
+
+	sort.Strings(keys)
+
+	return keys
+}
+
+// TestTTYHandlerWithAttrsDoesNotMutateReceiver checks that deriving does
+// not write through to the parent or to a sibling. slog permits a
+// handler to be shared, so a WithAttrs that appended into the receiver's
+// state would leak attributes between unrelated loggers.
+func TestTTYHandlerWithAttrsDoesNotMutateReceiver(t *testing.T) {
+	t.Parallel()
+
+	var buf bytes.Buffer
+
+	base := slog.New(log.NewTTYHandler(&buf, debugHandlerOptions()))
+	first := base.With("branch", "one")
+	second := base.With("branch", "two")
+
+	base.Info("base")
+	first.Info("first")
+	second.Info("second")
+
+	plain := ansiEscape.ReplaceAllString(buf.String(), "")
+	lines := strings.Split(strings.TrimSuffix(plain, "\n"), "\n")
+
+	require.Len(t, lines, 3)
+
+	assert.NotContains(t, lines[0], "branch=",
+		"deriving must not add attributes to the handler derived from")
+	assert.Contains(t, lines[1], "branch=one")
+	assert.NotContains(t, lines[1], "branch=two")
+	assert.Contains(t, lines[2], "branch=two")
+	assert.NotContains(t, lines[2], "branch=one")
+}
+
+// TestTTYHandlerConcurrentDerivation exercises the same handler being
+// derived from and written through by several goroutines at once, which
+// is what slog permits and what a mutating WithAttrs would make a data
+// race. Run under -race by script/test.
+func TestTTYHandlerConcurrentDerivation(t *testing.T) {
+	t.Parallel()
+
+	const workers = 16
+
+	var buf bytes.Buffer
+
+	base := slog.New(log.NewTTYHandler(&buf, debugHandlerOptions())).
+		With("shared", "yes")
+
+	var group sync.WaitGroup
+
+	group.Add(workers)
+
+	for worker := range workers {
+		go func() {
+			defer group.Done()
+
+			base.With("worker", worker).
+				WithGroup("g").
+				With("nested", worker).
+				Info("concurrent")
+		}()
+	}
+
+	group.Wait()
+
+	plain := ansiEscape.ReplaceAllString(buf.String(), "")
+	lines := strings.Split(strings.TrimSuffix(plain, "\n"), "\n")
+
+	require.Len(t, lines, workers)
+
+	for _, line := range lines {
+		assert.Contains(t, line, "shared=yes")
+		assert.Contains(t, line, "worker=")
+		assert.Contains(t, line, "g.nested=")
+	}
+}
+
+// TestTTYHandlerEmptyGroupAndAttrsAreNoOps covers the slog.Handler
+// contract corners: WithGroup("") and WithAttrs(nil) change nothing, and
+// an empty Attr is dropped rather than rendered as "=".
+func TestTTYHandlerEmptyGroupAndAttrsAreNoOps(t *testing.T) {
+	t.Parallel()
+
+	var buf bytes.Buffer
+
+	handler := log.NewTTYHandler(&buf, debugHandlerOptions())
+
+	assert.Same(t, handler, handler.WithGroup(""),
+		"an empty group name must not open a group")
+	assert.Same(t, handler, handler.WithAttrs(nil),
+		"deriving with no attributes must not allocate a handler")
+
+	slog.New(handler).LogAttrs(context.Background(), slog.LevelInfo, "msg",
+		slog.Attr{}, slog.String("kept", "yes"))
+
+	plain := ansiEscape.ReplaceAllString(buf.String(), "")
+
+	assert.Contains(t, plain, "kept=yes")
+	assert.NotContains(t, plain, " =")
+}

internal/log/with_test.go

@@ -0,0 +1,64 @@
+//nolint:testpackage // needs the package logger; see TestWithAttributesReachTTYOutput
+package log //nolint:revive,nolintlint // stdlib log unused here; see #76
+
+import (
+	"bytes"
+	"log/slog"
+	"regexp"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+// withTestANSIEscape matches the SGR sequences TTYHandler emits.
+var withTestANSIEscape = regexp.MustCompile(`\x1b\[[0-9;]*m`)
+
+// TestWithAttributesReachTTYOutput exercises the exported package-level
+// With through a TTYHandler, which is the path the reported defect was
+// on: the handler is selected by TTY-ness, so on a terminal With's
+// attributes were silently dropped while the same code printed them
+// correctly in CI.
+//
+// This is an in-package test so it can point the package logger at a
+// buffer. Building an slog.Logger over a TTYHandler by hand would test
+// slog, not this package's With, and there is no injectable sink to
+// reach it from outside. The package logger is process-global, so this
+// test must not run in parallel.
+//
+//nolint:paralleltest // replaces the process-global package logger
+func TestWithAttributesReachTTYOutput(t *testing.T) {
+	var buf bytes.Buffer
+
+	previous := logger
+
+	t.Cleanup(func() { logger = previous })
+
+	logger = slog.New(NewTTYHandler(&buf, &slog.HandlerOptions{
+		Level: slog.LevelDebug,
+	}))
+
+	With("key", "value").Info("hello")
+
+	plain := withTestANSIEscape.ReplaceAllString(buf.String(), "")
+
+	require.NotEmpty(t, plain)
+	assert.Contains(t, plain, "hello")
+	assert.Contains(t, plain, "key=value",
+		"log.With attributes must reach TTYHandler output")
+}
+
+// TestWithoutInitializedLoggerFallsBack pins the documented behavior of
+// With before Initialize has run: it hands back the slog default rather
+// than a nil logger that would panic at the call site.
+//
+//nolint:paralleltest // replaces the process-global package logger
+func TestWithoutInitializedLoggerFallsBack(t *testing.T) {
+	previous := logger
+
+	t.Cleanup(func() { logger = previous })
+
+	logger = nil
+
+	assert.NotNil(t, With("key", "value"))
+}

internal/vaultik/snapshot_list.go

@@ -87,7 +87,7 @@ func (v *Vaultik) ListSnapshots(jsonOutput bool) error {
 		snapshots = append(snapshots, info)
 	}
 
-	listing, remoteErr := v.collectRemoteSnapshots(localKeys, jsonOutput)
+	listing, remoteErr := v.collectRemoteSnapshots(localKeys)
 	if remoteErr != nil {
 		v.warnRemoteListingFailed(remoteErr, jsonOutput)
 	} else {
@@ -131,23 +131,23 @@ func (v *Vaultik) ListSnapshots(jsonOutput bool) error {
 // still worth printing, and `snapshot list` exiting non-zero because a
 // volume is unmounted would be worse than useless.
 //
-// In --json mode the warning goes to stderr rather than through the
+// The two output modes report it through different channels. Table mode
-// logger or the UI writer, both of which emit on stdout — the JSON
+// uses the UI writer, whose prose and color match the table it sits
-// document has to be the only thing on stdout for `snapshot list --json
+// under. The UI writer emits on stdout, though, so --json mode uses the
-// | jq` to work. The failure is also representable in the document
+// logger instead: stdout has to hold nothing but the JSON document for
-// itself: every row's remote_present is null when the destination could
+// `snapshot list --json | jq` to work. Both channels are chosen once,
-// not be listed.
+// never both, so the user is not told the same thing twice.
+//
+// The failure is also representable in the document itself: every row's
+// remote_present is null when the destination could not be listed.
 func (v *Vaultik) warnRemoteListingFailed(err error, jsonOutput bool) {
 	if jsonOutput {
-		_, _ = fmt.Fprintf(v.Stderr,
+		log.Warn("Could not list backup destination store; "+
-			"Warning: could not list backup destination store: %v. "+
+			"showing snapshots from the local index only", "error", err)
-				"Showing snapshots from the local index only.\n", err)
 
 		return
 	}
 
-	// Once only: the logger also writes to stdout, so emitting through
-	// both it and the UI would print the same sentence to the user twice.
 	v.UI.Warningf("Could not list backup destination store: %v.", err)
 	v.UI.Infof("Showing snapshots from the local index only.")
 }
@@ -156,69 +156,29 @@ func (v *Vaultik) warnRemoteListingFailed(err error, jsonOutput bool) {
 // is about to read is incomplete: manifests that could not be read, and
 // remote-only snapshots dropped by the maxRemoteOnlyRows cap.
 //
-// Table mode reports both below the table (see reportListDrift). In
+// Table mode reports both below the table (see reportListDrift) through
-// --json mode they cannot go on stdout — the document has to be the
+// the UI writer, which emits on stdout. In --json mode stdout has to
-// only thing there for `snapshot list --json | jq` to work — and the
+// hold nothing but the document for `snapshot list --json | jq` to
-// document's shape is deliberately left alone so existing consumers
+// work, and the document's shape is deliberately left alone so existing
-// keep parsing. So they go to stderr, the same place the
+// consumers keep parsing — so these go to the logger, which writes to
-// unreachable-destination warning already goes. A consumer that must
+// stderr. A consumer that must react to truncation can treat any output
-// react to truncation can treat any output on this stream as "this
+// on that stream as "this listing is not the whole picture"; silent
-// listing is not the whole picture"; silent truncation of a listing
+// truncation of a listing whose whole purpose is disaster recovery is
-// whose whole purpose is disaster recovery is the worse failure.
+// the worse failure.
 func (v *Vaultik) reportJSONListingLimits(listing *remoteSnapshotListing) {
 	if listing.unreadable > 0 {
-		_, _ = fmt.Fprintf(v.Stderr,
+		log.Warn("Some remote snapshot(s) could not be described: "+
-			"Warning: %d remote snapshot(s) could not be described: "+
+			"manifest missing or unreadable; they are missing from "+
-				"manifest missing or unreadable. They are missing from "+
+			"this listing", "unreadable", listing.unreadable)
-				"this listing.\n", listing.unreadable)
 	}
 
 	if listing.omitted > 0 {
-		_, _ = fmt.Fprintf(v.Stderr,
+		log.Warn("Listing truncated: further remote-only snapshot(s) "+
-			"Warning: listing truncated: %d further remote-only "+
+			"not shown", "omitted", listing.omitted,
-				"snapshot(s) not shown (limit %d per listing).\n",
+			"limit", maxRemoteOnlyRows)
-			listing.omitted, maxRemoteOnlyRows)
 	}
 }
 
-// kvPairSize is the number of variadic arguments that make up one
-// structured logging key/value pair.
-const kvPairSize = 2
-
-// warnWhileListing reports a per-snapshot problem found while
-// describing the destination store, through a writer that is safe for
-// the current output mode.
-//
-// In --json mode it writes to v.Stderr rather than calling log.Warn,
-// for the same reason warnRemoteListingFailed does: internal/log builds
-// its logger over os.Stdout and defaults to level Warn, so one warning
-// there would put a log line on stdout ahead of the JSON document and
-// break `snapshot list --json | jq`. A single corrupt manifest is
-// precisely the degradation this listing is built to survive, so it
-// must not be the thing that corrupts the output.
-//
-// This is a local workaround. Remove it, and the branch in
-// warnRemoteListingFailed, once issue #82 makes the logger's sink
-// configurable.
-func (v *Vaultik) warnWhileListing(jsonOutput bool, msg string, args ...any) {
-	if !jsonOutput {
-		log.Warn(msg, args...)
-
-		return
-	}
-
-	var line strings.Builder
-
-	_, _ = fmt.Fprintf(&line, "Warning: %s", msg)
-
-	for i := 0; i+kvPairSize <= len(args); i += kvPairSize {
-		pair := args[i : i+kvPairSize]
-		_, _ = fmt.Fprintf(&line, " %v=%v", pair[0], pair[1])
-	}
-
-	_, _ = fmt.Fprintln(v.Stderr, line.String())
-}
-
 // remoteSnapshotListing is the result of one pass over the destination
 // store's metadata/ prefix.
 type remoteSnapshotListing struct {
@@ -247,11 +207,8 @@ type remoteSnapshotListing struct {
 // Manifest reads scale only with the number of snapshots the local
 // index does not already know about, and are capped at
 // maxRemoteOnlyRows.
-//
-// jsonOutput only selects where per-snapshot warnings are written; see
-// warnWhileListing.
 func (v *Vaultik) collectRemoteSnapshots(
-	localKeys map[string]bool, jsonOutput bool,
+	localKeys map[string]bool,
 ) (*remoteSnapshotListing, error) {
 	keys, err := v.listAllRemoteSnapshotKeys()
 	if err != nil {
@@ -282,17 +239,22 @@ func (v *Vaultik) collectRemoteSnapshots(
 	}
 
 	listing.remoteOnly, listing.unreadable = v.describeRemoteOnlySnapshots(
-		unknown, jsonOutput)
+		unknown)
 
 	return listing, nil
 }
 
 // listingWarning is a problem found with one remote snapshot, recorded
-// rather than emitted on the spot. Manifest reads run concurrently and
+// rather than emitted on the spot. Manifest reads run concurrently, so
-// the writer chosen by warnWhileListing is not guaranteed to be safe
+// emitting from the worker that found the problem would order the
-// for concurrent use, so warnings are held until every read has
+// warnings by fetch completion — which varies run to run with network
-// finished and then emitted in key order from a single goroutine. That
+// timing and tells the reader nothing. Holding them and emitting in key
-// also makes the warning order deterministic run to run.
+// order from a single goroutine after every read has finished makes two
+// runs over the same damaged store produce the same diagnostics in the
+// same order.
+//
+// Concurrency safety is no longer part of the reason: these are emitted
+// through log.Warn, and slog handlers are safe for concurrent use.
 type listingWarning struct {
 	msg  string
 	args []any
@@ -306,7 +268,7 @@ type listingWarning struct {
 // failing the listing: one bad snapshot directory must not hide every
 // other snapshot the user has.
 func (v *Vaultik) describeRemoteOnlySnapshots(
-	keys []string, jsonOutput bool,
+	keys []string,
 ) ([]SnapshotInfo, int) {
 	found := make([]SnapshotInfo, len(keys))
 	ok := make([]bool, len(keys))
@@ -349,7 +311,7 @@ func (v *Vaultik) describeRemoteOnlySnapshots(
 
 	for i := range keys {
 		if warnings[i] != nil {
-			v.warnWhileListing(jsonOutput, warnings[i].msg, warnings[i].args...)
+			log.Warn(warnings[i].msg, warnings[i].args...)
 		}
 
 		if !ok[i] {

internal/vaultik/snapshot_list_test.go

@@ -521,16 +521,16 @@ func TestListSnapshots_JSONMergedView(t *testing.T) {
 // TestListSnapshots_JSONUnreachableRemote checks that a failed listing
 // does not corrupt the JSON document with warning text, and that
 // "unknown" is reported as null rather than as absence.
+//
+//nolint:paralleltest // captureProcessStderr replaces os.Stderr
 func TestListSnapshots_JSONUnreachableRemote(t *testing.T) {
-	log.Initialize(log.Config{})
-	t.Parallel()
-
 	env := newListEnv(t)
 	env.addLocal(t, listLocalID, time.Date(2026, 3, 1, 10, 0, 0, 0, time.UTC))
 	env.store.listErr = errRemoteUnreachable
 
-	err := env.v.ListSnapshots(true)
+	stderr := captureProcessStderr(t, func() {
-	require.NoError(t, err)
+		require.NoError(t, env.v.ListSnapshots(true))
+	})
 
 	// stdout must be nothing but the JSON document, so the warning has
 	// to go to stderr.
@@ -542,9 +542,8 @@ func TestListSnapshots_JSONUnreachableRemote(t *testing.T) {
 	assert.Nil(t, rows[0].RemotePresent,
 		"remote state is unknown when the destination cannot be listed")
 
-	assert.Contains(t, env.stderr.String(),
+	assert.Contains(t, stderr, "Could not list backup destination store")
-		"could not list backup destination store")
+	assert.Contains(t, stderr, "permission denied")
-	assert.Contains(t, env.stderr.String(), "permission denied")
 }
 
 // useNonUTCLocalZone points time.Local at a fixed non-UTC zone for the
@@ -635,10 +634,9 @@ func TestListSnapshots_TimestampsAreUTCOnNonUTCHost(t *testing.T) {
 // machine consumer would otherwise see no difference between "that
 // snapshot is not on the destination" and "that snapshot could not be
 // read".
+//
+//nolint:paralleltest // captureProcessStderr replaces os.Stderr
 func TestListSnapshots_JSONReportsUnreadableManifests(t *testing.T) {
-	log.Initialize(log.Config{})
-	t.Parallel()
-
 	env := newListEnv(t)
 
 	goodKey := env.addRemote(t, listRemoteID,
@@ -650,16 +648,18 @@ func TestListSnapshots_JSONReportsUnreadableManifests(t *testing.T) {
 		strings.NewReader("this is not a zstd stream"))
 	require.NoError(t, err)
 
-	err = env.v.ListSnapshots(true)
+	stderr := captureProcessStderr(t, func() {
-	require.NoError(t, err)
+		require.NoError(t, env.v.ListSnapshots(true))
+	})
 
 	rows := decodeListJSON(t, env.stdout.String())
 	require.Len(t, rows, 1)
 	assert.Equal(t, goodKey, rows[0].RemoteKey)
 
-	assert.Contains(t, env.stderr.String(),
+	assert.Contains(t, stderr, "could not be described",
-		"1 remote snapshot(s) could not be described",
 		"a row dropped from the JSON document must be announced somewhere")
+	assert.Contains(t, stderr, `"unreadable":1`,
+		"the count of dropped rows must be reported, not just the fact")
 }
 
 // maxRemoteOnlyRowsForTest mirrors the maxRemoteOnlyRows cap in the
@@ -671,10 +671,9 @@ const maxRemoteOnlyRowsForTest = 1000
 // truncation of a listing whose whole purpose is disaster recovery is
 // the wrong failure mode: the consumer least able to notice is exactly
 // the one reading JSON.
+//
+//nolint:paralleltest // captureProcessStderr replaces os.Stderr
 func TestListSnapshots_JSONReportsTruncation(t *testing.T) {
-	log.Initialize(log.Config{})
-	t.Parallel()
-
 	env := newListEnv(t)
 
 	timestamp := time.Date(2026, 3, 2, 11, 22, 33, 0, time.UTC)
@@ -684,25 +683,30 @@ func TestListSnapshots_JSONReportsTruncation(t *testing.T) {
 		env.addRemote(t, fmt.Sprintf("otherhost_bulk_%04d", i), timestamp)
 	}
 
-	err := env.v.ListSnapshots(true)
+	stderr := captureProcessStderr(t, func() {
-	require.NoError(t, err)
+		require.NoError(t, env.v.ListSnapshots(true))
+	})
 
 	rows := decodeListJSON(t, env.stdout.String())
 	assert.Len(t, rows, maxRemoteOnlyRowsForTest)
 
-	assert.Contains(t, env.stderr.String(), "listing truncated")
+	assert.Contains(t, stderr, "Listing truncated")
-	assert.Contains(t, env.stderr.String(), "1 further remote-only")
+	assert.Contains(t, stderr, `"omitted":1`)
+	assert.Contains(t, stderr,
+		fmt.Sprintf(`"limit":%d`, maxRemoteOnlyRowsForTest))
 }
 
 // captureProcessStdout redirects the process's own stdout to a pipe,
-// rebuilds the global logger over it, runs fn, and returns everything
+// rebuilds the global logger, runs fn, and returns everything written to
-// written.
+// the pipe.
 //
-// internal/log builds its logger over os.Stdout at construction time and
+// The logger is rebuilt on purpose even though it is supposed to write
-// offers no injectable sink (issue #82), so a warning logged during a
+// to stderr: that is exactly what makes this a regression guard. If the
-// --json listing lands on the process's real stdout, not on any writer a
+// logger ever goes back to os.Stdout, Initialize picks up the pipe and
-// test can inject. Capturing the file descriptor is therefore the only
+// the log record shows up in the capture, breaking the JSON parse here
-// way a test can see what `snapshot list --json | jq` would see.
+// the same way it would break `snapshot list --json | jq` in the field.
+// Without the rebuild, a regressed logger would write to the real stdout
+// the test process was started with and go unnoticed.
 //
 // Not parallel-safe: os.Stdout and the logger are process-global.
 func captureProcessStdout(t *testing.T, fn func(stdout io.Writer)) string {
@@ -714,8 +718,6 @@ func captureProcessStdout(t *testing.T, fn func(stdout io.Writer)) string {
 	previous := os.Stdout
 	os.Stdout = writer
 
-	// Rebuild the logger so it writes to the pipe rather than to the
-	// real stdout the test process was started with.
 	log.Initialize(log.Config{})
 
 	drained := make(chan string, 1)
@@ -738,7 +740,57 @@ func captureProcessStdout(t *testing.T, fn func(stdout io.Writer)) string {
 
 	require.NoError(t, reader.Close())
 
-	// Put the logger back on the restored stdout.
+	// Put the logger back on the restored streams.
+	log.Initialize(log.Config{})
+
+	return captured
+}
+
+// captureProcessStderr redirects the process's own stderr to a pipe,
+// rebuilds the global logger over it, runs fn, and returns everything
+// written.
+//
+// internal/log writes every diagnostic to os.Stderr and captures that
+// file at Initialize time, so a warning logged during a listing lands on
+// the process's real stderr, not on any writer a test can inject.
+// Capturing the file descriptor is therefore the only way a test can see
+// what the operator would see. The captured stream is a pipe rather than
+// a terminal, so the records are JSON — the same form a redirected
+// stderr gets in production.
+//
+// Not parallel-safe: os.Stderr and the logger are process-global.
+func captureProcessStderr(t *testing.T, fn func()) string {
+	t.Helper()
+
+	reader, writer, err := os.Pipe()
+	require.NoError(t, err)
+
+	previous := os.Stderr
+	os.Stderr = writer
+
+	log.Initialize(log.Config{})
+
+	drained := make(chan string, 1)
+
+	go func() {
+		var buf bytes.Buffer
+
+		_, _ = io.Copy(&buf, reader)
+
+		drained <- buf.String()
+	}()
+
+	fn()
+
+	os.Stderr = previous
+
+	require.NoError(t, writer.Close())
+
+	captured := <-drained
+
+	require.NoError(t, reader.Close())
+
+	// Put the logger back on the restored streams.
 	log.Initialize(log.Config{})
 
 	return captured
@@ -747,13 +799,18 @@ func captureProcessStdout(t *testing.T, fn func(stdout io.Writer)) string {
 // TestListSnapshots_JSONStdoutIsOnlyTheDocument is the regression guard
 // for `snapshot list --json | jq` surviving a damaged destination store.
 //
-// Every stdout writer the command has — the JSON encoder, the UI, and
+// Every stdout writer the command has — the JSON encoder and the UI —
-// the global logger — is pointed at one pipe here, exactly as they are
+// is pointed at one pipe here, exactly as they are pointed at one file
-// pointed at one file descriptor in production. A single log line about
+// descriptor in production, and the logger is rebuilt over that same
-// a corrupt manifest ahead of the array is enough to break the parse,
+// pipe's process-level stdout so that a logger which regressed back to
-// and that is what this asserts cannot happen.
+// stdout would land in the capture. A single log line about a corrupt
+// manifest ahead of the array is enough to break the parse, and that is
+// what this asserts cannot happen.
 //
-//nolint:paralleltest // replaces os.Stdout and the global logger
+// The two warnings are asserted on the separately captured stderr: they
+// must be emitted, just not there.
+//
+//nolint:paralleltest // replaces os.Stdout, os.Stderr and the logger
 func TestListSnapshots_JSONStdoutIsOnlyTheDocument(t *testing.T) {
 	env := newListEnv(t)
 
@@ -772,12 +829,16 @@ func TestListSnapshots_JSONStdoutIsOnlyTheDocument(t *testing.T) {
 	oddKey := env.addRemoteRawTimestamp(t,
 		"testhost_odd_2026-03-04T00:00:00Z", "the day before yesterday")
 
-	captured := captureProcessStdout(t, func(stdout io.Writer) {
+	var captured string
+
+	stderr := captureProcessStderr(t, func() {
+		captured = captureProcessStdout(t, func(stdout io.Writer) {
 			env.v.Stdout = stdout
 			env.v.UI = ui.NewWithColor(stdout, false)
 
 			require.NoError(t, env.v.ListSnapshots(true))
 		})
+	})
 
 	rows := decodeListJSON(t, captured)
 	require.Len(t, rows, 2, "the readable snapshots must both be listed")
@@ -794,8 +855,8 @@ func TestListSnapshots_JSONStdoutIsOnlyTheDocument(t *testing.T) {
 
 	// Both warnings were emitted, on the stream that cannot corrupt the
 	// document.
-	stderr := env.stderr.String()
 	assert.Contains(t, stderr, "Could not describe remote snapshot")
 	assert.Contains(t, stderr, "Remote manifest has an unparseable timestamp")
-	assert.Contains(t, stderr, "1 remote snapshot(s) could not be described")
+	assert.Contains(t, stderr, "could not be described")
+	assert.Contains(t, stderr, `"unreadable":1`)
 }

internal/vaultik/vaultik.go

@@ -43,7 +43,11 @@ type Vaultik struct {
 	ctx    context.Context //nolint:containedctx // ctx bound at construction by design
 	cancel context.CancelFunc
 
-	// IO
+	// IO. Stdout carries the output the user asked for and nothing else,
+	// so that `--json | jq` works. Stderr completes the standard triple
+	// for anything a command needs to write there directly; diagnostics
+	// are not that — they go through internal/log, which writes to the
+	// process's stderr.
 	Stdout io.Writer
 	Stderr io.Writer
 	Stdin  io.Reader