From 2408fc2ad39e9f834ae7050ea41f298b3c518edd Mon Sep 17 00:00:00 2001 From: Neal Richardson Date: Fri, 23 Oct 2026 10:03:58 -0400 Subject: [PATCH] feat: Stream Connect's startup logs to stderr while waiting for it to start While waiting for the HTTP server to start, print each new line of the container log to stderr as it appears, so CI runs don't look hung. Streaming stops once Connect is up. --quiet suppresses the stream, and failure paths print only the log lines that haven't been shown yet. Fixes #13. Co-Authored-By: Claude Opus 5.5 --- README.md | 2 +- action.yml | 2 +- main.py | 87 +++++++++++++++++++++++++++++------ test_main.py | 126 +++++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 201 insertions(+), 16 deletions(-) diff --git a/README.md b/README.md index f67820a..b2ddd03 100644 --- a/README.md +++ b/README.md @@ -131,7 +131,7 @@ The GitHub Action supports the following inputs: | `image` | No | | Container image to use, including tag (e.g., `posit/connect:2025.12.0`). Overrides `version`. | | `config-file` | No | | Path to rstudio-connect.gcfg configuration file | | `port` | No | `3939` | Port to map the Connect container to | -| `quiet` | No | `false` | Suppress progress indicators during image pull | +| `quiet` | No | `false` | Suppress image pull progress and the Connect logs shown while Connect starts | | `env` | No | | Environment variables to pass to Docker container (one per line, format: KEY=VALUE) | | `command` | No | | Command to run against Connect (omit for start-only mode) | | `stop` | No | | Container ID to stop (use instead of starting a new container) | diff --git a/action.yml b/action.yml index d23f0e1..0152a14 100644 --- a/action.yml +++ b/action.yml @@ -15,7 +15,7 @@ inputs: description: 'Container image to use for Posit Connect' required: false quiet: - description: 'Suppress progress indicators during image pull' + description: 'Suppress image pull progress and the Connect logs shown while Connect starts' required: false default: 'false' port: diff --git a/main.py b/main.py index 0f5cbb7..800bb22 100644 --- a/main.py +++ b/main.py @@ -99,7 +99,7 @@ def parse_args(): parser.add_argument( "--quiet", action="store_true", - help="Suppress progress indicators during image pull", + help="Suppress image pull progress and the Connect logs shown while Connect starts", ) parser.add_argument( "--port", @@ -455,12 +455,13 @@ def main() -> int: server_url = f"http://localhost:{args.port}" stop_container = True + # Echo Connect's startup logs to stderr (stdout is reserved for KEY=value lines) + startup_logs = ContainerLogs(container, quiet=args.quiet) try: print(f"Waiting for port {args.port} to open...", file=sys.stderr) if not is_port_open("localhost", args.port, timeout=60.0, container=container): - print("\nContainer logs:", file=sys.stderr) - print(container.logs().decode("utf-8", errors="replace"), file=sys.stderr) + startup_logs.dump() if container.status in ("exited", "dead"): raise RuntimeError( f"Posit Connect container exited before port {args.port} opened." @@ -468,14 +469,15 @@ def main() -> int: raise RuntimeError("Posit Connect did not start within 60 seconds.") print("Waiting for HTTP server to start...", file=sys.stderr) - if not wait_for_http_server(container, timeout=60.0, poll_interval=2.0): - print("\nContainer logs:", file=sys.stderr) - print(container.logs().decode("utf-8", errors="replace"), file=sys.stderr) + if not wait_for_http_server( + container, timeout=60.0, poll_interval=2.0, startup_logs=startup_logs + ): + startup_logs.dump() raise RuntimeError( "Posit Connect did not log HTTP server start within 60 seconds." ) - api_key = get_api_key(bootstrap_secret, container, server_url) + api_key = get_api_key(bootstrap_secret, container, server_url, startup_logs) # Execute user command if provided exit_code = 0 @@ -560,8 +562,55 @@ def extract_server_version(logs: str) -> str | None: return None +class ContainerLogs: + """ + Read a container's logs and echo new lines to stderr as they appear. + + Each poll() fetches the full log and prints only the complete lines that + haven't been shown yet, so callers can poll in a loop. dump() prints + whatever is left when something fails, so no line is printed twice. + With quiet=True nothing is echoed, and dump() prints the whole log. + """ + + def __init__(self, container, quiet: bool = False): + self.container = container + self.quiet = quiet + self.shown = 0 # bytes of the log already printed + + def poll(self) -> str: + """Fetch the full log, echo new complete lines, and return the log.""" + logs = self.container.logs() + if not self.quiet: + # Hold back a trailing partial line until it is finished + end = logs.rfind(b"\n", self.shown) + 1 + if end > self.shown: + self._print(logs[self.shown : end]) + self.shown = end + return logs.decode("utf-8", errors="replace") + + def dump(self) -> None: + """Print the part of the log that hasn't been shown yet.""" + logs = self.container.logs() + if self.shown == 0: + print("\nContainer logs:", file=sys.stderr) + elif len(logs) > self.shown: + print("\nContainer logs (continued):", file=sys.stderr) + self._print(logs[self.shown :]) + self.shown = len(logs) + + @staticmethod + def _print(chunk: bytes) -> None: + if not chunk: + return + text = chunk.decode("utf-8", errors="replace") + print(text, end="" if text.endswith("\n") else "\n", file=sys.stderr, flush=True) + + def wait_for_http_server( - container, timeout: float = 60.0, poll_interval: float = 2.0 + container, + timeout: float = 60.0, + poll_interval: float = 2.0, + startup_logs: ContainerLogs | None = None, ) -> bool: """ Wait until the container logs contain the HTTP server start message. @@ -571,21 +620,24 @@ def wait_for_http_server( :param container: docker.models.containers.Container instance :param timeout: Maximum seconds to wait (default 60) :param poll_interval: Seconds between log checks (default 2) + :param startup_logs: ContainerLogs that echoes new log lines to stderr + while waiting (default: a quiet one that echoes nothing) :return: True if message found before timeout, False otherwise """ + if startup_logs is None: + startup_logs = ContainerLogs(container, quiet=True) deadline = time.time() + timeout version = None while time.time() < deadline: - logs = container.logs().decode("utf-8", errors="replace") + logs = startup_logs.poll() if not version: version = extract_server_version(logs) if version: print(f"Running Posit Connect v{version}", file=sys.stderr) if "Unable to obtain a valid license" in logs: - print("\nContainer logs:", file=sys.stderr) - print(logs, file=sys.stderr) + startup_logs.dump() raise RuntimeError( "Unable to obtain a valid license. Your Posit Connect license may be expired or invalid. Please check your license file." ) @@ -652,14 +704,22 @@ def post_bootstrap(server_url: str, token: str) -> dict: raise AssertionError("unreachable") -def get_api_key(bootstrap_secret: str, container, server_url: str) -> str: +def get_api_key( + bootstrap_secret: str, + container, + server_url: str, + startup_logs: ContainerLogs | None = None, +) -> str: """ Bootstrap Connect and retrieve an API key. Uses Connect's bootstrap endpoint with a JWT generated from the bootstrap secret to create and retrieve an API key. This key is used to authenticate commands run against the Connect instance. Requires Connect 2022.10.0+. + On failure, prints the container logs not already shown by startup_logs. """ + if startup_logs is None: + startup_logs = ContainerLogs(container, quiet=True) try: # The bootstrap_secret we received is base64-encoded, need to decode it secret_bytes = base64.b64decode(bootstrap_secret.encode("utf-8")) @@ -670,8 +730,7 @@ def get_api_key(bootstrap_secret: str, container, server_url: str) -> str: raise RuntimeError(f"Bootstrap returned unexpected response: {response}") return api_key except Exception as e: - print("\nContainer logs:", file=sys.stderr) - print(container.logs().decode("utf-8", errors="replace"), file=sys.stderr) + startup_logs.dump() raise RuntimeError(f"Failed to bootstrap Connect and retrieve API key: {e}") diff --git a/test_main.py b/test_main.py index 55621e9..ecf8a6d 100644 --- a/test_main.py +++ b/test_main.py @@ -90,6 +90,114 @@ def test_valid_license_http_server_starts(): mock_container.stop.assert_not_called() +def test_startup_logs_are_streamed_to_stderr(): + mock_container = MagicMock() + mock_container.logs.side_effect = [ + b"Starting Posit Connect v2025.09.0\nLoading conf", + b"Starting Posit Connect v2025.09.0\nLoading config\n", + b"Starting Posit Connect v2025.09.0\nLoading config\nStarting HTTP server on [::]:3939\n", + ] + stdout, stderr = io.StringIO(), io.StringIO() + startup_logs = main.ContainerLogs(mock_container) + + with redirect_stdout(stdout), redirect_stderr(stderr): + result = main.wait_for_http_server( + mock_container, timeout=1.0, poll_interval=0.01, startup_logs=startup_logs + ) + + assert result is True + assert stdout.getvalue() == "" + # Each line appears once, a partial line waits until it is complete, + # and the version line is still reported + assert stderr.getvalue() == ( + "Starting Posit Connect v2025.09.0\n" + "Running Posit Connect v2025.09.0\n" + "Loading config\n" + "Starting HTTP server on [::]:3939\n" + ) + + +def test_startup_logs_quiet(): + mock_container = MagicMock() + mock_container.logs.return_value = b"Starting Posit Connect v2025.09.0\nStarting HTTP server on [::]:3939\n" + stderr = io.StringIO() + + with redirect_stderr(stderr): + result = main.wait_for_http_server( + mock_container, + timeout=1.0, + poll_interval=0.01, + startup_logs=main.ContainerLogs(mock_container, quiet=True), + ) + + assert result is True + assert stderr.getvalue() == "Running Posit Connect v2025.09.0\n" + + +def test_invalid_license_logs_not_duplicated(): + mock_container = MagicMock() + mock_container.logs.return_value = b'Starting Posit Connect v2025.09.0\nlevel=warning msg="Unable to obtain a valid license"\n' + stderr = io.StringIO() + + with redirect_stderr(stderr): + try: + main.wait_for_http_server( + mock_container, + timeout=1.0, + poll_interval=0.01, + startup_logs=main.ContainerLogs(mock_container), + ) + assert False, "Expected RuntimeError to be raised" + except RuntimeError as e: + assert "Unable to obtain a valid license" in str(e) + + output = stderr.getvalue() + assert output.count("Unable to obtain a valid license") == 1 + assert output.count("Starting Posit Connect") == 1 + assert "Container logs" not in output + + +def test_invalid_license_quiet_dumps_logs(): + mock_container = MagicMock() + mock_container.logs.return_value = b'level=warning msg="Unable to obtain a valid license"' + stderr = io.StringIO() + + with redirect_stderr(stderr): + try: + main.wait_for_http_server(mock_container, timeout=1.0, poll_interval=0.01) + assert False, "Expected RuntimeError to be raised" + except RuntimeError: + pass + + assert stderr.getvalue() == '\nContainer logs:\nlevel=warning msg="Unable to obtain a valid license"\n' + + +def test_container_logs_dump_prints_only_unseen_lines(): + mock_container = MagicMock() + mock_container.logs.side_effect = [b"one\ntw", b"one\ntwo\nthree\n"] + startup_logs = main.ContainerLogs(mock_container) + stderr = io.StringIO() + + with redirect_stderr(stderr): + startup_logs.poll() + startup_logs.dump() + + assert stderr.getvalue() == "one\n\nContainer logs (continued):\ntwo\nthree\n" + + +def test_container_logs_dump_prints_nothing_when_all_shown(): + mock_container = MagicMock() + mock_container.logs.return_value = b"one\ntwo\n" + startup_logs = main.ContainerLogs(mock_container) + stderr = io.StringIO() + + with redirect_stderr(stderr): + startup_logs.poll() + startup_logs.dump() + + assert stderr.getvalue() == "one\ntwo\n" + + def test_get_docker_tag_latest(): assert main.get_docker_tag("latest") == ("ghcr.io/posit-dev/connect", "latest") @@ -637,6 +745,24 @@ def test_post_bootstrap_raises_on_other_errors(): test_valid_license_http_server_starts() print("✓ test_valid_license_http_server_starts passed") + test_startup_logs_are_streamed_to_stderr() + print("✓ test_startup_logs_are_streamed_to_stderr passed") + + test_startup_logs_quiet() + print("✓ test_startup_logs_quiet passed") + + test_invalid_license_logs_not_duplicated() + print("✓ test_invalid_license_logs_not_duplicated passed") + + test_invalid_license_quiet_dumps_logs() + print("✓ test_invalid_license_quiet_dumps_logs passed") + + test_container_logs_dump_prints_only_unseen_lines() + print("✓ test_container_logs_dump_prints_only_unseen_lines passed") + + test_container_logs_dump_prints_nothing_when_all_shown() + print("✓ test_container_logs_dump_prints_nothing_when_all_shown passed") + test_image_and_version_exclusive() print("✓ test_image_and_version_exclusive passed")