diff --git a/CHANGELOG.md b/CHANGELOG.md index 23ef611..d98be01 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -33,6 +33,7 @@ and versions are tracked in the repo-root `VERSION` file. ### Fixed +- Capture inherited subprocess and descriptor-1 output inside the single JSON envelope, with bounded native-output handling (#379). - Enforce native Windows run-bundle retention with pinned directory handles; unsupported platforms fail closed once per pass (#378). - Preserve consumer-owned logging handlers, explicit levels, and parent routing across CLI invocations (#387). - Validate nested configuration mappings before merge/provenance traversal, diff --git a/docs/json-contracts.md b/docs/json-contracts.md index d0cf7e5..996fb99 100644 --- a/docs/json-contracts.md +++ b/docs/json-contracts.md @@ -26,6 +26,11 @@ in memory and rolls the remainder to a temporary file, so both temporary-disk use and finalization memory remain bounded. The temporary file is removed when the invocation ends. +The JSON capture boundary temporarily redirects process-wide file descriptor 1. +`run_app()` therefore rejects concurrent invocations in one process; callers +that need parallel CLI work should use separate processes or serialize the +invocations. + The mode check respects Click option arity: a value such as `--payload --json` does not activate JSON when `--json` is the payload. It does not run consumer callbacks, defaults, type converters, or close hooks as a @@ -35,6 +40,12 @@ If a command exceeds the limit, base-cli emits one `base-cli.error` envelope with `code: "capture_limit"` and exit code `1`; it never silently truncates the captured text. Use the NDJSON contract for larger record sets. +If a child retains the inherited stdout descriptor after the command returns, +base-cli emits `code: "capture_incomplete"` and includes the output drained +before the timeout in the error envelope. Detached children should use +`subprocess.DEVNULL` for stdout/stderr (and may use `start_new_session=True`) +when running under JSON mode. + ## Output and errors Both envelopes use `schema_version: 1` and stable fields: @@ -53,7 +64,7 @@ Both envelopes use `schema_version: 1` and stable fields: Failures use `schema: "base-cli.error"`, `type: "error"`, and a deterministic `code` derived from the lifecycle outcome (`usage_error`, `click_error`, -`capture_limit`, `aborted`, `interrupted`, `unexpected_error`, and so on). `details` always +`capture_limit`, `capture_incomplete`, `aborted`, `interrupted`, `unexpected_error`, and so on). `details` always contains the numeric `exit_code` and captured command stdout. A command's human output is represented as a JSON string, so it cannot introduce prose or ANSI escapes as a second stdout record. @@ -156,3 +167,17 @@ Each line is a JSON object with `schema_version`, `schema`, `timestamp` (UTC), bounds default-log retention to the most recent 20 run bundles (or the explicit `RetentionPolicy` setting). The legacy `max_log_files` option remains available for compatibility. JSON logs never use terminal color codes. + +### Child processes and native stdout + +JSON mode captures Python stdout, `os.write(1, ...)`, `sys.__stdout__`, and +subprocesses inheriting descriptor 1. The descriptor is restored before emitting +the single envelope. Use `subprocess.run([...], check=True)` or explicitly wait +for each `Popen` child before returning. A child retaining stdout after return +produces a capture error after a bounded wait. Native libraries must flush their +own stdio buffers before returning; writes after the invocation boundary cannot +be captured. Invalid UTF-8 bytes are represented with Unicode replacement characters. + +The 8 MiB JSON capture limit applies to native/child output as well. Exceeding it +produces an error envelope rather than a success with silently truncated output. +NDJSON and human output keep their streaming behavior. diff --git a/docs/strict-json-consumer.md b/docs/strict-json-consumer.md index 1a3e619..5f7015a 100644 --- a/docs/strict-json-consumer.md +++ b/docs/strict-json-consumer.md @@ -77,3 +77,17 @@ The schemas and fixtures are the source of truth. Do not add a new parser or redefine the wire contract in an adopter guide; link the exact contract version and record the `base-cli` release used for validation. Never place secrets or private paths in fixtures or public failure reports. + +### Child processes and native stdout + +JSON mode captures Python stdout, `os.write(1, ...)`, `sys.__stdout__`, and +subprocesses inheriting descriptor 1. The descriptor is restored before emitting +the single envelope. Use `subprocess.run([...], check=True)` or explicitly wait +for each `Popen` child before returning. A child retaining stdout after return +produces a capture error after a bounded wait. Native libraries must flush their +own stdio buffers before returning; writes after the invocation boundary cannot +be captured. Invalid UTF-8 bytes are represented with Unicode replacement characters. + +The 8 MiB JSON capture limit applies to native/child output as well. Exceeding it +produces an error envelope rather than a success with silently truncated output. +NDJSON and human output keep their streaming behavior. diff --git a/lib/python/base_cli/_run.py b/lib/python/base_cli/_run.py index 5591978..0fb81c0 100644 --- a/lib/python/base_cli/_run.py +++ b/lib/python/base_cli/_run.py @@ -9,7 +9,6 @@ import tempfile import traceback from collections.abc import Callable, Mapping -from contextlib import redirect_stdout from threading import Lock from typing import Any, TextIO, cast @@ -27,6 +26,7 @@ ) from ._click_compat import dialect_for_command from ._lifecycle import InvocationOutcome, outcome_from_exception, outcome_from_exit_code, system_exit_code +from ._stdout_capture import StdoutCaptureIncompleteError, capture_stdout from .exit_codes import ExitCode from .json_contracts import dumps_envelope, error_envelope, success_envelope from .lifecycle_options import LifecycleOption, LifecycleOptions @@ -301,7 +301,7 @@ def _run_app_invocation( standalone_mode=False, ) else: - with redirect_stdout(output_capture): + with capture_stdout(output_capture, _MAX_JSON_CAPTURE_BYTES, JsonCaptureLimitError): result = command.main( args=args, prog_name=display_command or app.name, @@ -356,6 +356,12 @@ def _run_app_invocation( if exc.code is not None and not isinstance(exc.code, int): print(str(exc.code), file=sys.stderr) return system_exit_code(exc) + except StdoutCaptureIncompleteError as exc: + if state.json_output: + outcome = InvocationOutcome("capture_incomplete", "error", ExitCode.FAILURE) + _emit_json_error(state, outcome, str(exc), output_capture) + return outcome.exit_code + raise except JsonCaptureLimitError as exc: if state.json_output: outcome = InvocationOutcome("capture_limit", "error", ExitCode.FAILURE) diff --git a/lib/python/base_cli/_stdout_capture.py b/lib/python/base_cli/_stdout_capture.py new file mode 100644 index 0000000..8e3443d --- /dev/null +++ b/lib/python/base_cli/_stdout_capture.py @@ -0,0 +1,117 @@ +"""Capture process stdout, including inherited child descriptors, for JSON runs.""" + +from __future__ import annotations + +import codecs +import os +import sys +import tempfile +from collections.abc import Iterator +from contextlib import contextmanager, redirect_stdout +from threading import Event, Lock, Thread +from typing import TextIO + + +class StdoutCaptureIncompleteError(RuntimeError): + """Raised when a child keeps stdout open past the capture deadline.""" + + +@contextmanager +def capture_stdout(sink: TextIO, limit: int, limit_error: type[Exception]) -> Iterator[None]: + """Drain fd 1 concurrently, restore it, then replay through the JSON limiter. + + The invocation owns the process output boundary. Children must be waited for + before returning; a child retaining stdout is a deterministic capture error. + """ + original = sys.stdout + original.flush() + saved = os.dup(1) + read_fd, write_fd = os.pipe() + spool = tempfile.SpooledTemporaryFile(max_size=1_048_576, mode="w+b") + abandoned = Event() + errors: list[BaseException] = [] + spool_lock = Lock() + overflow = False + + def drain() -> None: + nonlocal overflow + total = 0 + try: + with os.fdopen(read_fd, "rb", buffering=0) as reader: + while chunk := reader.read(65536): + if abandoned.is_set(): + break + total += len(chunk) + # Unresolved parser output retains the existing deferred + # spool semantics. Once JSON is selected, native writers + # are bounded too; continue draining to avoid child deadlock. + json_mode = not hasattr(sink, "json_output") or bool(sink.json_output) + if json_mode and total > limit: + overflow = True + continue + with spool_lock: + spool.write(chunk) + except BaseException as exc: + errors.append(exc) + finally: + if abandoned.is_set(): + spool.close() + + worker = Thread(target=drain, name="base-cli-stdout-capture", daemon=True) + writer: TextIO | None = None + try: + worker.start() + os.dup2(write_fd, 1) + os.close(write_fd) + write_fd = -1 + writer = os.fdopen(os.dup(1), "w", encoding="utf-8", errors="strict", buffering=1, newline="") + with redirect_stdout(writer): + try: + yield + finally: + writer.flush() + # sys.__stdout__ can have its own Python buffering. + if sys.__stdout__ is not None and sys.__stdout__ is not writer: + try: + sys.__stdout__.flush() + except (OSError, ValueError): + pass + finally: + try: + if writer is not None: + writer.close() + finally: + os.dup2(saved, 1) + os.close(saved) + if write_fd != -1: + os.close(write_fd) + worker.join(timeout=2) + if worker.is_alive(): + # Preserve everything drained before the timeout. The descriptor + # may remain open in a detached child, so this is an incomplete + # capture rather than a stdout-size overflow. + with spool_lock: + spool.seek(0) + decoder = codecs.getincrementaldecoder("utf-8")("replace") + while chunk := spool.read(65536): + sink.write(decoder.decode(chunk)) + sink.write(decoder.decode(b"", final=True)) + sink.flush() + abandoned.set() + raise StdoutCaptureIncompleteError( + "A child retained stdout after the command returned; captured output is incomplete. " + "Wait for child processes or redirect detached children to DEVNULL." + ) + try: + if errors: + raise OSError("Could not capture process stdout") from errors[0] + if overflow: + size = f"{limit // 1_048_576} MiB" if limit % 1_048_576 == 0 else f"{limit} bytes" + raise limit_error(f"JSON stdout exceeded the {size} limit; use NDJSON for large record sets.") + spool.seek(0) + decoder = codecs.getincrementaldecoder("utf-8")("replace") + while chunk := spool.read(65536): + sink.write(decoder.decode(chunk)) + sink.write(decoder.decode(b"", final=True)) + finally: + spool.close() diff --git a/tests/test_json_descriptor_capture.py b/tests/test_json_descriptor_capture.py new file mode 100644 index 0000000..602f5e1 --- /dev/null +++ b/tests/test_json_descriptor_capture.py @@ -0,0 +1,78 @@ +from __future__ import annotations + +import json +import os +import subprocess +import sys +from pathlib import Path + +import base_cli + + +def _run(tmp_path: Path, body: str, args: list[str]) -> subprocess.CompletedProcess[str]: + script = ( + """ +import os, subprocess, sys +import base_cli +app = base_cli.App(name='descriptor-capture', lifecycle_options=base_cli.LifecycleOptions(json=base_cli.LifecycleOption('--json'))) +@app.command() +def main(ctx): +""" + + "\n".join(" " + line for line in body.splitlines()) + + "\nraise SystemExit(base_cli.run_app(app))\n" + ) + return subprocess.run( + [sys.executable, "-c", script, *args], + text=True, + capture_output=True, + timeout=15, + env={ + **os.environ, + "BASE_CLI_CACHE_DIR": str(tmp_path), + "PYTHONPATH": str(Path(base_cli.__file__).resolve().parents[1]), + }, + ) + + +def test_json_captures_inherited_subprocess_and_descriptor_writers(tmp_path: Path) -> None: + result = _run( + tmp_path, + """print('python', flush=True) +os.write(1, b'descriptor\\n') +subprocess.run([sys.executable, '-c', "print('child')"], check=True) +sys.__stdout__.write('original\\n') +""", + ["--json"], + ) + assert result.returncode == 0, result.stderr + envelope = json.loads(result.stdout) + captured = envelope["details"]["stdout"] + assert all(word in captured for word in ("python", "descriptor", "child", "original")) + + +def test_native_output_limit_is_a_single_error_envelope(tmp_path: Path) -> None: + result = _run(tmp_path, "os.write(1, b'x' * (9 * 1024 * 1024))", ["--json"]) + assert result.returncode != 0 + envelope = json.loads(result.stdout) + assert "limit" in str(envelope) + + +def test_human_stdout_is_unchanged(tmp_path: Path) -> None: + result = _run(tmp_path, "subprocess.run([sys.executable, '-c', 'print(42)'], check=True)", []) + assert result.returncode == 0 + assert result.stdout == "42\n" + + +def test_detached_child_reports_incomplete_capture_with_partial_stdout(tmp_path: Path) -> None: + result = _run( + tmp_path, + """child = subprocess.Popen([sys.executable, '-c', 'import time; print(\\"child\\", flush=True); time.sleep(5)']) +print('parent', flush=True) +""", + ["--json"], + ) + assert result.returncode != 0 + envelope = json.loads(result.stdout) + assert envelope["code"] == "capture_incomplete" + assert "parent" in envelope["details"]["stdout"] + assert "incomplete" in envelope["message"]