Send diagnostics to stderr and stop dropping log attributes (closes #82, closes #97) #107

clawbot · 2026-08-09T18:29:21+02:00

clawbot commented

2026-08-09 18:29:21 +02:00

Two defects in internal/log, fixed in one pass because both live in
the handler construction path.

USER-VISIBLE CHANGE: `--verbose` and `--debug` output moves to stderr

All log output now goes to stderr. That includes everything from
--verbose and --debug, not just warnings and errors.

vaultik snapshot list --verbose > out.txt used to capture the
diagnostics along with the listing. It no longer does — they stay on the
terminal. Capturing both now needs > out.txt 2> log.txt, or
> out.txt 2>&1 to interleave them. Anyone with a script or a cron
wrapper that redirects only stdout and expects the log in the file will
see the change.

This is the intended contract rather than a side effect: stdout carries
the output that was asked for, stderr carries diagnostics. README.md
gains a "stdout and stderr" section stating it, and the --verbose /
--debug flag entries point at it.

#82: the logger wrote to stdout

Initialize built both handlers over os.Stdout. Every --json
subcommand writes its document to that same stream, and WARN/ERROR
are never suppressed by any flag, so a log record could land inside a
JSON document and break the parse.

Reproduced against main with the trigger from the report — a config
file at mode 0644, which fires the insecure-permissions WARN in
internal/config:

$ vaultik -q --config /tmp/demo/config.yml snapshot list --json
{"time":"...","level":"WARN","msg":"Config file has insecure permissions (contains S3 credentials)",...}
[]

$ ... | python3 -c 'import json,sys; json.load(sys.stdin)'
json.decoder.JSONDecodeError: Extra data: line 2 column 1 (char 279)

Same config, same command, this branch:

$ vaultik -q --config /tmp/demo/config.yml snapshot list --json
[]

with the WARN on stderr, and json.load accepting stdout.

The TTY/JSON format choice moved to os.Stderr along with the sink. It
has to follow the stream the records land on: testing stdout would
colorize records on a redirected stderr whenever stdout happened to be a
terminal, and emit JSON at a terminal in the reverse case.

--quiet and --cron semantics are unchanged. Level selection is not
touched, ui.Writer's quiet handling is not touched, and the run above
used -q — the warning still fired, which is the documented behaviour
(see issue #84):
UI.SetQuiet(true) suppresses Begin/Complete/Info/Notice/Detail/
Progress/Banner and never Warning/Error.

The `snapshot_list.go` workaround is gone

warnWhileListing was hand-rolling structured-log formatting
(fmt.Fprintf(&line, " %v=%v", ...) and a kvPairSize constant) purely
to reach a writer that was not stdout, and the jsonOutput parameter
threaded through collectRemoteSnapshots and
describeRemoteOnlySnapshots existed only to pick between the two
writers. Both are deleted; those warnings go through log.Warn in every
mode. reportJSONListingLimits likewise moved from
fmt.Fprintf(v.Stderr, ...) to log.Warn with structured fields.

warnRemoteListingFailed keeps its jsonOutput branch, for a reason
that is still true after this change and is now what the comment says:
table mode wants the prose v.UI.Warningf line, and v.UI writes to
stdout, so --json mode goes through the logger instead.

The listingWarning collect-then-emit machinery stays, with a
rewritten rationale. Its original justification — the chosen writer is
not safe for concurrent use — is obsolete, since slog handlers are.
What remains is ordering: emitting from the manifest-fetch workers would
order warnings by network timing, while collecting them and emitting in
key order after group.Wait() makes two runs over the same damaged
store produce the same diagnostics in the same order. No comment
anywhere still refers to this as pending work.

#97: `TTYHandler` discarded `WithAttrs` and `WithGroup`

Both returned the receiver and dropped their argument while their doc
comments claimed otherwise. Because the handler is selected by TTY-ness,
attributes vanished on a terminal and were correct in CI — it failed
precisely when someone was debugging interactively.

WithAttrs retains the attributes and emits them on every subsequent
record.
WithGroup is implemented rather than deferred: this format is one
line with nowhere to nest, so a group becomes a dotted key prefix
(WithGroup("db").With("rows", 3) renders db.rows=3). Record-level
slog.KindGroup values flatten the same way. Empty attrs are dropped
and an empty-key group is inlined, per the slog.Handler contract.
Both return a new handler. The receiver is never written to, and
the clone copies its slices rather than reslicing them, so two
concurrent derivations cannot append over each other's attribute. The
mutex became a *sync.Mutex so handlers sharing a stream keep sharing
one lock — a value mutex would have given every derived handler its
own and stopped serializing writes.
The // Simplified for now comments are gone, and the doc comments
now describe what the code does.

The tests fail against the unfixed handler

Verified by observation, not assumption: internal/log/tty_handler.go
was reverted to its main version with the new tests in place, and
make test reported

--- FAIL: TestWithAttributesReachTTYOutput
--- FAIL: TestTTYHandlerWithAttrsEmitsAttributes
--- FAIL: TestTTYHandlerWithAttrsPersistsAcrossRecords
--- FAIL: TestTTYHandlerWithGroupQualifiesKeys
--- FAIL: TestTTYHandlerWithAttrsDoesNotMutateReceiver
--- FAIL: TestTTYHandlerConcurrentDerivation
--- FAIL: TestTTYHandlerEmptyGroupAndAttrsAreNoOps
--- FAIL: TestTTYHandlerMatchesJSONHandlerAttributes
    --- FAIL: .../handler_attributes
    --- FAIL: .../handler_attributes_accumulate
    --- FAIL: .../group_qualifies_later_attributes
    --- FAIL: .../nested_groups
    --- FAIL: .../attributes_before_and_after_a_group
    --- FAIL: .../inline_group_value_on_the_record
FAIL	sneak.berlin/go/vaultik/internal/log

The handler was then restored and the suite went green.

TestWithAttributesReachTTYOutput goes through the exported
internal/log.With, which is the reachable API the issue names. It is an
in-package test because that is the only way to point the package logger
at a buffer; //nolint:testpackage carries the reason.

TestTTYHandlerMatchesJSONHandlerAttributes feeds both handlers the same
derivation chain and the same record and compares the emitted attribute
sets, flattening JSONHandler's nesting to the same dotted keys. That is
the drift guard the issue asks for.

Existing tests

Four internal/vaultik tests asserted these warnings on the injected
v.Stderr buffer. They now capture the process's real stderr through a
new captureProcessStderr helper, since that is where the warnings go;
the guarantees asserted are unchanged. captureProcessStdout keeps
rebuilding the logger on purpose — that is what would catch a logger
regressing back to stdout — and its doc comment no longer cites
issue #82 as the reason
no injectable sink exists.

Found while verifying, filed not fixed

Issue #106: the startup
banner is written to stdout by internal/cli/entry.go before cobra
parses anything, and bannerSuppressedInArgs recognizes only
--quiet/-q/--cron, not --json. So every --json document is
still preceded by two banner lines and a blank line unless -q is
passed. That is a different writer on a different path from the logger,
so it is filed rather than fixed here — but it means stdout is not fully
clean until that one lands too. The reproductions above use -q for
that reason.

Verification

make check: green. Tests, lint, and fmt-check all pass; the only
linter output is the gomodguard deprecation already tracked as
issue #90.
script/cibuild: exit 0, 140s wall. The three check layers executed
rather than replaying from cache (make fmt-check 2.4s, make lint
40.4s, make test 58.5s under the fresh CHECK_EPOCH); the 10
CACHED layers are dependency and module layers. 14 ok lines, zero
(cached) markers.
End-to-end with a real 0644 config and a file:// destination, before
and after, as shown above.
.golangci.yml unchanged: sha256
021cc83f4e6fc7c31b95b34b846723dfcf20b66b7baeea1dc40406e643346bcb.
No tags created; git tag -l is empty.

Closes [issue #82](https://git.eeqj.de/sneak/vaultik/issues/82). Closes [issue #97](https://git.eeqj.de/sneak/vaultik/issues/97). Two defects in `internal/log`, fixed in one pass because both live in the handler construction path. ## USER-VISIBLE CHANGE: `--verbose` and `--debug` output moves to stderr All log output now goes to stderr. That includes everything from `--verbose` and `--debug`, not just warnings and errors. `vaultik snapshot list --verbose > out.txt` used to capture the diagnostics along with the listing. It no longer does — they stay on the terminal. Capturing both now needs `> out.txt 2> log.txt`, or `> out.txt 2>&1` to interleave them. Anyone with a script or a cron wrapper that redirects only stdout and expects the log in the file will see the change. This is the intended contract rather than a side effect: stdout carries the output that was asked for, stderr carries diagnostics. `README.md` gains a "stdout and stderr" section stating it, and the `--verbose` / `--debug` flag entries point at it. ## #82: the logger wrote to stdout `Initialize` built both handlers over `os.Stdout`. Every `--json` subcommand writes its document to that same stream, and `WARN`/`ERROR` are never suppressed by any flag, so a log record could land inside a JSON document and break the parse. Reproduced against `main` with the trigger from the report — a config file at mode 0644, which fires the insecure-permissions `WARN` in `internal/config`: ``` $ vaultik -q --config /tmp/demo/config.yml snapshot list --json {"time":"...","level":"WARN","msg":"Config file has insecure permissions (contains S3 credentials)",...} [] $ ... | python3 -c 'import json,sys; json.load(sys.stdin)' json.decoder.JSONDecodeError: Extra data: line 2 column 1 (char 279) ``` Same config, same command, this branch: ``` $ vaultik -q --config /tmp/demo/config.yml snapshot list --json [] ``` with the `WARN` on stderr, and `json.load` accepting stdout. The TTY/JSON format choice moved to `os.Stderr` along with the sink. It has to follow the stream the records land on: testing stdout would colorize records on a redirected stderr whenever stdout happened to be a terminal, and emit JSON at a terminal in the reverse case. `--quiet` and `--cron` semantics are unchanged. Level selection is not touched, `ui.Writer`'s quiet handling is not touched, and the run above used `-q` — the warning still fired, which is the documented behaviour (see [issue #84](https://git.eeqj.de/sneak/vaultik/issues/84)): `UI.SetQuiet(true)` suppresses Begin/Complete/Info/Notice/Detail/ Progress/Banner and never Warning/Error. ### The `snapshot_list.go` workaround is gone `warnWhileListing` was hand-rolling structured-log formatting (`fmt.Fprintf(&line, " %v=%v", ...)` and a `kvPairSize` constant) purely to reach a writer that was not stdout, and the `jsonOutput` parameter threaded through `collectRemoteSnapshots` and `describeRemoteOnlySnapshots` existed only to pick between the two writers. Both are deleted; those warnings go through `log.Warn` in every mode. `reportJSONListingLimits` likewise moved from `fmt.Fprintf(v.Stderr, ...)` to `log.Warn` with structured fields. `warnRemoteListingFailed` keeps its `jsonOutput` branch, for a reason that is still true after this change and is now what the comment says: table mode wants the prose `v.UI.Warningf` line, and `v.UI` writes to stdout, so `--json` mode goes through the logger instead. The `listingWarning` collect-then-emit machinery **stays**, with a rewritten rationale. Its original justification — the chosen writer is not safe for concurrent use — is obsolete, since `slog` handlers are. What remains is ordering: emitting from the manifest-fetch workers would order warnings by network timing, while collecting them and emitting in key order after `group.Wait()` makes two runs over the same damaged store produce the same diagnostics in the same order. No comment anywhere still refers to this as pending work. ## #97: `TTYHandler` discarded `WithAttrs` and `WithGroup` Both returned the receiver and dropped their argument while their doc comments claimed otherwise. Because the handler is selected by TTY-ness, attributes vanished on a terminal and were correct in CI — it failed precisely when someone was debugging interactively. - `WithAttrs` retains the attributes and emits them on every subsequent record. - `WithGroup` is implemented rather than deferred: this format is one line with nowhere to nest, so a group becomes a dotted key prefix (`WithGroup("db").With("rows", 3)` renders `db.rows=3`). Record-level `slog.KindGroup` values flatten the same way. Empty attrs are dropped and an empty-key group is inlined, per the `slog.Handler` contract. - Both return a **new** handler. The receiver is never written to, and the clone copies its slices rather than reslicing them, so two concurrent derivations cannot append over each other's attribute. The mutex became a `*sync.Mutex` so handlers sharing a stream keep sharing one lock — a value mutex would have given every derived handler its own and stopped serializing writes. - The `// Simplified for now` comments are gone, and the doc comments now describe what the code does. ### The tests fail against the unfixed handler Verified by observation, not assumption: `internal/log/tty_handler.go` was reverted to its `main` version with the new tests in place, and `make test` reported ``` --- FAIL: TestWithAttributesReachTTYOutput --- FAIL: TestTTYHandlerWithAttrsEmitsAttributes --- FAIL: TestTTYHandlerWithAttrsPersistsAcrossRecords --- FAIL: TestTTYHandlerWithGroupQualifiesKeys --- FAIL: TestTTYHandlerWithAttrsDoesNotMutateReceiver --- FAIL: TestTTYHandlerConcurrentDerivation --- FAIL: TestTTYHandlerEmptyGroupAndAttrsAreNoOps --- FAIL: TestTTYHandlerMatchesJSONHandlerAttributes --- FAIL: .../handler_attributes --- FAIL: .../handler_attributes_accumulate --- FAIL: .../group_qualifies_later_attributes --- FAIL: .../nested_groups --- FAIL: .../attributes_before_and_after_a_group --- FAIL: .../inline_group_value_on_the_record FAIL sneak.berlin/go/vaultik/internal/log ``` The handler was then restored and the suite went green. `TestWithAttributesReachTTYOutput` goes through the exported `internal/log.With`, which is the reachable API the issue names. It is an in-package test because that is the only way to point the package logger at a buffer; `//nolint:testpackage` carries the reason. `TestTTYHandlerMatchesJSONHandlerAttributes` feeds both handlers the same derivation chain and the same record and compares the emitted attribute sets, flattening `JSONHandler`'s nesting to the same dotted keys. That is the drift guard the issue asks for. ## Existing tests Four `internal/vaultik` tests asserted these warnings on the injected `v.Stderr` buffer. They now capture the process's real stderr through a new `captureProcessStderr` helper, since that is where the warnings go; the guarantees asserted are unchanged. `captureProcessStdout` keeps rebuilding the logger on purpose — that is what would catch a logger regressing back to stdout — and its doc comment no longer cites [issue #82](https://git.eeqj.de/sneak/vaultik/issues/82) as the reason no injectable sink exists. ## Found while verifying, filed not fixed [Issue #106](https://git.eeqj.de/sneak/vaultik/issues/106): the startup banner is written to stdout by `internal/cli/entry.go` before cobra parses anything, and `bannerSuppressedInArgs` recognizes only `--quiet`/`-q`/`--cron`, not `--json`. So every `--json` document is still preceded by two banner lines and a blank line unless `-q` is passed. That is a different writer on a different path from the logger, so it is filed rather than fixed here — but it means stdout is not fully clean until that one lands too. The reproductions above use `-q` for that reason. ## Verification - `make check`: green. Tests, lint, and fmt-check all pass; the only linter output is the `gomodguard` deprecation already tracked as [issue #90](https://git.eeqj.de/sneak/vaultik/issues/90). - `script/cibuild`: exit 0, 140s wall. The three check layers executed rather than replaying from cache (`make fmt-check` 2.4s, `make lint` 40.4s, `make test` 58.5s under the fresh `CHECK_EPOCH`); the 10 `CACHED` layers are dependency and module layers. 14 `ok` lines, zero `(cached)` markers. - End-to-end with a real 0644 config and a `file://` destination, before and after, as shown above. - `.golangci.yml` unchanged: sha256 `021cc83f4e6fc7c31b95b34b846723dfcf20b66b7baeea1dc40406e643346bcb`. - No tags created; `git tag -l` is empty.

clawbot added 1 commit 2026-08-09 18:29:21 +02:00

Send diagnostics to stderr and stop dropping log attributes (closes #82 )

check / check (pull_request) Successful in 2m34s

Details

b7aee81fa5

Two defects in internal/log, fixed together because both live in the
handler construction path.

Logger on stdout (#82). Initialize built both handlers over os.Stdout.
Every --json subcommand writes its document to that same stream, and
WARN/ERROR are never suppressed by any flag, so a log record could land
inside a JSON document and break the parse. This was not theoretical: a
config file with group- or world-readable permissions triggers a WARN
during startup, which was enough to make `snapshot list --json | jq`
fail. Diagnostics now go to stderr, and the TTY/JSON format choice
follows stderr's TTY-ness rather than stdout's -- testing the wrong
stream would colorize records on a redirected stderr whenever stdout
happened to be a terminal, and emit JSON to a terminal in the reverse
case.

This is user-visible: --verbose and --debug output moves to stderr as
well, so `vaultik snapshot list -v > out.txt` no longer captures the
diagnostics. README.md documents the split under a new "stdout and
stderr" section. --quiet and --cron semantics are untouched: level
selection is unchanged, and warnings and errors are still emitted in
both modes.

It also retires the local workaround in internal/vaultik/snapshot_list.go.
warnWhileListing had been hand-rolling structured-log formatting to reach
a writer that was not stdout, and the jsonOutput parameter threaded
through the remote-listing helpers existed only to choose between the two
writers; both are gone, and those warnings go through log.Warn in every
mode. The collect-then-emit machinery around listingWarning stays, on
its remaining merit rather than its original one: slog handlers are safe
for concurrent use, but emitting from the manifest-fetch workers would
order warnings by network timing, where collecting and emitting in key
order after group.Wait makes two runs over the same damaged store
produce the same diagnostics in the same order.

TTYHandler dropped attributes (#97). WithAttrs and WithGroup discarded
their arguments and returned the receiver, while their doc comments
claimed the opposite. Because the handler is chosen by TTY-ness, this
failed only on a terminal and worked correctly in CI -- so it broke
exactly when someone was debugging interactively. Both now return a new
handler: the receiver is never written to, since slog permits a handler
to be shared and derived from concurrently, and the derived handler
copies its slices rather than reslicing so two concurrent derivations
cannot overwrite each other's attributes. The mutex became a pointer so
handlers sharing a stream keep sharing one lock. Attributes persist
across every subsequent record, and grouping is implemented as dotted
key prefixes, which is the only honest rendering for a format with
nowhere to nest.

Tests: an attribute attached through the exported log.With reaches
TTYHandler output; attributes persist across records; groups qualify
keys; deriving does not leak between siblings or back to the parent;
sixteen goroutines derive from and write through one handler under
-race; and the TTY and JSON handlers are fed identical derivation chains
and compared attribute set by attribute set, which is the test that
would have caught the original defect and the one that stops the two
paths drifting again. All of these fail against the unfixed handler.

The existing snapshot-list tests that asserted these warnings on an
injected writer now capture the process's real stderr, which is where
they go; the assertions are otherwise unchanged.

clawbot referenced this pull request

2026-08-09 18:29:42 +02:00

Logger writes to stdout, so any warning corrupts --json output #82

clawbot referenced this pull request

2026-08-09 18:30:03 +02:00

TTYHandler silently discards log.With attributes, so diagnostics differ between terminal and CI #97

clawbot added the needs-review label 2026-08-09 18:30:53 +02:00

clawbot commented

2026-08-09 18:43:02 +02:00

Review: PASS

Independent review of
PR #107 against
issue #82 and
issue #97.

Blocking findings

None.

Verified

#97 handler correctness. WithAttrs/WithGroup never write to
the receiver; clone() copies rather than reslices attrs/groups,
so concurrent derivation from one parent cannot interleave appends.
The *sync.Mutex is load-bearing — TestTTYHandlerConcurrentDerivation
has 16 goroutines writing through derived handlers into one
bytes.Buffer, which is only safe because the pointer is shared. The
slog.Handler contract corners are right: WithGroup("") and
WithAttrs(nil) return the receiver, empty Attr dropped, empty
group dropped, empty-key group inlined, KindGroup record values
flattened. Nested groups, group-then-attrs, and attrs straddling a
group all match slog.JSONHandler under the dotted-key flattening.
Resolving LogValuer at WithAttrs time rather than Handle time is
a deviation from the naive reading but matches what stdlib's own
handlers do via preformattedAttrs — correct, noted because it
surprises.
Revert-and-run reproduced, not taken on trust. tty_handler.go
reverted to main in a scratch worktree with the new tests in place:
8 top-level FAILs and 6 of 7
TestTTYHandlerMatchesJSONHandlerAttributes subtests fail
(record_attributes_only passes, as it must — it exercises no
derivation). Every other package stayed green. Matches the PR body
exactly.
#82 stream change. No writer in internal/log targets stdout any
more. Keying the TTY/JSON choice on os.Stderr is correct: a
redirected stderr now gets jsonl even when stdout is a terminal, which
is the property that matters (see nit 1 on the doc text).
Workaround removal loses nothing. Initialize sets LevelWarn
under --quiet/--cron, so the log.Warn calls in
reportJSONListingLimits still fire in the exact -q --json mode the
reproduction uses — the truncation and unreadable-manifest counts are
not regressed from
PR #83's finding 2, and
the tests now assert the counts as "unreadable":1 / "omitted":1 /
"limit":1000 rather than only the prose, which is stronger than
before. warnRemoteListingFailed's --json branch is still justified
(v.UI writes to stdout). The listingWarning collect-then-emit
rationale holds: worker-order emission would vary with fetch timing,
and the rewritten comment says exactly that and explicitly retires the
obsolete concurrency-safety reason.
--quiet/--cron semantics unchanged; level selection and
ui.Writer untouched.
No claim of a fully clean --json stdout — the PR body, the TODO
entry and the issue comment all name
issue #106 as the
remaining stdout contamination.
Nothing weakened. .golangci.yml sha256 matches
021cc83f…46bcb; Dockerfile, script/*, REPO_POLICIES.md,
.gitea/, Makefile byte-identical to main. No test function
deleted; 10 assertions removed, 16 added.
CI green on b7aee81 (check / check, success in 2m34s).
Mergeable against main, no conflicts.
script/cibuild: exit 0, 314s wall, fresh CHECK_EPOCH; the
check layers executed rather than replayed — make fmt-check 5.4s,
make lint 102.1s (0 issues.), make test 132.1s — 14 ok lines,
zero (cached) markers; the 14 CACHED layers are dependency/module
layers. The only lint output is the gomodguard deprecation already
tracked as issue #90.
-race clean.
No Claude/Anthropic references or attribution trailers anywhere in the
diff or commit. No tags on origin. Naming, no-stutter, inclusive
terminology, make fmt clean.

Nits (non-blocking)

AGENTS.md policy 9 now contradicts the code. Lines 86-87 still
read "If stdout is not a terminal, output the structured logs in
jsonl format." After this change the format follows stderr, so with
vaultik snapshot list --json | jq at a terminal, stdout is not a
terminal and the logs are colorized rather than jsonl — a literal
deviation from the written rule. internal/log/log.go argues the
reinterpretation in a code comment, and I agree the policy's
operative content ("when the log destination is unwatched, make it
machine-readable") is faithfully preserved; keying on stdout after
moving the sink would put ANSI escapes on a redirected stderr, which
is plainly worse. Judgement call, stated plainly: I did not treat
this as an iron-rule failure, because the rule said "stdout" only
because that is where logs used to go. But AGENTS.md is what the
next agent will read, and it now says something false — it should get
the one-line amendment to "the log stream". Owner's call whether that
lands here or separately.
Vaultik.Stderr now has zero production writers. After
warnWhileListing and the fmt.Fprintf(v.Stderr, …) calls went
away, the field is only assigned in constructors and tests;
env.stderr in snapshot_list_test.go likewise has no readers left.
vaultik.go documents the field as deliberately kept to "complete
the standard triple", so this is a choice rather than an oversight —
flagging only so it is a known one.
TODO.md line ~328 (a dated historical entry from earlier work)
still says "still a local workaround pending issue #82". Read as an
immutable history record it is fine, and the new entry supersedes it;
noted only because the PR body claims nothing anywhere still cites
issue #82 as pending —
that is true of code comments, not of TODO.md history.
bytesAttrKey special-casing does not survive grouping. An
int64 attribute named bytes under WithGroup("x") has key
x.bytes by the time writeAttr compares, so it renders as a raw
number rather than a human byte count. Unreachable today — nothing
in the tree calls WithGroup — and arguably the more predictable
behaviour. Mentioned for the record.
The PR body closes
issue #97 as
Closes [issue #97](…); Gitea's auto-close parser may not match a
keyword followed by a markdown link, and the landing commit title
carries only (closes #82). Worth confirming
issue #97 actually
closes on merge rather than assuming.

## Review: PASS Independent review of [PR #107](https://git.eeqj.de/sneak/vaultik/pulls/107) against [issue #82](https://git.eeqj.de/sneak/vaultik/issues/82) and [issue #97](https://git.eeqj.de/sneak/vaultik/issues/97). ### Blocking findings None. ### Verified - **#97 handler correctness.** `WithAttrs`/`WithGroup` never write to the receiver; `clone()` copies rather than reslices `attrs`/`groups`, so concurrent derivation from one parent cannot interleave appends. The `*sync.Mutex` is load-bearing — `TestTTYHandlerConcurrentDerivation` has 16 goroutines writing through derived handlers into one `bytes.Buffer`, which is only safe because the pointer is shared. The `slog.Handler` contract corners are right: `WithGroup("")` and `WithAttrs(nil)` return the receiver, empty `Attr` dropped, empty group dropped, empty-key group inlined, `KindGroup` record values flattened. Nested groups, group-then-attrs, and attrs straddling a group all match `slog.JSONHandler` under the dotted-key flattening. Resolving `LogValuer` at `WithAttrs` time rather than `Handle` time is a deviation from the naive reading but matches what stdlib's own handlers do via `preformattedAttrs` — correct, noted because it surprises. - **Revert-and-run reproduced, not taken on trust.** `tty_handler.go` reverted to `main` in a scratch worktree with the new tests in place: 8 top-level `FAIL`s and 6 of 7 `TestTTYHandlerMatchesJSONHandlerAttributes` subtests fail (`record_attributes_only` passes, as it must — it exercises no derivation). Every other package stayed green. Matches the PR body exactly. - **#82 stream change.** No writer in `internal/log` targets stdout any more. Keying the TTY/JSON choice on `os.Stderr` is correct: a redirected stderr now gets jsonl even when stdout is a terminal, which is the property that matters (see nit 1 on the doc text). - **Workaround removal loses nothing.** `Initialize` sets `LevelWarn` under `--quiet`/`--cron`, so the `log.Warn` calls in `reportJSONListingLimits` still fire in the exact `-q --json` mode the reproduction uses — the truncation and unreadable-manifest counts are not regressed from [PR #83](https://git.eeqj.de/sneak/vaultik/pulls/83)'s finding 2, and the tests now assert the counts as `"unreadable":1` / `"omitted":1` / `"limit":1000` rather than only the prose, which is stronger than before. `warnRemoteListingFailed`'s `--json` branch is still justified (`v.UI` writes to stdout). The `listingWarning` collect-then-emit rationale holds: worker-order emission would vary with fetch timing, and the rewritten comment says exactly that and explicitly retires the obsolete concurrency-safety reason. - **`--quiet`/`--cron` semantics unchanged**; level selection and `ui.Writer` untouched. - **No claim of a fully clean `--json` stdout** — the PR body, the TODO entry and the issue comment all name [issue #106](https://git.eeqj.de/sneak/vaultik/issues/106) as the remaining stdout contamination. - **Nothing weakened.** `.golangci.yml` sha256 matches `021cc83f…46bcb`; `Dockerfile`, `script/*`, `REPO_POLICIES.md`, `.gitea/`, `Makefile` byte-identical to `main`. No test function deleted; 10 assertions removed, 16 added. - **CI green** on `b7aee81` (`check / check`, success in 2m34s). Mergeable against `main`, no conflicts. - **`script/cibuild`**: exit 0, 314s wall, fresh `CHECK_EPOCH`; the check layers executed rather than replayed — `make fmt-check` 5.4s, `make lint` 102.1s (`0 issues.`), `make test` 132.1s — 14 `ok` lines, zero `(cached)` markers; the 14 `CACHED` layers are dependency/module layers. The only lint output is the `gomodguard` deprecation already tracked as [issue #90](https://git.eeqj.de/sneak/vaultik/issues/90). `-race` clean. - No Claude/Anthropic references or attribution trailers anywhere in the diff or commit. No tags on origin. Naming, no-stutter, inclusive terminology, `make fmt` clean. ### Nits (non-blocking) 1. **`AGENTS.md` policy 9 now contradicts the code.** Lines 86-87 still read "If stdout is not a terminal, output the structured logs in jsonl format." After this change the format follows stderr, so with `vaultik snapshot list --json | jq` at a terminal, stdout is not a terminal and the logs are colorized rather than jsonl — a literal deviation from the written rule. `internal/log/log.go` argues the reinterpretation in a code comment, and I agree the policy's operative content ("when the log destination is unwatched, make it machine-readable") is faithfully preserved; keying on stdout after moving the sink would put ANSI escapes on a redirected stderr, which is plainly worse. **Judgement call, stated plainly: I did not treat this as an iron-rule failure**, because the rule said "stdout" only because that is where logs used to go. But `AGENTS.md` is what the next agent will read, and it now says something false — it should get the one-line amendment to "the log stream". Owner's call whether that lands here or separately. 2. **`Vaultik.Stderr` now has zero production writers.** After `warnWhileListing` and the `fmt.Fprintf(v.Stderr, …)` calls went away, the field is only assigned in constructors and tests; `env.stderr` in `snapshot_list_test.go` likewise has no readers left. `vaultik.go` documents the field as deliberately kept to "complete the standard triple", so this is a choice rather than an oversight — flagging only so it is a known one. 3. **`TODO.md` line ~328** (a dated historical entry from earlier work) still says "still a local workaround pending issue #82". Read as an immutable history record it is fine, and the new entry supersedes it; noted only because the PR body claims nothing anywhere still cites [issue #82](https://git.eeqj.de/sneak/vaultik/issues/82) as pending — that is true of code comments, not of `TODO.md` history. 4. **`bytesAttrKey` special-casing does not survive grouping.** An int64 attribute named `bytes` under `WithGroup("x")` has key `x.bytes` by the time `writeAttr` compares, so it renders as a raw number rather than a human byte count. Unreachable today — nothing in the tree calls `WithGroup` — and arguably the more predictable behaviour. Mentioned for the record. 5. The PR body closes [issue #97](https://git.eeqj.de/sneak/vaultik/issues/97) as `Closes [issue #97](…)`; Gitea's auto-close parser may not match a keyword followed by a markdown link, and the landing commit title carries only `(closes #82)`. Worth confirming [issue #97](https://git.eeqj.de/sneak/vaultik/issues/97) actually closes on merge rather than assuming.

clawbot added merge-ready and removed needs-review labels 2026-08-09 18:43:41 +02:00

clawbot merged commit c16ef476a9 into main

2026-08-09 18:43:56 +02:00

clawbot deleted branch fix-log-stdout

2026-08-09 18:43:56 +02:00

clawbot referenced this pull request

2026-08-09 18:44:19 +02:00

Startup banner goes to stdout and --json does not suppress it, so every --json document is preceded by three lines of prose #106

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: sneak/vaultik#107

Send diagnostics to stderr and stop dropping log attributes (closes #82, closes #97) #107

USER-VISIBLE CHANGE: --verbose and --debug output moves to stderr

#82: the logger wrote to stdout

The snapshot_list.go workaround is gone

#97: TTYHandler discarded WithAttrs and WithGroup

The tests fail against the unfixed handler

Existing tests

Found while verifying, filed not fixed

Verification

Review: PASS

Blocking findings

Verified

Nits (non-blocking)

USER-VISIBLE CHANGE: `--verbose` and `--debug` output moves to stderr

The `snapshot_list.go` workaround is gone

#97: `TTYHandler` discarded `WithAttrs` and `WithGroup`