Quiet only the stdout UI under --json, not the log level (closes #112 )

--json was folded into Quiet, which pinned the stderr log level to WARN. So `prune --json` gave a machine consumer no record of the local index rows it deleted, even under --verbose: the audit records were gated off stdout and pinned below the level on stderr. --json now quiets only the stdout UI, keeping the JSON document clean (issue #108); the stderr log level follows --verbose/--debug again, since diagnostics have gone to stderr since #82. The same coupling is removed for `snapshot verify`, `snapshot remove`, and `remote info`, which carried it for the same outdated reason. A test asserts `--verbose prune --json` emits the cleanup record on stderr while stdout stays exactly one document, and that --json alone keeps it below the level. model: claude-opus-4-8
2026-09-21 23:06:25 +00:00
9 changed files with 195 additions and 54 deletions
@@ -63,7 +63,7 @@ A content-addressed unit of data. Files are split into variable-size chunks usin
 - `ChunkHash`: SHA256 hash of chunk content (primary key)
 - `Size`: Chunk size in bytes

-Chunk sizes vary between `avgChunkSize/4` and `avgChunkSize*4` (2.5MB-40MB for the 10MB default average).
+Chunk sizes vary between `avgChunkSize/4` and `avgChunkSize*4` (typically 16KB-256KB for 64KB average).

 #### FileChunk (`database.FileChunk`)
 Maps files to their constituent chunks:
@@ -120,7 +120,7 @@ The CLI uses fx for dependency injection. Here's the instantiation order:
 ```go
 // cli/app.go: NewApp()
 fx.New(
-    fx.Supply(config.Path(opts.ConfigPath)),         // 1. Config path
+    fx.Supply(config.ConfigPath(opts.ConfigPath)),  // 1. Config path
    fx.Supply(opts.LogOptions),                      // 2. Log options
    fx.Provide(globals.New),                         // 3. Globals
    fx.Provide(log.New),                             // 4. Logger config
@@ -193,7 +193,7 @@ scanner := v.ScannerFactory(snapshot.ScannerParams{
 - **Created by**: `chunker.NewChunker(avgChunkSize)`
 - **When**: Inside `snapshot.NewScanner()`
 - **Configuration**:
-  - `avgChunkSize`: From config (default 10MB)
+  - `avgChunkSize`: From config (typically 64KB)
  - `minChunkSize`: avgChunkSize / 4
  - `maxChunkSize`: avgChunkSize * 4

@@ -147,10 +147,10 @@ vaultik [--config <path>] config edit
 vaultik [--config <path>] config get <key>
 vaultik [--config <path>] config set <key> <value>
 vaultik [--config <path>] snapshot create [snapshot-names...] [--cron] [--prune] [--keep-newer-than <duration>]
-vaultik [--config <path>] snapshot list [--json]                  # alias: ls
+vaultik [--config <path>] snapshot list [--json]
 vaultik [--config <path>] snapshot verify <snapshot-id> [--deep] [--json]
 vaultik [--config <path>] snapshot purge [--keep-latest | --older-than <duration>] [--snapshot <name>...] [--force]
-vaultik [--config <path>] snapshot remove <snapshot-id> [--dry-run] [--force] [--local-only] [--json]  # alias: rm
+vaultik [--config <path>] snapshot remove <snapshot-id> [--dry-run] [--force] [--local-only] [--json]
 vaultik [--config <path>] snapshot restore <snapshot-id> <target-dir> [paths...] [--verify]
 vaultik [--config <path>] prune [--force] [--json]
 vaultik [--config <path>] info
@@ -169,21 +169,6 @@ vaultik version
 * `--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`)

-### locking
-
-Every command that opens the local index — `snapshot create`, `snapshot
-list`, `snapshot verify`, `snapshot purge`, `snapshot remove`, `snapshot
-restore`, `prune`, `info`, and `remote info`/`remote nuke` — takes a
-process-wide lock at `$XDG_DATA_HOME/vaultik/vaultik.pid`
-(`~/.local/share/vaultik/vaultik.pid` on Linux) for the whole run. Only
-one such command runs at a time: a second one exits immediately with an
-"already running" error rather than waiting. The lock is not scoped to
-mutating commands, so read-only commands are affected too — `vaultik
-snapshot list` fails while a backup is in progress; scoping it so
-read-only commands run during a backup is tracked in
-[issue #150](https://git.eeqj.de/sneak/vaultik/issues/150). `config`,
-`database delete`, `completion`, and `version` do not take the lock.
-
 ### stdout and stderr

 Log output — everything from `--verbose` and `--debug`, and every
@@ -218,8 +203,6 @@ and `vaultik prune --json | jq .` both work as written.
 * `VAULTIK_AGE_SECRET_KEY`: Age private key for decryption (required for `snapshot restore` and `snapshot verify --deep`)
 * `VAULTIK_CONFIG`: Path to config file (overridden by `--config`)
 * `VAULTIK_INDEX_PATH`: Override local SQLite index path
-* `VAULTIK_CPUPROFILE`: Write a CPU profile to this path for the duration of the run (development/debugging)
-* `VAULTIK_MEMPROFILE`: Write a heap profile to this path when the run exits (development/debugging)

 ### shell completion

@@ -412,10 +395,6 @@ both are set.

 ## architecture

-For an implementation-level view of the internals — the data model, the
-`fx` dependency-injection wiring, and the scanner — see
-[`ARCHITECTURE.md`](ARCHITECTURE.md).
-
 ### remote storage layout

 ```
@@ -493,24 +472,19 @@ derivation.

 ### compression

-* zstd compression at configurable level (1-19, default 3). The level is
-  accepted as 1-19 but maps onto zstd's four internal speed presets:
-  1-2 fastest, 3-5 default, 6-9 better, 10-19 best. Levels within the
-  same band compress identically.
+* zstd compression at configurable level (1-19, default 3)
 * Applied before encryption at the blob level

 ---

 ## configuration reference

-Run `vaultik config init` to generate a fully commented config file; a
-complete annotated example also lives in
-[`config.example.yml`](config.example.yml). Key fields:
+Run `vaultik config init` to generate a fully commented config file.
+Key fields:

 | Field | Default | Description |
 |-------|---------|-------------|
 | `age_recipients` | (required) | Age public keys for encryption |
-| `age_secret_key` | (unset) | Age private key for decryption (`snapshot restore`, `snapshot verify --deep`). Setting it in the config file places the private key on the backed-up host, defeating the public-key-only design (see "why" above). Prefer the `VAULTIK_AGE_SECRET_KEY` environment variable, supplied only on the machine you restore from. |
 | `snapshots` | (required) | Named snapshot definitions with paths and excludes |
 | `storage_url` | | Storage backend URL (`s3://`, `file://`, `rclone://`) |
 | `s3.*` | | Legacy S3 configuration (endpoint, bucket, credentials) |
@@ -626,17 +600,9 @@ priority.

 ## output style

-The operational narration of the long-running commands — the Begin,
-Complete, Progress, and status lines of `snapshot create`, `prune`,
-`snapshot restore`, and the like — goes through helpers in `internal/ui`
-and conforms to the uniform style below. Some commands instead write
-plain text straight to stdout (`version`, `info`, `config`, the
-`database delete` prompt, and the `snapshot list` table); that output is
-unstyled and does not honor `--quiet`. Routing it through `internal/ui`
-is tracked in
-[issue #149](https://git.eeqj.de/sneak/vaultik/issues/149). Color is
-enabled when stdout is a TTY and the `NO_COLOR` environment variable is
-unset (https://no-color.org/).
+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
@@ -25,6 +25,17 @@ release" is exactly the contradiction

 # Completed Steps

+- 2026-09-21: Stopped `--json` from silencing stderr diagnostics
+  ([issue #112](https://git.eeqj.de/sneak/vaultik/issues/112)). `--json`
+  used to be folded into `Quiet`, which pinned the log level to `WARN`,
+  so `prune --json` gave a machine consumer no record of the local index
+  rows it deleted even under `--verbose`. `--json` now quiets only the
+  stdout UI (the JSON document must stay clean, per
+  [issue #108](https://git.eeqj.de/sneak/vaultik/issues/108)); the stderr
+  log level follows `--verbose`/`--debug` again. The coupling was
+  removed the same way for `snapshot verify`, `snapshot remove`, and
+  `remote info`, which carried it for the same outdated reason.
+
 - 2026-09-21: Stopped `prune` from reporting a failed row count as 0
  ([issue #96](https://git.eeqj.de/sneak/vaultik/issues/96)). The seven
  `getTableCount` reads in `PruneDatabase` discarded their error, so a
@@ -49,6 +49,11 @@ type AppOptions struct {
 // silenced — per the documented convention that --quiet suppresses
 // non-error output only. The startup banner is printed by Entry
 // before cobra parses arguments, gated by the same arg-level check.
+//
+// --json quiets the UI here too, because stdout then carries a JSON
+// document and human narration would corrupt it. Unlike Quiet it does
+// not lower the stderr log level (issue #112), so --verbose/--debug
+// still surface diagnostics alongside the document.
 func setupGlobals(
 	lc fx.Lifecycle, g *globals.Globals, v *vaultik.Vaultik, opts log.Options,
 ) {
@@ -56,7 +61,7 @@ func setupGlobals(
 		OnStart: func(_ context.Context) error {
 			g.StartTime = time.Now().UTC()

-			if opts.Cron || opts.Quiet {
+			if opts.Cron || opts.Quiet || opts.JSON {
 				v.UI.SetQuiet(true)
 			}

@@ -279,10 +284,11 @@ func RunOperation(
 // shared by the list/purge/verify/remove/remote-info subcommands:
 // resolve the config, then run op against the Vaultik instance through
 // RunOperation, reporting a failure prefixed with failMsg (suppressed
-// while suppressErrors is true, e.g. under --json). extraQuiet is OR-ed
-// into LogOptions.Quiet (e.g. --json output modes).
+// while suppressErrors is true, e.g. under --json). jsonOutput marks a
+// command whose stdout is a JSON document: it quiets the UI but, unlike
+// Quiet, leaves the stderr log level alone.
 func runVaultikApp(
-	cmd *cobra.Command, extraQuiet, suppressErrors bool,
+	cmd *cobra.Command, jsonOutput, suppressErrors bool,
 	failMsg string, op func(v *vaultik.Vaultik) error,
 ) error {
 	configPath, err := ResolveConfigPath()
@@ -297,7 +303,8 @@ func runVaultikApp(
 		LogOptions: log.Options{
 			Verbose: rootFlags.Verbose,
 			Debug:   rootFlags.Debug,
-			Quiet:   rootFlags.Quiet || extraQuiet,
+			Quiet:   rootFlags.Quiet,
+			JSON:    jsonOutput,
 		},
 	}, op, func(err error) {
 		if suppressErrors {
@@ -0,0 +1,140 @@
+package cli //nolint:testpackage // shares the prune fixtures and capture helpers
+
+import (
+	"bytes"
+	"io"
+	"os"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+// staleRecordLogMessage is the local-cleanup audit line CleanupLocalSnapshots
+// logs for each stale record. It is exactly the signal issue #112 says a
+// machine consumer lost under --json: gated off stdout, and pinned below
+// the log level on stderr because --json used to force Quiet.
+const staleRecordLogMessage = "Removing stale local snapshot record"
+
+// TestEntryPruneJSONStderrHonoursVerbosity is the end-to-end regression
+// guard for issue #112. Under --json the log level must still follow
+// --verbose/--debug rather than being pinned to WARN, so the
+// local-cleanup records reach stderr under --verbose while stdout stays
+// exactly one JSON document; without --verbose they stay below the
+// level, as they do without --json.
+//
+// Both halves are asserted together on the same run, because the fix has
+// to keep the document clean (issue #108) while freeing stderr.
+//
+// Not parallel: it replaces os.Args, os.Stdout, os.Stderr and the xdg
+// globals.
+//
+//nolint:paralleltest // replaces os.Args, os.Stdout, os.Stderr and the xdg globals
+func TestEntryPruneJSONStderrHonoursVerbosity(t *testing.T) {
+	for _, testCase := range []struct {
+		name         string
+		verbose      bool
+		wantOnStderr bool
+	}{
+		{
+			name:         "verbose json surfaces the cleanup record on stderr",
+			verbose:      true,
+			wantOnStderr: true,
+		},
+		{
+			name:         "json alone keeps the cleanup record below the level",
+			verbose:      false,
+			wantOnStderr: false,
+		},
+	} {
+		t.Run(testCase.name, func(t *testing.T) {
+			configPath := writeHermeticPruneConfig(t, true)
+
+			previousArgs := os.Args
+
+			t.Cleanup(func() {
+				os.Args = previousArgs
+				rootFlags = RootFlags{}
+			})
+
+			args := []string{
+				programName, flagConfig, configPath, cmdPrune, flagJSON,
+			}
+			if testCase.verbose {
+				args = append(args, "--verbose")
+			}
+
+			os.Args = args
+
+			stdout, stderr := captureProcessStdoutAndStderr(t,
+				func() { _ = Entry() })
+
+			// The document stays clean in both cases: freeing stderr must
+			// not regress issue #108.
+			requireExactlyOneJSONDocument(t, stdout)
+
+			if testCase.wantOnStderr {
+				assert.Contains(t, stderr, staleRecordLogMessage,
+					"--verbose --json must emit the cleanup record on stderr")
+				assert.Contains(t, stderr, stalePruneSnapshotID,
+					"the record must name the snapshot it removed")
+			} else {
+				assert.NotContains(t, stderr, staleRecordLogMessage,
+					"without --verbose the record stays below the log level")
+			}
+		})
+	}
+}
+
+// captureProcessStdoutAndStderr redirects both of the process's own
+// standard streams to pipes for the duration of fn and returns what was
+// written to each. The redirection is at the file-descriptor level
+// because the logger binds os.Stderr when it initializes inside fn, and
+// the JSON document reaches os.Stdout independently; the point is to see
+// where each actually lands.
+//
+// Not parallel-safe: os.Stdout and os.Stderr are process-global.
+func captureProcessStdoutAndStderr(t *testing.T, fn func()) (string, string) {
+	t.Helper()
+
+	outReader, outWriter, err := os.Pipe()
+	require.NoError(t, err)
+
+	errReader, errWriter, err := os.Pipe()
+	require.NoError(t, err)
+
+	previousOut, previousErr := os.Stdout, os.Stderr
+	os.Stdout, os.Stderr = outWriter, errWriter
+
+	capturedOut := drain(outReader)
+	capturedErr := drain(errReader)
+
+	fn()
+
+	os.Stdout, os.Stderr = previousOut, previousErr
+
+	require.NoError(t, outWriter.Close())
+	require.NoError(t, errWriter.Close())
+
+	out, errOut := <-capturedOut, <-capturedErr
+
+	require.NoError(t, outReader.Close())
+	require.NoError(t, errReader.Close())
+
+	return out, errOut
+}
+
+// drain copies a reader to a string on a goroutine and delivers the
+// result once the writer end is closed.
+func drain(reader io.Reader) <-chan string {
+	captured := make(chan string, 1)
+
+	go func() {
+		var buf bytes.Buffer
+
+		_, _ = io.Copy(&buf, reader)
+		captured <- buf.String()
+	}()
+
+	return captured
+}
@@ -41,7 +41,8 @@ work (e.g. after a crashed backup or to reclaim storage).`,
 				LogOptions: log.Options{
 					Verbose: rootFlags.Verbose,
 					Debug:   rootFlags.Debug,
-					Quiet:   rootFlags.Quiet || opts.JSON,
+					Quiet:   rootFlags.Quiet,
+					JSON:    opts.JSON,
 				},
 			}, func(v *vaultik.Vaultik) error {
 				return v.Prune(opts)
@@ -85,7 +85,8 @@ func newRemoteInfoCommand() *cobra.Command {
 				LogOptions: log.Options{
 					Verbose: rootFlags.Verbose,
 					Debug:   rootFlags.Debug,
-					Quiet:   rootFlags.Quiet || jsonOutput,
+					Quiet:   rootFlags.Quiet,
+					JSON:    jsonOutput,
 				},
 			}, func(v *vaultik.Vaultik) error {
 				return v.RemoteInfo(jsonOutput)
@@ -209,7 +209,8 @@ func newSnapshotVerifyCommand() *cobra.Command {
 				LogOptions: log.Options{
 					Verbose: rootFlags.Verbose,
 					Debug:   rootFlags.Debug,
-					Quiet:   rootFlags.Quiet || opts.JSON,
+					Quiet:   rootFlags.Quiet,
+					JSON:    opts.JSON,
 				},
 			}, func(v *vaultik.Vaultik) error {
 				return v.VerifySnapshotWithOptions(snapshotID, opts)
@@ -14,8 +14,18 @@ var Module = fx.Module("log",
 )

 // New creates a new logger configuration from provided options.
+//
+// JSON is intentionally not carried into Config: a command emitting a
+// JSON document on stdout must keep its stderr log level under
+// --verbose/--debug, so --json must not lower it (issue #112). JSON
+// silences the stdout UI in setupGlobals instead.
 func New(opts Options) Config {
-	return Config(opts)
+	return Config{
+		Verbose: opts.Verbose,
+		Debug:   opts.Debug,
+		Cron:    opts.Cron,
+		Quiet:   opts.Quiet,
+	}
 }

 // Options are provided by the CLI.
@@ -24,4 +34,8 @@ type Options struct {
 	Debug   bool
 	Cron    bool
 	Quiet   bool
+	// JSON marks a command whose stdout carries a machine-readable
+	// document. It silences the human UI on stdout (see setupGlobals),
+	// but unlike Quiet it leaves the stderr log level alone.
+	JSON bool
 }