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")