fix(cli): a --json payload no longer shares stdout with the log (BACKLOG #1489)

[wshallwshall]

What this fixes

messagefoundry <cmd> --json writes a machine-parsed document to stdout, and the engine's default log sink writes human-readable lines to the same descriptor. One log line ahead of the payload makes json.loads raise Extra data: line 1 column 5: the text format opens with the ISO timestamp, so 2026 parses as a number and the payload becomes trailing garbage.

Cost, measured 2026-09-09 across every ci.yml run since 2026-09-08T20:00Z: five occurrences on five different branches including a push to main itself, and three of 22 merge-queue batches (14 percent), each evicting a healthy pull request into a full re-merge cycle. PRs 885, 981 and 1003 were evicted this way. That census is ATTRIBUTED to the seat that dispatched this work, not re-derived here -- what this seat checked is that those three pull requests exist and are now MERGED, which is consistent with an eviction followed by a re-merge but does not on its own establish the cause. The mechanism does not rest on the census: the regression test below reproduces it deterministically.

The change

main() calls configure_stderr_logging() before it dispatches, whenever the parsed arguments carry --json. That subcommand's log sink is stderr; stdout carries the payload alone.

Three things it deliberately does not do

logging_guard.py is untouched. Its rollover notice goes to the rolled sink on purpose, and the module says so: the notice landing is the proof that the replacement stream accepted a write, which is precisely what separates stage 1 (healed) from stage 2 (unwritable). Sending the notice to stderr would leave stage 1 unable to tell a healed sink from a dead one, so the fail-closed halt would lose its trigger. BACKLOG #1489's first prescription said to do that and was retracted before it merged; this change does not revive it.

tests/test_checks.py keeps asserting json.loads(capsys.readouterr().out). That assertion was optimistic while a log sink pointed at stdout, and is sound now. Relaxing it was the other option and was rejected.

serve and supervise are unchanged. They take no --json and print no payload, so they still log to the stdout NSSM captures. docs/SERVICE.md's log-ownership table and the service.out.log runbook steps stay true, and no doc, tray hint or retention comment moves.

configure_stderr_logging is reused rather than rebuilt: it already existed for the ADR 0087 sandbox worker, whose stdout carries MFW2 IPC frames. Its docstring now names both callers. It also carries the PHI-redaction and control-char-scrub filter chain, which the logging.lastResort fallback a handler-less subcommand degrades to today does not.

Regression test, and proof it fails without the change

tests/test_checks.py::test_check_json_payload_survives_a_log_record installs the guarded stdout sink serve installs, points its stream at a closed object (what a capture teardown or a supervisor file-swap leaves behind), forces one record during check --json, then asserts stdout parses and the record reached stderr.

Reverted to main's __main__.py it fails with exactly the measured error:

E           json.decoder.JSONDecodeError: Extra data: line 1 column 5 (char 4)
s = '2026-09-09T14:32:27Z WARNING  messagefoundry.logging_guard: application log sink \'stdout\' was rolled after a write ...'

Forcing the record is what makes it deterministic. The roll is timing-dependent otherwise, which is why five real failures read as flakes.

Checks run

Check	Result
ruff format + ruff check on the three changed .py files	clean
mypy messagefoundry (strict)	Success, no issues in 273 source files
scripts/docs/backlog_status_check.py	OK, 720 items each declaring one status, 6 advisory warnings (all pre-existing, none from this change)
pytest: test_checks.py + the 25 other test files that pass --json to main + test_logging.py + test_backlog_status_check.py	886 passed, 1 skipped
pytest: test_asvs_phase0.py + test_audit_offbox_tee.py	156 passed, 1 skipped
pre-commit (all hooks, at commit time)	passed

Not run to completion here: the full pytest suite was started but had not finished inside this session. The legs that only ever run on a hosted runner, windows-service-smoke among them, must be read from CI after merge-queue entry.

Verified but worth a second reader

getattr(args, "json", False) covers every subcommand that declares a --json flag. A subcommand that prints JSON without declaring the flag would not be covered; in a real CLI process such a command has no root handler at all and degrades to logging.lastResort, which is already stderr, so nothing writes to its stdout either. The collision only ever appears where a stdout log sink has been installed.

BACKLOG #1489

Co-Authored-By: Claude Opus 5 noreply@anthropic.com

🤖 Generated with Claude Code