diff --git a/README.md b/README.md index e36176b..c28ecdf 100644 --- a/README.md +++ b/README.md @@ -200,6 +200,8 @@ Fetching metrics requires `s3:ListBucket` on the stack's cache bucket and `s3:Ge With `--debug`, `roc logs` also reports the full resolver diagnostics before streaming logs. +For slow public package downloads, use the [network diagnostics guide](docs/network-diagnostics.md) to collect bounded transfer timings and local counters before the ephemeral runner terminates, then correlate them with `roc logs --full`. The guide includes an optional Linux workflow probe; it does not add a CLI command or enable continuous network monitoring. + ### `roc interrupt` Trigger a spot interruption on the instance running a specific job, simulating a spot instance interruption for testing purposes. diff --git a/docs/network-diagnostics.md b/docs/network-diagnostics.md new file mode 100644 index 0000000..225e0de --- /dev/null +++ b/docs/network-diagnostics.md @@ -0,0 +1,58 @@ +# Investigating slow public downloads + +Collect evidence while the affected runner still exists. `roc logs JOB_URL --full` retrieves retained diagnostics; it cannot reconstruct destination timings or TCP counters that were never recorded. Use the CLI version matching the stack, and record both versions, the job URL, UTC interval, runner family, region/AZ, networking mode, and whether the slow transfer ran on the host or inside BuildKit. + +## Capture a small reproducible sample + +Copy [`network_probe.py`](../examples/diagnostics/network_probe.py) into the workload repository. It needs Linux, Python 3.9 or newer, and curl 8.4 or newer. The latter supports enforcing the transfer-size cap even when the server did not advertise its response size. No Python packages, AWS permissions, or root access are required. + +Invoke it immediately before and after the slow step. With no arguments it only records local interface/TCP counters, load average, and memory availability. With one to three explicitly selected public HTTPS URLs it also performs bounded GET requests and records DNS, TCP, TLS, first-byte and total timings, response status, byte count, and average download rate. Choose an affected package URL and an independent control of comparable size; tiny HTML pages are poor bandwidth controls. + +```yaml +- name: Network counters before the build + run: python3 .github/scripts/network_probe.py > "$RUNNER_TEMP/network-before.jsonl" + +# Run the workload here. Capture during the slowdown if possible; a probe +# after recovery cannot explain a transient incident. + +- name: Network counters after the build + if: always() + run: python3 .github/scripts/network_probe.py > "$RUNNER_TEMP/network-after.jsonl" + +- name: Preserve network observations + if: always() + uses: actions/upload-artifact@v7 + with: + name: network-${{ github.job }}-${{ strategy.job-index }} + path: ${{ runner.temp }}/network-*.jsonl + retention-days: 3 +``` + +For transfer timings, pass public URLs as arguments, for example `python3 .github/scripts/network_probe.py https://packages.example.org/sample.tar.gz`. Replace that illustrative URL with a real package or control. Each URL is limited to 20 seconds and a 10 MiB range request, with a five-second connection timeout and at most three HTTPS redirects. A server that ignores ranges may trigger curl exit code 63 (size limit); exit code 28 is a timeout. These are observations, not evidence of successful full transfers. The probe preserves failed-transfer records and exits successfully after collecting them so diagnostics do not replace the build's result. + +The sample does not print response bodies, headers, curl stderr, full URLs, environment variables, or credentials. It rejects userinfo, query strings, and fragments, ignores `.curlrc`, and only emits selected fields from curl's JSON. Use public unauthenticated URLs, avoid tokens embedded in URL paths, and review artifacts before attaching them to a public issue. Proxy environment settings still affect curl's route; record whether a proxy is in use without publishing its credentials. Raw `roc` archives and verbose logs need a separate review and are not sanitized by this probe. + +## Interpret the observations + +| Observation | Next check | +| --------------------------------------------------------------------- | ----------------------------------------------------------------------------------------------------------------------------- | +| DNS time rises | Resolver health and whether only one destination is affected. | +| Connection or TLS time rises | Compare destinations and host/container paths; inspect network path and connection setup. | +| First byte is slow but connection setup is quick | Remote package service/CDN response, authentication, or server throttling. | +| Transfer rate falls and retransmissions rise during the same interval | Collect same-instance route/ENA diagnostics before termination; counters suggest loss or retries but do not locate the cause. | +| High CPU load, memory pressure, or local disk pressure | Compare workload/resource metrics before attributing delay to egress. | +| Host probes are fast but a BuildKit package step is slow | Repeat comparable probes inside the build network namespace; host totals cannot attribute traffic to a specific container. | +| Only the cache endpoint fails immediately with 404 | Diagnose cache API selection separately from slow public package downloads. | + +Counters are cumulative and can reset with an interface or instance; compare samples from the same runner and interval. They include unrelated concurrent traffic and provide no per-flow attribution. Inspect destination-specific route, ENA allowance and conntrack data through an authorized live session when needed; aggregate network bytes alone establish none of those conditions. Download speed includes startup time and the sample cap, so it is not a maximum-throughput benchmark. + +After the job, export `roc logs JOB_URL --full` from an authorized workstation and correlate it with the probe timestamps. Consult the [current CLI contract](https://runs-on.com/docs/observability/cli/) for the available retained artifacts. [runs-on/runs-on#542](https://github.com/runs-on/runs-on/issues/542) describes a transient incident on v2.12.1-rc.4; this procedure does not establish a defect in that release or reproduce the incident on v3. Provider-side alerting and automatic retention of finer network diagnostics remain separate work. + +## Validate the example locally + +```bash +python3 -m unittest discover -s examples/diagnostics -p 'test_*.py' +python3 examples/diagnostics/network_probe.py +``` + +The second command only reads local counters. Transfer limits and timing fields are documented in the [curl manual](https://curl.se/docs/manpage.html). diff --git a/examples/diagnostics/.gitignore b/examples/diagnostics/.gitignore new file mode 100644 index 0000000..c18dd8d --- /dev/null +++ b/examples/diagnostics/.gitignore @@ -0,0 +1 @@ +__pycache__/ diff --git a/examples/diagnostics/network_probe.py b/examples/diagnostics/network_probe.py new file mode 100644 index 0000000..488f568 --- /dev/null +++ b/examples/diagnostics/network_probe.py @@ -0,0 +1,197 @@ +#!/usr/bin/env python3 +"""Collect bounded Linux egress diagnostics without recording request secrets.""" + +import argparse +import datetime +import json +import os +import subprocess +from pathlib import Path +from urllib.parse import urlsplit + +MAX_BYTES = 10 * 1024 * 1024 +MAX_SECONDS = 20 +TIMING_FIELDS = ( + "http_code", + "http_version", + "num_redirects", + "size_download", + "speed_download", + "time_namelookup", + "time_connect", + "time_appconnect", + "time_starttransfer", + "time_total", +) +TCP_FIELDS = { + "RetransSegs", + "InErrs", + "OutRsts", + "InSegs", + "OutSegs", + "TCPSynRetrans", + "TCPTimeouts", + "TCPFastRetrans", + "TCPLostRetransmit", +} +INTERFACE_FIELDS = ( + "rx_bytes", + "tx_bytes", + "rx_packets", + "tx_packets", + "rx_errors", + "tx_errors", + "rx_dropped", + "tx_dropped", +) + + +def timestamp(): + return datetime.datetime.now(datetime.timezone.utc).isoformat() + + +def read_text(path): + try: + return Path(path).read_text() + except OSError: + return "" + + +def tcp_counters(text): + result = {} + lines = text.splitlines() + for header, values in zip(lines[::2], lines[1::2]): + names, counts = header.split(), values.split() + if not names or not counts or names[0] != counts[0]: + continue + for name, value in zip(names[1:], counts[1:]): + if name in TCP_FIELDS and value.isdigit(): + result[names[0].rstrip(":") + "." + name] = int(value) + return result + + +def system_sample(phase): + interfaces = {} + for interface in sorted(Path("/sys/class/net").glob("*")): + counters = {} + for field in INTERFACE_FIELDS: + value = read_text(interface / "statistics" / field).strip() + if value.isdigit(): + counters[field] = int(value) + interfaces[interface.name] = counters + memory = {} + for line in read_text("/proc/meminfo").splitlines(): + name, _, value = line.partition(":") + if name in {"MemTotal", "MemAvailable", "SwapTotal", "SwapFree"}: + memory[name] = value.strip() + return { + "kind": "system", + "phase": phase, + "timestamp": timestamp(), + "interfaces": interfaces, + "memory": memory, + "load_average": read_text("/proc/loadavg").split()[:3], + "tcp": tcp_counters(read_text("/proc/net/snmp")) + | tcp_counters(read_text("/proc/net/netstat")), + } + + +def validate_url(value): + try: + parsed = urlsplit(value) + if ( + parsed.scheme != "https" + or not parsed.hostname + or parsed.username is not None + or parsed.password is not None + or parsed.query + or parsed.fragment + or any(ord(char) < 33 or ord(char) == 127 for char in value) + ): + raise ValueError + _ = ( + parsed.port + ) # Validate malformed or out-of-range ports before invoking curl. + except ValueError: + raise argparse.ArgumentTypeError( + "use an HTTPS URL without credentials, query, fragment, or whitespace" + ) from None + return value + + +def transfer(url, index): + result = { + "kind": "transfer", + "timestamp": timestamp(), + "endpoint_index": index, + "hostname": urlsplit(url).hostname, + "max_bytes": MAX_BYTES, + "max_seconds": MAX_SECONDS, + } + try: + process = subprocess.run( + [ + "curl", + "--disable", + "--silent", + "--globoff", + "--proto", + "=https", + "--proto-redir", + "=https", + "--location", + "--max-redirs", + "3", + "--connect-timeout", + "5", + "--max-time", + str(MAX_SECONDS), + "--range", + f"0-{MAX_BYTES - 1}", + "--max-filesize", + str(MAX_BYTES), + "--output", + os.devnull, + "--write-out", + "%{json}", + "--url", + url, + ], + capture_output=True, + text=True, + timeout=MAX_SECONDS + 5, + check=False, + ) + result["curl_exit_code"] = process.returncode + # curl's complete JSON and stderr can contain URLs, credentials, and + # proxy details. Emit only explicitly selected timing and size fields. + data = json.loads(process.stdout) + result.update({key: data[key] for key in TIMING_FIELDS if key in data}) + except FileNotFoundError: + result["error"] = "curl-not-found" + except subprocess.TimeoutExpired: + result["error"] = "probe-timeout" + except (ValueError, TypeError): + result["error"] = "invalid-curl-json" + return result + + +def main(): + parser = argparse.ArgumentParser(description=__doc__) + parser.add_argument( + "urls", + nargs="*", + type=validate_url, + help="up to three public package or control URLs", + ) + args = parser.parse_args() + if len(args.urls) > 3: + parser.error("at most three URLs are allowed per probe") + print(json.dumps(system_sample("before")), flush=True) + for index, url in enumerate(args.urls, start=1): + print(json.dumps(transfer(url, index)), flush=True) + print(json.dumps(system_sample("after")), flush=True) + + +if __name__ == "__main__": + main() diff --git a/examples/diagnostics/test_network_probe.py b/examples/diagnostics/test_network_probe.py new file mode 100644 index 0000000..74338fe --- /dev/null +++ b/examples/diagnostics/test_network_probe.py @@ -0,0 +1,69 @@ +import argparse +import json +import subprocess +import unittest +from unittest.mock import patch + +import network_probe + + +class NetworkProbeTests(unittest.TestCase): + def test_rejects_credential_bearing_and_non_https_urls(self): + for url in ( + "http://example.com/file", + "https://user:secret@example.com/file", + "https://example.com/file?token=secret", + "https://example.com/#secret", + "https://example.com/\nfile", + "https://example.com:99999/file", + ): + with self.subTest(url=url), self.assertRaises(argparse.ArgumentTypeError): + network_probe.validate_url(url) + + def test_only_numeric_counter_fields_are_collected(self): + sample = "Tcp: InSegs RetransSegs Secret\nTcp: 120 4 do-not-emit\n" + self.assertEqual( + network_probe.tcp_counters(sample), + {"Tcp.InSegs": 120, "Tcp.RetransSegs": 4}, + ) + + @patch("network_probe.subprocess.run") + def test_transfer_filters_sensitive_curl_output(self, run): + run.return_value = subprocess.CompletedProcess( + [], + 28, + json.dumps( + { + "http_code": 206, + "time_total": 20, + "size_download": 1024, + "url_effective": "https://example.com/?token=secret", + "errormsg": "secret", + "proxy_used": "secret", + "referer": "secret", + } + ), + "secret", + ) + result = network_probe.transfer("https://example.com/file", 1) + self.assertEqual(result["curl_exit_code"], 28) + self.assertEqual(result["size_download"], 1024) + self.assertNotIn("secret", json.dumps(result)) + command = run.call_args.args[0] + self.assertEqual(command[:2], ["curl", "--disable"]) + self.assertIn("--globoff", command) + self.assertEqual(command[command.index("--max-time") + 1], "20") + self.assertEqual(command[command.index("--max-filesize") + 1], "10485760") + + @patch( + "network_probe.subprocess.run", + side_effect=subprocess.TimeoutExpired(["secret"], 25), + ) + def test_timeout_does_not_echo_the_command(self, run): + result = network_probe.transfer("https://example.com/file", 1) + self.assertEqual(result["error"], "probe-timeout") + self.assertNotIn("secret", json.dumps(result)) + + +if __name__ == "__main__": + unittest.main()