diff --git a/BENCHMARK.md b/BENCHMARK.md index 7abb20b..654700f 100644 --- a/BENCHMARK.md +++ b/BENCHMARK.md @@ -220,6 +220,74 @@ The checker is intentionally stricter than a benchmark smoke. It rejects one-case provenance runs, local diagnostics, missing p25/median/p75 metrics, and non-Testbox evidence even when the run is useful for CI or debugging. +## Cold-start phase latency + +Use the cold-start harness to compare two Rustwright revisions. Run it on one +reserved Testbox. The matrix builds both wheels in that Testbox and installs +them in separate virtual environments inside one derived Docker image. + +Run one launcher process for one sample: + +```bash +RUSTWRIGHT_STARTUP_TIMING_FILE=.benchmark-data/results/startup-core.jsonl python benchmarks/startup_latency.py +``` + +The launcher measures import, manager creation, API startup, first Chromium +facade access, browser launch, first page creation, the blank-page probe, and +close. It prints one JSON record. A failed run prints an error record and exits +nonzero. Core JSONL is optional. The launcher still works on revisions that do +not implement `RUSTWRIGHT_STARTUP_TIMING_FILE`. + +Use `--browser-path` to pass `executable_path` through the public launch API. +Otherwise, let the library read `RUSTWRIGHT_CHROMIUM`, `CHROME`, or `CHROMIUM`. +Set `RUSTWRIGHT_CDP_TRANSPORT` to select `websocket` or `pipe`. The public +launch API does not accept a transport argument. Never pass custom Chromium +arguments or `ignore_default_args` to this benchmark. + +Run 30 matched pairs in balanced ABBA order. Keep the default +`per-sample-container` isolation. It starts each sample in a fresh container +with equal memory and swap caps. The `revision-block-container` mode is a +diagnostic fallback. It reuses container state and cannot pass the Testbox +evidence checker. + +Warm one Testbox and run the full matrix there: + +```bash +RUSTWRIGHT_TESTBOX_REF= \ +RUSTWRIGHT_TESTBOX_IDLE_TIMEOUT=120 \ +RUSTWRIGHT_TESTBOX_DOWNLOAD_RESULTS=1 \ +tools/run_benchmark_testbox.sh -- 'set -euo pipefail; mkdir -p .benchmark-data/results .benchmark-data/reports; timestamp="$(date -u +%Y%m%dT%H%M%SZ)"; matrix_rc=0; TEST_DOCKER_MEMORY_LIMIT=8g RUSTWRIGHT_DOCKER_IMAGE=rustwright-verify-testbox python tools/run_startup_latency_matrix.py --before-rev --after-rev --pairs 30 --order balanced-abba --output ".benchmark-data/results/startup-latency-${timestamp}.json" --json || matrix_rc=$?; if [ "$matrix_rc" -ne 0 ] && [ "$matrix_rc" -ne 3 ]; then exit 1; fi; python tools/check_startup_latency.py ".benchmark-data/results/startup-latency-${timestamp}.json" --source testbox --runner blacksmith-testbox --run-url "testbox:${HOSTNAME:-unknown}" --min-pairs 20 --require-balanced-order --require-matched-environment --output ".benchmark-data/reports/startup-latency-${timestamp}-validation.json" --json' +``` + +The matrix runs sequentially at concurrency one. It records both source SHAs, +wheel and image identities, browser and runtime versions, resource caps, CPU +data, the exact command, start time, sample order, sample and metadata container +names, and the full metadata container command. +It retains failures as raw samples. Exit 0 means all samples passed. Exit 3 +means the artifact is complete but retains sample failures. Exit 1 means setup +or protocol failure. The command above runs the checker after exit 0 or 3. The +checker supplies the final pipeline result. + +`tools/startup_latency_stats.py` is the stdlib-only statistics source for the +matrix and checker. It reports median, p25, p75, MAD, paired median changes, +and a 95% paired bootstrap interval for each phase. The +`paired-delta-random-v1` protocol uses exactly 10,000 resamples. Its seed is +`startup-latency::`. It draws each sample index +from the seeded `random.Random.random()` stream. This stream is stable across +Python versions. The protocol does not use `randrange`, whose stream is not +guaranteed to remain stable. Do not report p95 from this protocol. + +The checker fails closed. It requires at least 20 complete pairs, exact ABBA +balance, equal matched environments, contiguous phase endpoints, the derived +first-page total, complete provenance, success rates, and recomputed +statistics. `--source testbox` is an operator attestation. Use it only for a +real Testbox run. Supply a nonempty runner label and Testbox run reference. +Reviewers use the label and reference as part of the evidence. + +Keep raw results under `.benchmark-data/results/`. Keep summaries and checker +reports under `.benchmark-data/reports/`. These paths are untracked. Do not +commit the generated artifacts. + ## Local Diagnostic: Trusted Input Default On 2026-07-03, after disabling untrusted DOM action fast paths by default, a diff --git a/Dockerfile b/Dockerfile index 9b26476..606c4f4 100644 --- a/Dockerfile +++ b/Dockerfile @@ -54,13 +54,17 @@ RUN --mount=type=cache,target=/root/.cache/pip \ COPY src ./src COPY python ./python -# The root Cargo.toml declares `node` as a workspace member, so cargo must be -# able to load node/Cargo.toml (and its lib source) to resolve the workspace -# before maturin builds the Python extension — even though this image never -# builds the Node addon. Copy just the crate manifest and sources, not -# node_modules. +# The root Cargo.toml declares `node`, `capi`, and `rust-native` as workspace +# members, so cargo must be able to load each member manifest (and its lib +# sources) to resolve the workspace before maturin builds the Python +# extension — even though this image never builds those crates. Copy just the +# crate manifests and sources, not node_modules or build output. COPY node/Cargo.toml node/build.rs ./node/ COPY node/src ./node/src +COPY capi/Cargo.toml ./capi/ +COPY capi/src ./capi/src +COPY rust-native/Cargo.toml ./rust-native/ +COPY rust-native/src ./rust-native/src RUN --mount=type=cache,target=/root/.cache/pip \ --mount=type=cache,target=/usr/local/cargo/registry \ diff --git a/benchmarks/startup_latency.py b/benchmarks/startup_latency.py new file mode 100755 index 0000000..e8bf53d --- /dev/null +++ b/benchmarks/startup_latency.py @@ -0,0 +1,294 @@ +#!/usr/bin/env python3 +"""Measure one Rustwright cold-start sample in one Python process.""" + +from __future__ import annotations + +import importlib +import sys +import time + + +ENTRYPOINT = "python-sync" +MEASURED_PHASES = ( + "python_import", + "manager_factory", + "api_startup", + "chromium_facade_first_access", + "browser_launch", + "first_page", + "first_page_probe", + "close", +) + + +class UsageError(ValueError): + pass + + +def emit_record(record: dict[str, object]) -> None: + import json + + print(json.dumps(record, sort_keys=True, separators=(",", ":"))) + + +def parse_args() -> tuple[str | None, bool]: + arguments = sys.argv[1:] + if arguments in (["-h"], ["--help"]): + return None, True + if not arguments: + return None, False + if len(arguments) == 2 and arguments[0] == "--browser-path" and arguments[1]: + return arguments[1], False + if len(arguments) == 1 and arguments[0].startswith("--browser-path="): + value = arguments[0].split("=", 1)[1] + if value: + return value, False + raise UsageError("usage: startup_latency.py [--browser-path PATH]") + + +def package_version() -> str | None: + from importlib import metadata + + try: + return metadata.version("rustwright") + except Exception: + return None + + +def requested_browser_path(explicit_path: str | None) -> str | None: + import os + + if explicit_path: + return explicit_path + for name in ("RUSTWRIGHT_CHROMIUM", "CHROME", "CHROMIUM"): + value = os.environ.get(name) + if value: + return value + return None + + +def read_core_probe(path_value: str | None) -> dict[str, object]: + import json + import os + from pathlib import Path + + if path_value is None: + return {"status": "disabled", "records": []} + if path_value == "-": + return {"status": "stderr", "records": []} + + path = Path(path_value) + if not path.is_file(): + return {"status": "absent", "records": []} + + records: list[dict[str, object]] = [] + invalid_lines = 0 + try: + for line in path.read_text(encoding="utf-8").splitlines(): + if not line.strip(): + continue + try: + value = json.loads(line) + except (TypeError, ValueError): + invalid_lines += 1 + continue + if isinstance(value, dict) and value.get("pid") == os.getpid(): + records.append(value) + except (OSError, UnicodeError) as exc: + return { + "status": "unreadable", + "records": [], + "error_type": type(exc).__name__, + } + + status = "present" if records else "absent" + result: dict[str, object] = {"status": status, "records": records} + if invalid_lines: + result["invalid_line_count"] = invalid_lines + return result + + +def cleanup(page: object, browser: object, playwright: object) -> list[str]: + errors: list[str] = [] + for name, value, close_name in ( + ("page", page, "close"), + ("browser", browser, "close"), + ("manager", playwright, "stop"), + ): + if value is None: + continue + try: + getattr(value, close_name)() + except Exception as exc: # The error record must survive cleanup failures. + errors.append(f"{name}:{type(exc).__name__}") + return errors + + +def main() -> int: + try: + browser_path, show_help = parse_args() + except UsageError as exc: + import os + + emit_record( + { + "schema_version": 1, + "status": "error", + "entrypoint": ENTRYPOINT, + "pid": os.getpid(), + "failed_phase": "argument_parse", + "error_type": type(exc).__name__, + "error_message": str(exc), + "cleanup_errors": [], + "core_timing_file": os.environ.get("RUSTWRIGHT_STARTUP_TIMING_FILE"), + } + ) + return 2 + if show_help: + print( + "Run one cold Rustwright launch and print one JSON record.\n" + "usage: startup_latency.py [--browser-path PATH]\n" + "Rustwright otherwise uses RUSTWRIGHT_CHROMIUM, CHROME, or CHROMIUM.\n" + "Set RUSTWRIGHT_CDP_TRANSPORT to websocket or pipe." + ) + return 0 + + epoch_ns = 0 + phases: list[dict[str, object]] = [] + current_phase = MEASURED_PHASES[0] + rustwright = None + manager = None + playwright = None + chromium = None + browser = None + page = None + probe: dict[str, object] | None = None + + def measure(name: str, operation): + nonlocal current_phase + current_phase = name + start_offset_ns = phases[-1]["end_offset_ns"] if phases else 0 + value = operation() + end_offset_ns = time.perf_counter_ns() - epoch_ns + phases.append( + { + "name": name, + "status": "ok", + "start_offset_ns": start_offset_ns, + "end_offset_ns": end_offset_ns, + "duration_ns": end_offset_ns - start_offset_ns, + } + ) + return value + + epoch_ns = time.perf_counter_ns() + try: + rustwright = measure("python_import", lambda: importlib.import_module("rustwright")) + manager = measure("manager_factory", rustwright.sync_playwright) + playwright = measure("api_startup", manager.start) + chromium = measure("chromium_facade_first_access", lambda: playwright.chromium) + + launch_options: dict[str, object] = {} + if browser_path: + launch_options["executable_path"] = browser_path + browser = measure("browser_launch", lambda: chromium.launch(**launch_options)) + page = measure("first_page", browser.new_page) + + def assert_first_page() -> dict[str, object]: + observed = { + "url": page.url, + "viewport_size": page.viewport_size, + } + expected = { + "url": "about:blank", + "viewport_size": {"width": 1280, "height": 720}, + } + if observed != expected: + raise AssertionError(f"blank-page probe mismatch: {observed!r}") + return observed + + probe = measure("first_page_probe", assert_first_page) + + def close_all() -> None: + nonlocal page, browser, playwright + page.close() + page = None + browser.close() + browser = None + playwright.stop() + playwright = None + + measure("close", close_all) + except Exception as exc: + import os + cleanup_errors = cleanup(page, browser, playwright) + error_record = { + "schema_version": 1, + "status": "error", + "entrypoint": ENTRYPOINT, + "pid": os.getpid(), + "failed_phase": current_phase, + "error_type": type(exc).__name__, + "error_message": str(exc), + "cleanup_errors": cleanup_errors, + "core_timing_file": os.environ.get("RUSTWRIGHT_STARTUP_TIMING_FILE"), + } + emit_record(error_record) + return 1 + + import os + import platform + for previous, current in zip(phases, phases[1:]): + if previous["end_offset_ns"] != current["start_offset_ns"]: + error_record = { + "schema_version": 1, + "status": "error", + "entrypoint": ENTRYPOINT, + "pid": os.getpid(), + "failed_phase": "timing_validation", + "error_type": "NonContiguousTimingError", + "error_message": ( + f"{previous['name']} ended at {previous['end_offset_ns']} ns; " + f"{current['name']} started at {current['start_offset_ns']} ns" + ), + "cleanup_errors": [], + "core_timing_file": os.environ.get("RUSTWRIGHT_STARTUP_TIMING_FILE"), + } + emit_record(error_record) + return 1 + + first_page_phase = phases[MEASURED_PHASES.index("first_page")] + total_duration_ns = first_page_phase["end_offset_ns"] - phases[0]["start_offset_ns"] + + core_timing_file = os.environ.get("RUSTWRIGHT_STARTUP_TIMING_FILE") + result = { + "schema_version": 1, + "status": "ok", + "entrypoint": ENTRYPOINT, + "pid": os.getpid(), + "clock": "perf_counter_ns", + "clock_precision_ns": 1, + "phases": phases, + "derived": { + "cold_process_to_first_page": { + "status": "ok", + "start_offset_ns": phases[0]["start_offset_ns"], + "end_offset_ns": first_page_phase["end_offset_ns"], + "duration_ns": total_duration_ns, + } + }, + "probe": probe, + "python_version": platform.python_version(), + "browser_version": os.environ.get("RUSTWRIGHT_BROWSER_VERSION"), + "library_version": package_version(), + "browser_path": requested_browser_path(browser_path), + "transport": os.environ.get("RUSTWRIGHT_CDP_TRANSPORT") or "websocket", + "core_timing_file": core_timing_file, + "core_probe": read_core_probe(core_timing_file), + } + emit_record(result) + return 0 + + +if __name__ == "__main__": + raise SystemExit(main()) diff --git a/python/rustwright/__init__.py b/python/rustwright/__init__.py index 9699488..ab21afd 100644 --- a/python/rustwright/__init__.py +++ b/python/rustwright/__init__.py @@ -26,7 +26,6 @@ expect, sync_playwright, ) -from .async_api import async_playwright __all__ = [ "Browser", @@ -56,3 +55,17 @@ "async_playwright", "sync_playwright", ] + + +# Import attribution showed the async facade subtree is about 20% of package import, so defer it for sync-only users. +def __getattr__(name: str): + if name == "async_playwright": + from .async_api import async_playwright + + globals()[name] = async_playwright + return async_playwright + raise AttributeError(f"module {__name__!r} has no attribute {name!r}") + + +def __dir__() -> list[str]: + return sorted(set(globals()) | set(__all__)) diff --git a/src/lib.rs b/src/lib.rs index b42fd9a..77dcf80 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -38,6 +38,7 @@ use tokio_tungstenite::tungstenite::http::{HeaderName, HeaderValue, Uri}; use tokio_tungstenite::tungstenite::{Error as WsError, Message}; use tokio_tungstenite::{connect_async, MaybeTlsStream}; +mod startup_timing; mod telemetry; pub type RwResult = Result; @@ -3419,12 +3420,13 @@ mod tests { let browser = Arc::new(BrowserInner { runtime: OwnedRuntime::new(runtime), client: Arc::new(client), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -5181,12 +5183,13 @@ multiline-compatible = """4.5.6""" let browser = Arc::new(BrowserInner { runtime: OwnedRuntime::new(runtime), client: Arc::clone(&client), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -5319,12 +5322,13 @@ multiline-compatible = """4.5.6""" let browser = Arc::new(BrowserInner { runtime: OwnedRuntime::new(runtime), client: Arc::clone(&client), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -6000,12 +6004,13 @@ multiline-compatible = """4.5.6""" alive: Arc::new(AtomicBool::new(true)), alive_tx, }), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -6451,6 +6456,28 @@ multiline-compatible = """4.5.6""" ); } + #[test] + fn browser_keyboard_platform_state_defaults_to_control_and_sets_once() { + let mac_first = BrowserKeyboardPlatformState::default(); + assert_eq!(mac_first.get(), BrowserKeyboardPlatform::Control); + assert!(mac_first.set_once_from_version(&json!({ + "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 14_0)" + }))); + assert!(!mac_first.set_once_from_version(&json!({ + "userAgent": "Mozilla/5.0 (X11; Linux x86_64)" + }))); + assert_eq!(mac_first.get(), BrowserKeyboardPlatform::Mac); + + let control_first = BrowserKeyboardPlatformState::default(); + assert!(control_first.set_once_from_version(&json!({ + "userAgent": "Mozilla/5.0 (X11; Linux x86_64)" + }))); + assert!(!control_first.set_once_from_version(&json!({ + "userAgent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 14_0)" + }))); + assert_eq!(control_first.get(), BrowserKeyboardPlatform::Control); + } + #[test] fn key_chord_parsing_deduplicates_repeated_modifiers() { // Holding a held modifier is a no-op for the page but not for us: each @@ -8647,12 +8674,13 @@ multiline-compatible = """4.5.6""" alive: Arc::new(AtomicBool::new(true)), alive_tx, }), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -8713,12 +8741,13 @@ multiline-compatible = """4.5.6""" alive: Arc::new(AtomicBool::new(true)), alive_tx, }), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -9035,12 +9064,13 @@ multiline-compatible = """4.5.6""" let browser = Arc::new(BrowserInner { runtime: OwnedRuntime::new(runtime), client: Arc::clone(&client), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -9205,12 +9235,13 @@ multiline-compatible = """4.5.6""" alive: Arc::new(AtomicBool::new(true)), alive_tx, }), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -10011,12 +10042,13 @@ multiline-compatible = """4.5.6""" let browser = Arc::new(BrowserInner { runtime: OwnedRuntime::new(tokio::runtime::Runtime::new().unwrap()), client, + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -18247,12 +18279,13 @@ async fn settle_write_status( struct BrowserInner { runtime: OwnedRuntime, client: Arc, + startup_probe: Option>, process: Mutex>, profile_dir: Mutex>, owned: bool, ws_endpoint: String, stealth_user_agent_override: Mutex>, - keyboard_platform: BrowserKeyboardPlatform, + keyboard_platform: BrowserKeyboardPlatformState, single_process_fallback: bool, lifecycle: Arc, attached_pages: AttachedPageRegistry, @@ -18295,20 +18328,30 @@ impl BrowserKeyboardPlatform { } } -fn detect_browser_keyboard_platform( - runtime: &tokio::runtime::Runtime, - client: &CdpClient, - timeout: Duration, -) -> BrowserKeyboardPlatform { - if timeout.is_zero() { - return BrowserKeyboardPlatform::Control; +#[derive(Default)] +struct BrowserKeyboardPlatformState(AtomicU8); + +impl BrowserKeyboardPlatformState { + const UNSET: u8 = 0; + const CONTROL: u8 = 1; + const MAC: u8 = 2; + + fn get(&self) -> BrowserKeyboardPlatform { + match self.0.load(Ordering::SeqCst) { + Self::MAC => BrowserKeyboardPlatform::Mac, + _ => BrowserKeyboardPlatform::Control, + } + } + + fn set_once_from_version(&self, version: &Value) -> bool { + let value = match BrowserKeyboardPlatform::from_version(version) { + BrowserKeyboardPlatform::Mac => Self::MAC, + BrowserKeyboardPlatform::Control => Self::CONTROL, + }; + self.0 + .compare_exchange(Self::UNSET, value, Ordering::SeqCst, Ordering::SeqCst) + .is_ok() } - runtime - .block_on(client.send("Browser.getVersion", json!({}), None, timeout)) - .map(|version| BrowserKeyboardPlatform::from_version(&version)) - // Browser keyboard semantics must never depend on the client host. If - // metadata is unavailable, use the cross-platform Control mapping. - .unwrap_or_default() } #[derive(Default)] @@ -19034,6 +19077,41 @@ fn browser_context_create_params(options_json: Option<&str>) -> RwResult } Ok(params) } +async fn create_browser_context_inner( + browser: Arc, + params: Value, +) -> RwResult> { + let startup_probe = browser.startup_probe.clone(); + startup_timing::measure_phase_async( + startup_probe.as_deref(), + startup_timing::Phase::ContextCreate, + Some(startup_timing::ParentPhase::PageCreate), + async move { + let result = browser + .client + .send( + "Target.createBrowserContext", + params, + None, + Duration::from_secs(5), + ) + .await?; + let context_id = result + .get("browserContextId") + .and_then(Value::as_str) + .ok_or_else(|| { + RwError::Message("CDP did not return a browserContextId".to_string()) + })? + .to_string(); + Ok(Arc::new(ContextInner { + browser, + context_id: Some(context_id), + lifecycle: Arc::new(CloseLifecycle::new()), + })) + }, + ) + .await +} async fn close_context_cleanup(context: Arc) -> RwResult<()> { if let Some(context_id) = context.context_id.clone() { @@ -21159,31 +21237,10 @@ impl PyBrowser { fn new_context(&self, options_json: Option<&str>) -> PyResult { let params = browser_context_create_params(options_json).map_err(py_err)?; let browser = Arc::clone(&self.inner); - let result = browser - .block_on(async { - browser - .client - .send( - "Target.createBrowserContext", - params, - None, - Duration::from_secs(5), - ) - .await - }) + let inner = browser + .block_on(create_browser_context_inner(Arc::clone(&browser), params)) .map_err(py_err)?; - let context_id = result - .get("browserContextId") - .and_then(Value::as_str) - .ok_or_else(|| PyRuntimeError::new_err("CDP did not return a browserContextId"))? - .to_string(); - Ok(PyBrowserContext { - inner: Arc::new(ContextInner { - browser: Arc::clone(&self.inner), - context_id: Some(context_id), - lifecycle: Arc::new(CloseLifecycle::new()), - }), - }) + Ok(PyBrowserContext { inner }) } #[pyo3(signature = (options_json=None))] @@ -21191,32 +21248,7 @@ impl PyBrowser { let params = browser_context_create_params(options_json).map_err(py_err)?; let browser = Arc::clone(&self.inner); let runtime = browser.runtime.handle().clone(); - let future_browser = Arc::clone(&browser); - let creation = runtime.spawn(async move { - let result = future_browser - .client - .send( - "Target.createBrowserContext", - params, - None, - Duration::from_secs(5), - ) - .await?; - let context_id = result - .get("browserContextId") - .and_then(Value::as_str) - .ok_or_else(|| { - RwError::Message("CDP did not return a browserContextId".to_string()) - })? - .to_string(); - Ok(PyBrowserContext { - inner: Arc::new(ContextInner { - browser: future_browser, - context_id: Some(context_id), - lifecycle: Arc::new(CloseLifecycle::new()), - }), - }) - }); + let creation = runtime.spawn(create_browser_context_inner(browser, params)); python_future_on( py, runtime, @@ -21225,7 +21257,7 @@ impl PyBrowser { .await .map_err(|error| RwError::Message(error.to_string()))? }, - |py, context| Ok(Py::new(py, context)?.into_any()), + |py, inner| Ok(Py::new(py, PyBrowserContext { inner })?.into_any()), ) } @@ -29976,7 +30008,11 @@ return { ready: true, result: true, payload: null }; } fn keyboard_primary_modifier(&self) -> &'static str { - self.inner.browser.keyboard_platform.primary_modifier() + self.inner + .browser + .keyboard_platform + .get() + .primary_modifier() } #[pyo3(signature = (text, delay_ms=None, timeout_ms=None))] @@ -29998,7 +30034,7 @@ return { ready: true, result: true, payload: null }; &text, delay, transport_timeout, - page.browser.keyboard_platform, + page.browser.keyboard_platform.get(), )) .map_err(py_err) } @@ -32171,58 +32207,82 @@ impl PyPage { } fn launch_chromium_with_options(options: LaunchOptions) -> RwResult> { - launch_chromium_with_options_cancelable(options, None) -} - -fn launch_chromium_with_options_cancelable( - options: LaunchOptions, - cancelled: Option>, -) -> RwResult> { - launch_chromium_with_options_cancellation(options, cancelled, None) + launch_chromium_with_options_cancellation( + options, + None, + None, + Some(startup_timing::EntryPoint::RustNative), + ) } fn launch_chromium_with_options_token( options: LaunchOptions, cancel: CancelToken, ) -> RwResult> { - launch_chromium_with_options_cancellation(options, Some(cancel.atomic_flag()), Some(cancel)) + launch_chromium_with_options_cancellation( + options, + Some(cancel.atomic_flag()), + Some(cancel), + Some(startup_timing::EntryPoint::RustNative), + ) } fn launch_chromium_with_options_cancellation( mut options: LaunchOptions, cancelled: Option>, cancel: Option, + entrypoint: Option, ) -> RwResult> { + let startup_probe = startup_timing::StartupProbe::from_env( + entrypoint.unwrap_or(startup_timing::EntryPoint::Unknown), + ); if options.timeout.is_none() { options.timeout = Some(30_000.0); } - let runtime = tokio::runtime::Builder::new_multi_thread() - .enable_all() - .worker_threads(2) - .build() - .map_err(|error| RwError::Message(error.to_string()))?; + let runtime = startup_timing::measure_phase( + startup_probe.as_deref(), + startup_timing::Phase::RuntimeCreate, + Some(startup_timing::ParentPhase::BrowserLaunch), + || { + tokio::runtime::Builder::new_multi_thread() + .enable_all() + .worker_threads(2) + .build() + .map_err(|error| RwError::Message(error.to_string())) + }, + )?; let timeout = BrowserInner::command_timeout(options.timeout); - let (mut child, profile_dir, transport, single_process_fallback) = - launch_chromium_process(&options, &runtime, timeout, cancelled.clone())?; + let (mut child, profile_dir, transport, single_process_fallback) = launch_chromium_process( + &options, + &runtime, + timeout, + cancelled.clone(), + startup_probe.as_deref(), + )?; let ws_endpoint = transport.endpoint_label(); - let client_result = match transport { - LaunchedCdpTransport::WebSocket(endpoint) => runtime.block_on(async { - if let Some(cancelled) = cancelled.clone() { - tokio::select! { - result = CdpClient::connect(&endpoint) => result, - () = wait_for_launch_cancellation(cancelled) => { - Err(RwError::Message("browser launch was cancelled".to_string())) + let client_result = startup_timing::measure_phase( + startup_probe.as_deref(), + startup_timing::Phase::TransportConnect, + Some(startup_timing::ParentPhase::BrowserLaunch), + || match transport { + LaunchedCdpTransport::WebSocket(endpoint) => runtime.block_on(async { + if let Some(cancelled) = cancelled.clone() { + tokio::select! { + result = CdpClient::connect(&endpoint) => result, + () = wait_for_launch_cancellation(cancelled) => { + Err(RwError::Message("browser launch was cancelled".to_string())) + } } + } else { + CdpClient::connect(&endpoint).await } - } else { - CdpClient::connect(&endpoint).await + }), + #[cfg(unix)] + LaunchedCdpTransport::Pipe { read, write } => { + runtime.block_on(CdpClient::connect_pipe(read, write)) } - }), - #[cfg(unix)] - LaunchedCdpTransport::Pipe { read, write } => { - runtime.block_on(CdpClient::connect_pipe(read, write)) - } - }; + }, + ); let client = match client_result { Ok(client) => client, Err(error) => { @@ -32231,39 +32291,47 @@ fn launch_chromium_with_options_cancellation( return Err(error); } }; - let keyboard_platform = - detect_browser_keyboard_platform(&runtime, &client, Duration::from_secs(5)); if let Err(error) = start_service_worker_stealth_auto_attach_cancelable( &runtime, Arc::clone(&client), Duration::from_secs(5), cancel, + startup_probe.as_deref(), ) { client.close(); let _ = child.kill(); let _ = child.wait(); return Err(error); } - let browser = Arc::new(BrowserInner { - runtime: OwnedRuntime::new(runtime), - client, - process: Mutex::new(Some(child)), - profile_dir: Mutex::new(profile_dir), - owned: true, - ws_endpoint, - stealth_user_agent_override: Mutex::new(None), - keyboard_platform, - single_process_fallback, - lifecycle: Arc::new(CloseLifecycle::new()), - attached_pages: AttachedPageRegistry::default(), - next_native_network_index: AtomicU64::new(1), - }); - if launch_was_cancelled(cancelled.as_ref()) { - let _ = close_browser_blocking(Arc::clone(&browser)); - return Err(RwError::Message("browser launch was cancelled".to_string())); - } - telemetry::record_engine_launched(&browser.runtime); - Ok(browser) + let browser_probe = startup_probe.clone(); + startup_timing::measure_phase( + startup_probe.as_deref(), + startup_timing::Phase::BrowserReturn, + Some(startup_timing::ParentPhase::BrowserLaunch), + || { + let browser = Arc::new(BrowserInner { + runtime: OwnedRuntime::new(runtime), + client, + startup_probe: browser_probe, + process: Mutex::new(Some(child)), + profile_dir: Mutex::new(profile_dir), + owned: true, + ws_endpoint, + stealth_user_agent_override: Mutex::new(None), + keyboard_platform: BrowserKeyboardPlatformState::default(), + single_process_fallback, + lifecycle: Arc::new(CloseLifecycle::new()), + attached_pages: AttachedPageRegistry::default(), + next_native_network_index: AtomicU64::new(1), + }); + if launch_was_cancelled(cancelled.as_ref()) { + let _ = close_browser_blocking(Arc::clone(&browser)); + return Err(RwError::Message("browser launch was cancelled".to_string())); + } + telemetry::record_engine_launched(&browser.runtime); + Ok(browser) + }, + ) } fn launch_was_cancelled(cancelled: Option<&Arc>) -> bool { @@ -32284,7 +32352,14 @@ fn launch_chromium(py: Python<'_>, options_json: &str) -> PyResult { let options: LaunchOptions = serde_json::from_str(options_json) .map_err(|error| PyValueError::new_err(error.to_string()))?; let inner = py - .detach(move || launch_chromium_with_options(options)) + .detach(move || { + launch_chromium_with_options_cancellation( + options, + None, + None, + Some(startup_timing::EntryPoint::PythonSync), + ) + }) .map_err(py_err)?; Ok(PyBrowser { inner }) } @@ -32298,7 +32373,12 @@ fn launch_chromium_async(py: Python<'_>, options_json: &str) -> PyResult, ) -> RwResult<()> { // Validate before focusing so an invalid key cannot fire page focus handlers. - parse_key_chord(key, page.browser.keyboard_platform)?; + let keyboard_platform = page.browser.keyboard_platform.get(); + parse_key_chord(key, keyboard_platform)?; let focus = match locator_json { Some(locator_json) => Some( focus_locator_for_native_input(page, locator_json, index, deadline, cancel.cloned()) @@ -35620,7 +35700,7 @@ async fn press_locator_for_native_input( deadline, delay_policy, cancel, - page.browser.keyboard_platform, + keyboard_platform, ) .await } else { @@ -35632,7 +35712,7 @@ async fn press_locator_for_native_input( deadline, delay_policy, cancel, - page.browser.keyboard_platform, + keyboard_platform, ) .await }; @@ -36279,13 +36359,6 @@ fn create_page(browser: Arc, context_id: Option) -> RwResu .map(|inner| PyPage { inner }) } -fn create_page_raw( - browser: Arc, - context_id: Option, -) -> RwResult> { - create_page_raw_cancelable(browser, context_id, None) -} - fn create_page_raw_cancelable( browser: Arc, context_id: Option, @@ -36305,8 +36378,20 @@ async fn create_page_async( let mut params = json!({ "url": "about:blank" }); if let Some(context_id) = &context_id { params["browserContextId"] = Value::String(context_id.clone()); + } else { + startup_timing::record_skipped( + browser.startup_probe.as_deref(), + startup_timing::Phase::ContextCreate, + Some(startup_timing::ParentPhase::PageCreate), + ); } - let target_guard = create_target_cancellation_safe(Arc::clone(&browser), params).await?; + let target_guard = startup_timing::measure_phase_async( + browser.startup_probe.as_deref(), + startup_timing::Phase::TargetCreate, + Some(startup_timing::ParentPhase::PageCreate), + create_target_cancellation_safe(Arc::clone(&browser), params), + ) + .await?; let target_id = target_guard .target_id .as_deref() @@ -36434,59 +36519,94 @@ async fn attach_existing_page_unregistered( timeout: Duration, session_cleanup: Arc, ) -> RwResult { - let attached = browser - .client - .send( - "Target.attachToTarget", - json!({ "targetId": target_id, "flatten": true }), - None, - timeout, - ) - .await?; - let session_id = attached - .get("sessionId") - .and_then(Value::as_str) - .ok_or_else(|| RwError::Message("CDP did not return a sessionId".to_string()))? - .to_string(); + let session_id = startup_timing::measure_phase_async( + browser.startup_probe.as_deref(), + startup_timing::Phase::TargetAttach, + Some(startup_timing::ParentPhase::PageCreate), + async { + let attached = browser + .client + .send( + "Target.attachToTarget", + json!({ "targetId": target_id, "flatten": true }), + None, + timeout, + ) + .await?; + attached + .get("sessionId") + .and_then(Value::as_str) + .ok_or_else(|| RwError::Message("CDP did not return a sessionId".to_string())) + .map(ToString::to_string) + }, + ) + .await?; session_cleanup.set_session(session_id.clone()); let session_guard = AttachedSessionGuard::new(session_cleanup); let event_stream_start_cursor = browser.client.event_cursor(); - initialize_attached_page_session(&browser.client, &session_id, Duration::from_secs(5)).await?; + initialize_attached_page_session( + &browser.client, + &session_id, + Duration::from_secs(5), + browser.startup_probe.as_deref(), + ) + .await?; - install_stealth_defaults(&browser, &session_id).await?; - enable_page_iframe_auto_attach(&browser.client, &session_id, Duration::from_secs(5)).await?; - let page_inner = Arc::new(PageInner { - browser: Arc::clone(&browser), - target_id, - registry_generation, - session_id: session_id.clone(), - context_id, - main_frame_id: Mutex::new(None), - frame_state: Mutex::new(PageFrameState::new(session_id.clone())), - iframe_setup_tasks: IframeSetupTaskRegistry::default(), - network_requests: Arc::new(Mutex::new(NetworkRequestStore::new( - event_stream_start_cursor, - ))), - console_records: Mutex::new(ConsoleRecordStore::default()), - console_capture: tokio::sync::Mutex::new(ConsoleCaptureState::default()), - console_replay_until_event_cursor: Mutex::new(HashMap::new()), - observation_event_cursor: AtomicU64::new(0), - native_network_records: Mutex::new(NativeNetworkRecordStore::new( - browser.next_native_network_index.load(Ordering::SeqCst), - )), - event_stream_start_cursor, - background_override_active: Arc::new(AtomicBool::new(false)), - screenshot_lock: Arc::new(tokio::sync::Mutex::new(())), - mouse_dispatch_lock: Arc::new(tokio::sync::Mutex::new(())), - fill_dispatch_lock: Arc::new(tokio::sync::Mutex::new(())), - default_timeouts: Mutex::new(DefaultTimeoutRegister::default()), - lifecycle: Arc::new(CloseLifecycle::new()), - target_closed: AtomicBool::new(false), - crashed: AtomicBool::new(false), - close_target_on_drop: AtomicBool::new(false), - }); - let _ = refresh_page_frame_tree(&page_inner, Duration::from_secs(5)).await; - spawn_page_oopif_event_listener(Arc::downgrade(&page_inner)); + startup_timing::measure_phase_async( + browser.startup_probe.as_deref(), + startup_timing::Phase::PageStealth, + Some(startup_timing::ParentPhase::PageCreate), + install_stealth_defaults(&browser, &session_id), + ) + .await?; + startup_timing::measure_phase_async( + browser.startup_probe.as_deref(), + startup_timing::Phase::PageIframeAttach, + Some(startup_timing::ParentPhase::PageCreate), + enable_page_iframe_auto_attach(&browser.client, &session_id, Duration::from_secs(5)), + ) + .await?; + let page_inner = startup_timing::measure_phase_async( + browser.startup_probe.as_deref(), + startup_timing::Phase::PageStateAndFrameTree, + Some(startup_timing::ParentPhase::PageCreate), + async { + let page_inner = Arc::new(PageInner { + browser: Arc::clone(&browser), + target_id, + registry_generation, + session_id: session_id.clone(), + context_id, + main_frame_id: Mutex::new(None), + frame_state: Mutex::new(PageFrameState::new(session_id.clone())), + iframe_setup_tasks: IframeSetupTaskRegistry::default(), + network_requests: Arc::new(Mutex::new(NetworkRequestStore::new( + event_stream_start_cursor, + ))), + console_records: Mutex::new(ConsoleRecordStore::default()), + console_capture: tokio::sync::Mutex::new(ConsoleCaptureState::default()), + console_replay_until_event_cursor: Mutex::new(HashMap::new()), + observation_event_cursor: AtomicU64::new(0), + native_network_records: Mutex::new(NativeNetworkRecordStore::new( + browser.next_native_network_index.load(Ordering::SeqCst), + )), + event_stream_start_cursor, + background_override_active: Arc::new(AtomicBool::new(false)), + screenshot_lock: Arc::new(tokio::sync::Mutex::new(())), + mouse_dispatch_lock: Arc::new(tokio::sync::Mutex::new(())), + fill_dispatch_lock: Arc::new(tokio::sync::Mutex::new(())), + default_timeouts: Mutex::new(DefaultTimeoutRegister::default()), + lifecycle: Arc::new(CloseLifecycle::new()), + target_closed: AtomicBool::new(false), + crashed: AtomicBool::new(false), + close_target_on_drop: AtomicBool::new(false), + }); + let _ = refresh_page_frame_tree(&page_inner, Duration::from_secs(5)).await; + spawn_page_oopif_event_listener(Arc::downgrade(&page_inner)); + Ok::<_, RwError>(page_inner) + }, + ) + .await?; Ok(UnregisteredPage { page: page_inner, session_guard, @@ -36687,10 +36807,25 @@ async fn initialize_attached_page_session( client: &Arc, session_id: &str, timeout: Duration, + startup_probe: Option<&startup_timing::StartupProbe>, ) -> RwResult<()> { - enable_attached_session_domains(client, session_id, timeout).await?; - enable_action_dispatch_binding_for_session(client, session_id, timeout).await?; - finish_attached_page_session_initialization(client, session_id, timeout).await + startup_timing::measure_phase_async( + startup_probe, + startup_timing::Phase::PageDomains, + Some(startup_timing::ParentPhase::PageCreate), + enable_attached_session_domains(client, session_id, timeout), + ) + .await?; + startup_timing::measure_phase_async( + startup_probe, + startup_timing::Phase::PageOptionalAttach, + Some(startup_timing::ParentPhase::PageCreate), + async { + enable_action_dispatch_binding_for_session(client, session_id, timeout).await?; + finish_attached_page_session_initialization(client, session_id, timeout).await + }, + ) + .await } async fn enable_attached_session_domains( @@ -37875,12 +38010,13 @@ mod native_console_record_tests { alive: Arc::new(AtomicBool::new(true)), alive_tx, }), + startup_probe: None, process: Mutex::new(None), profile_dir: Mutex::new(None), owned: false, ws_endpoint: "ws://test.invalid".to_string(), stealth_user_agent_override: Mutex::new(None), - keyboard_platform: BrowserKeyboardPlatform::Control, + keyboard_platform: BrowserKeyboardPlatformState::default(), single_process_fallback: false, lifecycle: Arc::new(CloseLifecycle::new()), attached_pages: AttachedPageRegistry::default(), @@ -38341,6 +38477,7 @@ async fn install_stealth_defaults(browser: &BrowserInner, session_id: &str) -> R Duration::from_secs(5), ) .await?; + browser.keyboard_platform.set_once_from_version(&version); let override_value = version .get("userAgent") .and_then(Value::as_str) @@ -38407,21 +38544,15 @@ async fn install_worker_stealth_defaults(client: &CdpClient, session_id: &str) - Ok(()) } -fn start_service_worker_stealth_auto_attach( - runtime: &tokio::runtime::Runtime, - client: Arc, - timeout: Duration, -) -> RwResult<()> { - start_service_worker_stealth_auto_attach_cancelable(runtime, client, timeout, None) -} - fn start_service_worker_stealth_auto_attach_cancelable( runtime: &tokio::runtime::Runtime, client: Arc, timeout: Duration, cancel: Option, + startup_probe: Option<&startup_timing::StartupProbe>, ) -> RwResult<()> { - runtime.block_on(cancelable(cancel, async { + let phase_started = startup_probe.map(|_| Instant::now()); + let result = runtime.block_on(cancelable(cancel, async { client .send( "Target.setAutoAttach", @@ -38443,7 +38574,20 @@ fn start_service_worker_stealth_auto_attach_cancelable( ) .await .map(|_| ()) - }))?; + })); + let phase_timing = phase_started.map(|started| (started, started.elapsed())); + if let Err(error) = result { + if let (Some(probe), Some((started, duration))) = (startup_probe, phase_timing) { + probe.record( + startup_timing::Phase::ServiceWorkerAutoAttach, + Some(startup_timing::ParentPhase::BrowserLaunch), + started, + duration, + startup_timing::Status::Error, + ); + } + return Err(error); + } let mut events = client.subscribe(); runtime.spawn(async move { @@ -38483,6 +38627,15 @@ fn start_service_worker_stealth_auto_attach_cancelable( .await; } }); + if let (Some(probe), Some((started, duration))) = (startup_probe, phase_timing) { + probe.record( + startup_timing::Phase::ServiceWorkerAutoAttach, + Some(startup_timing::ParentPhase::BrowserLaunch), + started, + duration, + startup_timing::Status::Ok, + ); + } Ok(()) } @@ -39189,7 +39342,13 @@ fn launch_chromium_process( runtime: &tokio::runtime::Runtime, timeout: Duration, cancelled: Option>, + startup_probe: Option<&startup_timing::StartupProbe>, ) -> RwResult<(Child, Option, LaunchedCdpTransport, bool)> { + let mut launch_phases = startup_timing::PhaseSpan::new( + startup_probe, + startup_timing::Phase::LaunchPrepare, + Some(startup_timing::ParentPhase::BrowserLaunch), + ); let executable = find_chromium_executable( options.executable_path.as_deref(), options.channel.as_deref(), @@ -39207,6 +39366,13 @@ fn launch_chromium_process( })?; let user_debugging_port = remote_debugging_port_from_args(&options.args)?; let use_pipe_transport = chromium_pipe_transport_requested()?; + if let Some(startup_probe) = startup_probe { + startup_probe.set_transport(if use_pipe_transport { + startup_timing::Transport::Pipe + } else { + startup_timing::Transport::Websocket + }); + } if use_pipe_transport && user_debugging_port.is_some() { return Err(RwError::Message( "RUSTWRIGHT_CDP_TRANSPORT=pipe cannot be combined with --remote-debugging-port launch args" @@ -39240,9 +39406,23 @@ fn launch_chromium_process( dynamic_debugging_port, use_pipe_transport, cancelled.clone(), + &mut launch_phases, ) { - Ok((child, transport)) => return Ok((child, profile_dir, transport, false)), - Err(error) if should_retry_chromium_single_process(options, &error) => { + Ok((child, transport)) => { + launch_phases.finish(startup_timing::Status::Ok); + Ok((child, profile_dir, transport, false)) + } + Err(error) => { + launch_phases.finish(startup_timing::Status::Error); + if !should_retry_chromium_single_process(options, &error) { + return Err(error); + } + + let mut retry_launch_phases = startup_timing::PhaseSpan::new( + startup_probe, + startup_timing::Phase::LaunchPrepare, + Some(startup_timing::ParentPhase::BrowserLaunch), + ); match launch_chromium_attempt( &executable, options, @@ -39255,16 +39435,20 @@ fn launch_chromium_process( dynamic_debugging_port, use_pipe_transport, cancelled, + &mut retry_launch_phases, ) { - Ok((child, transport)) => return Ok((child, profile_dir, transport, true)), + Ok((child, transport)) => { + retry_launch_phases.finish(startup_timing::Status::Ok); + Ok((child, profile_dir, transport, true)) + } Err(retry_error) => { - return Err(RwError::Message(format!( + retry_launch_phases.finish(startup_timing::Status::Error); + Err(RwError::Message(format!( "{error}\nRetrying with --single-process also failed: {retry_error}" - ))); + ))) } } } - Err(error) => return Err(error), } } @@ -39306,6 +39490,7 @@ fn launch_chromium_attempt( dynamic_debugging_port: bool, use_pipe_transport: bool, cancelled: Option>, + launch_phases: &mut startup_timing::PhaseSpan<'_>, ) -> RwResult<(Child, LaunchedCdpTransport)> { let stderr_file = NamedTempFile::new()?; let mut command = Command::new(executable); @@ -39369,6 +39554,7 @@ fn launch_chromium_attempt( } command.arg("about:blank"); + launch_phases.transition(startup_timing::Phase::ProcessToEndpoint); let mut child = match command.spawn() { Ok(child) => child, Err(error) => { diff --git a/src/startup_timing.rs b/src/startup_timing.rs new file mode 100644 index 0000000..b7e5eeb --- /dev/null +++ b/src/startup_timing.rs @@ -0,0 +1,495 @@ +use std::collections::hash_map::RandomState; +use std::env; +use std::fs::OpenOptions; +use std::future::Future; +use std::hash::BuildHasher; +use std::io::{self, Write}; +#[cfg(unix)] +use std::os::unix::fs::OpenOptionsExt; +use std::path::PathBuf; +use std::process; +use std::sync::atomic::{AtomicU8, Ordering}; +use std::sync::{Arc, LazyLock, Mutex}; +use std::time::{Duration, Instant}; + +use serde::Serialize; + +const STARTUP_TIMING_ENV: &str = "RUSTWRIGHT_STARTUP_TIMING_FILE"; + +static PROCESS_IDENTITY: LazyLock = LazyLock::new(|| ProcessIdentity { + epoch: Instant::now(), + startup_id: random_startup_id(), +}); +static PROCESS_WRITE_LOCK: Mutex<()> = Mutex::new(()); + +struct ProcessIdentity { + epoch: Instant, + startup_id: String, +} + +#[derive(Clone, Copy, Debug, Eq, PartialEq, Serialize)] +#[serde(rename_all = "kebab-case")] +pub(crate) enum EntryPoint { + PythonSync, + PythonAsync, + RustNative, + Unknown, +} + +#[derive(Clone, Copy, Debug, Eq, PartialEq, Serialize)] +#[serde(rename_all = "snake_case")] +pub(crate) enum Phase { + RuntimeCreate, + LaunchPrepare, + ProcessToEndpoint, + TransportConnect, + ServiceWorkerAutoAttach, + BrowserReturn, + ContextCreate, + TargetCreate, + TargetAttach, + PageDomains, + PageOptionalAttach, + PageStealth, + PageIframeAttach, + PageStateAndFrameTree, +} + +#[derive(Clone, Copy, Debug, Eq, PartialEq, Serialize)] +#[serde(rename_all = "snake_case")] +pub(crate) enum ParentPhase { + BrowserLaunch, + PageCreate, +} + +#[derive(Clone, Copy, Debug, Eq, PartialEq, Serialize)] +#[serde(rename_all = "lowercase")] +pub(crate) enum Status { + Ok, + Error, + Skipped, +} + +#[derive(Clone, Copy, Debug, Eq, PartialEq, Serialize)] +#[serde(rename_all = "lowercase")] +pub(crate) enum Transport { + Websocket, + Pipe, + None, +} + +impl Transport { + const fn as_u8(self) -> u8 { + match self { + Self::None => 0, + Self::Websocket => 1, + Self::Pipe => 2, + } + } + + const fn from_u8(value: u8) -> Self { + match value { + 1 => Self::Websocket, + 2 => Self::Pipe, + _ => Self::None, + } + } +} + +#[derive(Serialize)] +struct PhaseRecord<'a> { + schema_version: u8, + startup_id: &'a str, + pid: u32, + entrypoint: EntryPoint, + phase: Phase, + parent_phase: Option, + start_offset_ns: u128, + duration_ns: u128, + status: Status, + transport: Transport, +} + +impl<'a> PhaseRecord<'a> { + #[allow(clippy::too_many_arguments)] + fn new( + startup_id: &'a str, + pid: u32, + entrypoint: EntryPoint, + phase: Phase, + parent_phase: Option, + start_offset_ns: u128, + duration_ns: u128, + status: Status, + transport: Transport, + ) -> Self { + Self { + schema_version: 1, + startup_id, + pid, + entrypoint, + phase, + parent_phase, + start_offset_ns, + duration_ns, + status, + transport, + } + } +} + +enum Destination { + Stderr, + File(PathBuf), +} + +fn write_record(destination: &Destination, line: &[u8]) { + match destination { + Destination::Stderr => { + let stderr = io::stderr(); + let mut stderr = stderr.lock(); + let _ = stderr.write_all(line); + } + Destination::File(path) => { + let mut options = OpenOptions::new(); + options.create(true).append(true); + #[cfg(unix)] + options.custom_flags(libc::O_NONBLOCK); + let Ok(mut file) = options.open(path) else { + return; + }; + let Ok(metadata) = file.metadata() else { + return; + }; + if !metadata.file_type().is_file() { + return; + } + let _ = file.write_all(line); + } + } +} + +pub(crate) struct StartupProbe { + identity: &'static ProcessIdentity, + destination: Destination, + entrypoint: EntryPoint, + transport: AtomicU8, +} + +impl StartupProbe { + fn new(destination: Destination, entrypoint: EntryPoint) -> Self { + Self { + identity: &PROCESS_IDENTITY, + destination, + entrypoint, + transport: AtomicU8::new(Transport::None.as_u8()), + } + } + + /// Read the opt-in destination once for this launch call. + pub(crate) fn from_env(entrypoint: EntryPoint) -> Option> { + let destination = env::var_os(STARTUP_TIMING_ENV)?; + let destination = if destination == "-" { + Destination::Stderr + } else { + Destination::File(PathBuf::from(destination)) + }; + Some(Arc::new(Self::new(destination, entrypoint))) + } + + pub(crate) fn set_transport(&self, transport: Transport) { + self.transport.store(transport.as_u8(), Ordering::Relaxed); + } + + pub(crate) fn record( + &self, + phase: Phase, + parent_phase: Option, + started: Instant, + duration: Duration, + status: Status, + ) { + let record = PhaseRecord::new( + &self.identity.startup_id, + process::id(), + self.entrypoint, + phase, + parent_phase, + started + .saturating_duration_since(self.identity.epoch) + .as_nanos(), + duration.as_nanos(), + status, + Transport::from_u8(self.transport.load(Ordering::Relaxed)), + ); + let Some(line) = format_json_line(&record) else { + return; + }; + let Ok(_guard) = PROCESS_WRITE_LOCK.lock() else { + return; + }; + write_record(&self.destination, &line); + } +} + +fn random_startup_id() -> String { + let pid = process::id(); + let high = RandomState::new().hash_one((pid, 0_u8)); + let low = RandomState::new().hash_one((pid, 1_u8)); + format!("{high:016x}{low:016x}") +} + +fn format_json_line(record: &PhaseRecord<'_>) -> Option> { + let mut line = serde_json::to_vec(record).ok()?; + line.push(b'\n'); + Some(line) +} + +pub(crate) fn measure_phase( + probe: Option<&StartupProbe>, + phase: Phase, + parent_phase: Option, + operation: impl FnOnce() -> Result, +) -> Result { + match probe { + None => operation(), + Some(probe) => { + let started = Instant::now(); + let result = operation(); + let status = if result.is_ok() { + Status::Ok + } else { + Status::Error + }; + probe.record(phase, parent_phase, started, started.elapsed(), status); + result + } + } +} + +pub(crate) async fn measure_phase_async( + probe: Option<&StartupProbe>, + phase: Phase, + parent_phase: Option, + operation: F, +) -> Result +where + F: Future>, +{ + match probe { + None => operation.await, + Some(probe) => { + let started = Instant::now(); + let result = operation.await; + let status = if result.is_ok() { + Status::Ok + } else { + Status::Error + }; + probe.record(phase, parent_phase, started, started.elapsed(), status); + result + } + } +} + +pub(crate) fn record_skipped( + probe: Option<&StartupProbe>, + phase: Phase, + parent_phase: Option, +) { + if let Some(probe) = probe { + probe.record( + phase, + parent_phase, + Instant::now(), + Duration::ZERO, + Status::Skipped, + ); + } +} + +struct ActivePhaseSpan<'a> { + probe: &'a StartupProbe, + phase: Phase, + parent_phase: Option, + started: Instant, +} + +pub(crate) struct PhaseSpan<'a> { + active: Option>, +} + +impl<'a> PhaseSpan<'a> { + pub(crate) fn new( + probe: Option<&'a StartupProbe>, + phase: Phase, + parent_phase: Option, + ) -> Self { + Self { + active: probe.map(|probe| ActivePhaseSpan { + probe, + phase, + parent_phase, + started: Instant::now(), + }), + } + } + + pub(crate) fn transition(&mut self, phase: Phase) { + let Some(active) = self.active.as_mut() else { + return; + }; + if active.phase == phase { + return; + } + active.probe.record( + active.phase, + active.parent_phase, + active.started, + active.started.elapsed(), + Status::Ok, + ); + active.phase = phase; + active.started = Instant::now(); + } + + pub(crate) fn finish(mut self, status: Status) { + if let Some(active) = self.active.take() { + active.probe.record( + active.phase, + active.parent_phase, + active.started, + active.started.elapsed(), + status, + ); + } + } +} + +impl Drop for PhaseSpan<'_> { + fn drop(&mut self) { + if let Some(active) = self.active.take() { + active.probe.record( + active.phase, + active.parent_phase, + active.started, + active.started.elapsed(), + Status::Error, + ); + } + } +} + +#[cfg(test)] +mod tests { + use super::*; + use serde_json::Value; + + #[test] + fn startup_phase_json_line_escapes_string_fields() { + let record = PhaseRecord::new( + "id\"with\ncontrol", + 7, + EntryPoint::Unknown, + Phase::RuntimeCreate, + None, + 11, + 13, + Status::Ok, + Transport::None, + ); + let line = format_json_line(&record).expect("record serialization must succeed"); + assert_eq!(line.last(), Some(&b'\n')); + let value: Value = serde_json::from_slice(&line).expect("JSON line must parse"); + assert_eq!(value["startup_id"], "id\"with\ncontrol"); + } + + #[test] + fn startup_phase_record_contains_pinned_fields() { + let record = PhaseRecord::new( + "0123456789abcdef", + 42, + EntryPoint::PythonSync, + Phase::TransportConnect, + Some(ParentPhase::BrowserLaunch), + 100, + 25, + Status::Ok, + Transport::Websocket, + ); + let value = serde_json::to_value(record).expect("record serialization must succeed"); + assert_eq!(value["schema_version"], 1); + assert_eq!(value["entrypoint"], "python-sync"); + assert_eq!(value["phase"], "transport_connect"); + assert_eq!(value["parent_phase"], "browser_launch"); + assert_eq!(value["start_offset_ns"], 100); + assert_eq!(value["duration_ns"], 25); + assert_eq!(value["status"], "ok"); + assert_eq!(value["transport"], "websocket"); + } + + #[test] + fn disabled_probe_short_circuits_to_operation() { + let mut calls = 0; + let result: Result = measure_phase( + None, + Phase::RuntimeCreate, + Some(ParentPhase::BrowserLaunch), + || { + calls += 1; + Ok(9) + }, + ); + assert_eq!(result, Ok(9)); + assert_eq!(calls, 1); + } + + #[tokio::test] + async fn disabled_probe_short_circuits_to_async_operation() { + let mut calls = 0; + let result: Result = measure_phase_async( + None, + Phase::RuntimeCreate, + Some(ParentPhase::BrowserLaunch), + async { + calls += 1; + Ok(9) + }, + ) + .await; + assert_eq!(result, Ok(9)); + assert_eq!(calls, 1); + } + + #[test] + fn disabled_span_stays_inactive_across_boundaries() { + let mut span = PhaseSpan::new(None, Phase::LaunchPrepare, Some(ParentPhase::BrowserLaunch)); + assert!(span.active.is_none()); + span.transition(Phase::ProcessToEndpoint); + assert!(span.active.is_none()); + span.finish(Status::Ok); + } + + #[test] + fn skipped_context_record_has_zero_duration() { + let directory = tempfile::tempdir().expect("temporary directory must be created"); + let path = directory.path().join("startup-timing.jsonl"); + let probe = StartupProbe::new(Destination::File(path.clone()), EntryPoint::RustNative); + probe.set_transport(Transport::Pipe); + + record_skipped( + Some(&probe), + Phase::ContextCreate, + Some(ParentPhase::PageCreate), + ); + + let line = std::fs::read(&path).expect("timing line must be readable"); + assert_eq!(line.iter().filter(|byte| **byte == b'\n').count(), 1); + let value: Value = serde_json::from_slice(&line).expect("timing line must parse"); + assert_eq!(value["phase"], "context_create"); + assert_eq!(value["duration_ns"], 0); + assert_eq!(value["status"], "skipped"); + assert_eq!(value["parent_phase"], "page_create"); + assert_eq!(value["transport"], "pipe"); + } +} diff --git a/tests/test_rustwright_sync_api.py b/tests/test_rustwright_sync_api.py index bf9a941..2799f79 100644 --- a/tests/test_rustwright_sync_api.py +++ b/tests/test_rustwright_sync_api.py @@ -205,6 +205,19 @@ def subprocess_env(**overrides: str) -> dict[str, str]: return env +def _run_rustwright_subprocess(source: str, marker: str) -> None: + result = subprocess.run( + [sys.executable, "-c", source], + env=subprocess_env(), + text=True, + stdout=subprocess.PIPE, + stderr=subprocess.STDOUT, + timeout=10, + ) + assert result.returncode == 0, result.stdout + assert marker in result.stdout, result.stdout + + def require_reference_module(module_name: str, reason: str) -> None: probe = subprocess.run( [ @@ -33559,6 +33572,105 @@ def test_unsupported_browser_types_raise(playwright): playwright.firefox.launch() +def test_async_api_basic_flow_defers_async_import_for_sync_manager_lifecycle(): + _run_rustwright_subprocess( + inspect.cleandoc( + """ + import sys + + import rustwright + + assert "rustwright.async_api" not in sys.modules + assert "asyncio" not in sys.modules + playwright = rustwright.sync_playwright().start() + playwright.stop() + assert "rustwright.async_api" not in sys.modules + assert "asyncio" not in sys.modules + print("cold-sync-ok") + """ + ), + "cold-sync-ok", + ) + + +def test_async_api_basic_flow_lazy_attribute_loads_and_caches_callable(): + _run_rustwright_subprocess( + inspect.cleandoc( + """ + import sys + + import rustwright + + first = rustwright.async_playwright + second = rustwright.async_playwright + assert callable(first) + assert first is second + assert rustwright.__dict__["async_playwright"] is first + assert "rustwright.async_api" in sys.modules + print("lazy-attribute-ok") + """ + ), + "lazy-attribute-ok", + ) + + +def test_async_api_basic_flow_import_forms_remain_supported(): + _run_rustwright_subprocess( + inspect.cleandoc( + """ + import sys + + from rustwright import async_playwright + + assert callable(async_playwright) + assert "rustwright.async_api" in sys.modules + print("root-import-ok") + """ + ), + "root-import-ok", + ) + _run_rustwright_subprocess( + inspect.cleandoc( + """ + import rustwright.async_api + from rustwright.async_api import async_playwright + + assert callable(rustwright.async_api.async_playwright) + assert async_playwright is rustwright.async_api.async_playwright + print("direct-import-ok") + """ + ), + "direct-import-ok", + ) + _run_rustwright_subprocess( + inspect.cleandoc( + """ + namespace = {} + exec("from rustwright import *", namespace) + assert callable(namespace["async_playwright"]) + print("star-import-ok") + """ + ), + "star-import-ok", + ) + + +def test_async_api_basic_flow_root_directory_and_public_exports_are_stable(): + assert "async_playwright" in dir(rustwright) + assert "async_playwright" in rustwright.__all__ + # __all__ may legitimately grow on main; defend the durable contract + # instead of a frozen snapshot: no duplicates, and every advertised + # export resolves (async_playwright through the lazy module __getattr__). + assert len(rustwright.__all__) == len(set(rustwright.__all__)) + for public_name in rustwright.__all__: + assert getattr(rustwright, public_name) is not None + assert set(rustwright.__all__) <= set(dir(rustwright)) + missing_name = "_missing_public_name_for_test" + with pytest.raises(AttributeError) as exc_info: + getattr(rustwright, missing_name) + assert str(exc_info.value) == f"module 'rustwright' has no attribute {missing_name!r}" + + def test_async_api_basic_flow(): async def run() -> None: from playwright.async_api import async_playwright diff --git a/tools/check_startup_latency.py b/tools/check_startup_latency.py new file mode 100755 index 0000000..cd307a4 --- /dev/null +++ b/tools/check_startup_latency.py @@ -0,0 +1,1108 @@ +#!/usr/bin/env python3 +"""Validate a cold-start latency matrix as Testbox evidence.""" + +from __future__ import annotations + +import argparse +import datetime as dt +import json +import math +import re +from pathlib import Path +from typing import Any + +from startup_latency_stats import BOOTSTRAP_PROTOCOL, summarize_paired_ms + + +ROOT = Path(__file__).resolve().parents[1] +REPORTS_DIR = ROOT / ".benchmark-data" / "reports" +MEASURED_PHASES = ( + "python_import", + "manager_factory", + "api_startup", + "chromium_facade_first_access", + "browser_launch", + "first_page", + "first_page_probe", + "close", +) +SUMMARY_PHASES = (*MEASURED_PHASES, "cold_process_to_first_page") +MATCHED_ENVIRONMENT_FIELDS = ( + "image_digest", + "browser_executable", + "browser_version", + "python_version", + "rust_version", + "memory_limit", + "memory_swap_limit", + "cpu_quota", + "cpu", + "transport", + "launcher_sha256", + "environment_id", +) +SHA_PATTERN = re.compile(r"^[0-9a-f]{40,64}$") +DIGEST_PATTERN = re.compile(r"^[0-9a-f]{64}$") +MEMORY_LIMITS_GIB = { + "1g": 1, + "2g": 2, + "3g": 3, + "4g": 4, + "5g": 5, + "6g": 6, + "7g": 7, + "8g": 8, + "1024m": 1, + "2048m": 2, + "3072m": 3, + "4096m": 4, + "5120m": 5, + "6144m": 6, + "7168m": 7, + "8192m": 8, +} + + +class Validation: + def __init__(self) -> None: + self.violations: list[dict[str, str]] = [] + + def reject(self, code: str, message: str, location: str) -> None: + self.violations.append({"code": code, "message": message, "location": location}) + + def require(self, condition: bool, code: str, message: str, location: str) -> bool: + if not condition: + self.reject(code, message, location) + return False + return True + + +def utc_now() -> str: + return dt.datetime.now(dt.timezone.utc).isoformat() + + +def is_number(value: Any) -> bool: + return ( + isinstance(value, (int, float)) + and not isinstance(value, bool) + and math.isfinite(float(value)) + ) + + +def get_path(value: Any, *path: str) -> Any: + current = value + for name in path: + if not isinstance(current, dict) or name not in current: + return None + current = current[name] + return current + + +def contains_p95(value: Any, path: str = "artifact") -> list[str]: + matches: list[str] = [] + if isinstance(value, dict): + for key, child in value.items(): + child_path = f"{path}.{key}" + if "p95" in str(key).lower(): + matches.append(child_path) + matches.extend(contains_p95(child, child_path)) + elif isinstance(value, list): + for index, child in enumerate(value): + matches.extend(contains_p95(child, f"{path}[{index}]")) + return matches + + +def validate_source(args: argparse.Namespace, validation: Validation) -> None: + validation.require( + args.source == "testbox", + "source_not_testbox", + "--source must explicitly assert testbox", + "--source", + ) + for name in ("runner", "run_url"): + value = getattr(args, name) + validation.require( + isinstance(value, str) and bool(value.strip()), + "missing_attestation", + f"--{name.replace('_', '-')} must be nonempty", + f"--{name.replace('_', '-')}", + ) + + +def validate_provenance(artifact: dict[str, Any], validation: Validation) -> None: + provenance = artifact.get("provenance") + if not validation.require( + isinstance(provenance, dict), + "missing_provenance", + "provenance must be an object", + "artifact.provenance", + ): + return + + for name in ("before_sha", "after_sha"): + value = provenance.get(name) + validation.require( + isinstance(value, str) and bool(SHA_PATTERN.fullmatch(value)), + "missing_provenance", + f"{name} must be a full Git SHA", + f"artifact.provenance.{name}", + ) + + for name in ("base_image_digest", "image_digest"): + value = provenance.get(name) + validation.require( + isinstance(value, str) + and value.startswith("sha256:") + and bool(DIGEST_PATTERN.fullmatch(value.removeprefix("sha256:"))), + "missing_provenance", + f"{name} must be a sha256 image identity", + f"artifact.provenance.{name}", + ) + + wheels = provenance.get("wheels") + for revision in ("before", "after"): + records = wheels.get(revision) if isinstance(wheels, dict) else None + valid = isinstance(records, list) and len(records) == 1 + if valid: + record = records[0] + valid = ( + isinstance(record, dict) + and isinstance(record.get("filename"), str) + and bool(record["filename"]) + and isinstance(record.get("sha256"), str) + and bool(DIGEST_PATTERN.fullmatch(record["sha256"])) + ) + validation.require( + valid, + "missing_provenance", + f"{revision} wheel filename and sha256 are required", + f"artifact.provenance.wheels.{revision}", + ) + + required_nonempty = ( + ("measurement_image",), + ("metadata_container_name",), + ("browser", "executable"), + ("browser", "version"), + ("python_version",), + ("rust_version",), + ("exact_command",), + ("start_time",), + ("fixture_hash",), + ("launcher_sha256",), + ("transport",), + ) + for path in required_nonempty: + value = get_path(provenance, *path) + validation.require( + isinstance(value, str) and bool(value.strip()), + "missing_provenance", + f"{'.'.join(path)} is required", + f"artifact.provenance.{'.'.join(path)}", + ) + metadata_container_name = provenance.get("metadata_container_name") + metadata_command = provenance.get("metadata_command") + metadata_command_valid = ( + isinstance(metadata_command, list) + and len(metadata_command) >= 4 + and metadata_command[:2] == ["docker", "run"] + and all(isinstance(value, str) for value in metadata_command) + ) + validation.require( + metadata_command_valid, + "missing_provenance", + "metadata_command must record the full docker run argv list", + "artifact.provenance.metadata_command", + ) + validation.require( + metadata_command_valid + and isinstance(metadata_container_name, str) + and any( + value == "--name" + and metadata_command[position + 1] == metadata_container_name + for position, value in enumerate(metadata_command[:-1]) + ), + "invalid_container_isolation", + "the metadata command must assign its recorded container name", + "artifact.provenance.metadata_command", + ) + + for name in ("fixture_hash", "launcher_sha256"): + value = provenance.get(name) + validation.require( + isinstance(value, str) and bool(DIGEST_PATTERN.fullmatch(value)), + "missing_provenance", + f"{name} must be a sha256 digest", + f"artifact.provenance.{name}", + ) + validation.require( + provenance.get("fixture_hash") == provenance.get("launcher_sha256"), + "missing_provenance", + "fixture_hash must identify the recorded launcher", + "artifact.provenance.fixture_hash", + ) + + cpu = provenance.get("cpu") + validation.require( + isinstance(cpu, dict) + and bool(cpu.get("model")) + and isinstance(cpu.get("logical_count"), int) + and cpu["logical_count"] > 0, + "missing_provenance", + "CPU model and logical count are required", + "artifact.provenance.cpu", + ) + validation.require( + provenance.get("parallelism") == "sequential" and provenance.get("concurrency") == 1, + "invalid_execution_model", + "execution must be sequential with concurrency 1", + "artifact.provenance", + ) + validation.require( + provenance.get("container_isolation") == "one_fresh_container_per_sample", + "invalid_container_isolation", + "each sample must use one fresh container", + "artifact.provenance.container_isolation", + ) + + for name in ("memory_limit", "memory_swap_limit"): + value = provenance.get(name) + validation.require( + isinstance(value, str) + and value.lower() in MEMORY_LIMITS_GIB + and MEMORY_LIMITS_GIB[value.lower()] <= 8, + "invalid_resource_cap", + f"{name} must be a recognized cap of at most 8 GiB", + f"artifact.provenance.{name}", + ) + validation.require( + provenance.get("memory_limit") == provenance.get("memory_swap_limit"), + "invalid_resource_cap", + "memory and swap caps must match", + "artifact.provenance", + ) + + order = provenance.get("order_sequence") + validation.require( + isinstance(order, list) and all(value in ("before", "after") for value in order), + "missing_provenance", + "the sample order sequence is required", + "artifact.provenance.order_sequence", + ) + + +def expected_order(pair_count: int) -> list[dict[str, Any]]: + expected: list[dict[str, Any]] = [] + sequence_index = 0 + for pair_id in range(1, pair_count + 1): + revisions = ("before", "after") if pair_id % 2 else ("after", "before") + for order_position, revision in enumerate(revisions, start=1): + expected.append( + { + "sequence_index": sequence_index, + "pair_id": pair_id, + "order_position": order_position, + "revision": revision, + } + ) + sequence_index += 1 + return expected + + +def validate_balanced_order( + artifact: dict[str, Any], + pair_count: int, + validation: Validation, +) -> None: + validation.require( + artifact.get("order_scheme") == "balanced-abba", + "unbalanced_order", + "order_scheme must be balanced-abba", + "artifact.order_scheme", + ) + validation.require( + pair_count > 0 and pair_count % 2 == 0, + "unbalanced_order", + "an exact balanced-abba matrix requires a positive even pair count", + "artifact.pair_count_requested", + ) + order = artifact.get("order_sequence") + expected = expected_order(pair_count) if pair_count > 0 else [] + validation.require( + order == expected, + "unbalanced_order", + "order_sequence must alternate AB then BA for every two matched pairs", + "artifact.order_sequence", + ) + provenance_order = get_path(artifact, "provenance", "order_sequence") + expected_tokens = [item["revision"] for item in expected] + validation.require( + provenance_order == expected_tokens, + "unbalanced_order", + "provenance order_sequence must match the detailed order", + "artifact.provenance.order_sequence", + ) + + +def validate_environment_record( + environment: Any, + validation: Validation, + location: str, +) -> bool: + if not validation.require( + isinstance(environment, dict), + "mismatched_environment", + "sample environment must be an object", + location, + ): + return False + valid = True + for name in MATCHED_ENVIRONMENT_FIELDS: + value = environment.get(name) + present = value is not None and value != "" and value != {} + valid = validation.require( + present, + "mismatched_environment", + f"matched environment field {name} is required", + f"{location}.{name}", + ) and valid + return valid + + +def validate_launcher( + sample: dict[str, Any], + validation: Validation, + location: str, +) -> bool: + launcher = sample.get("launcher") + if sample.get("status") != "passed": + if isinstance(launcher, dict): + validation.require( + "phases" not in launcher and "derived" not in launcher, + "failure_used_as_timing", + "a failed sample must not contain timing phases", + f"{location}.launcher", + ) + return False + + if not validation.require( + isinstance(launcher, dict) and launcher.get("status") == "ok", + "invalid_sample", + "a passed sample requires an ok launcher record", + f"{location}.launcher", + ): + return False + valid = validation.require( + launcher.get("schema_version") == 1 + and launcher.get("entrypoint") == "python-sync" + and isinstance(launcher.get("pid"), int) + and not isinstance(launcher.get("pid"), bool) + and launcher["pid"] > 0 + and launcher.get("clock") == "perf_counter_ns", + "invalid_sample", + "launcher schema, entrypoint, pid, and monotonic clock are required", + f"{location}.launcher", + ) + phases = launcher.get("phases") + if not validation.require( + isinstance(phases, list), + "invalid_phases", + "phases must be a list", + f"{location}.launcher.phases", + ): + return False + names = [phase.get("name") if isinstance(phase, dict) else None for phase in phases] + valid = validation.require( + names == list(MEASURED_PHASES), + "non_contiguous_phases", + "phase names and order must match the cold-start contract", + f"{location}.launcher.phases", + ) and valid + previous_end: int | None = None + first_start: int | None = None + first_page_end: int | None = None + for index, phase in enumerate(phases): + phase_location = f"{location}.launcher.phases[{index}]" + if not isinstance(phase, dict): + validation.reject("invalid_phases", "phase must be an object", phase_location) + valid = False + continue + start = phase.get("start_offset_ns") + end = phase.get("end_offset_ns") + duration = phase.get("duration_ns") + numbers_valid = all( + isinstance(value, int) and not isinstance(value, bool) and value >= 0 + for value in (start, end, duration) + ) + valid = validation.require( + numbers_valid, + "invalid_phases", + "phase offsets and duration must be finite nonnegative integers", + phase_location, + ) and valid + valid = validation.require( + phase.get("status") == "ok", + "invalid_phases", + "every timing phase must have status ok", + f"{phase_location}.status", + ) and valid + if not numbers_valid: + continue + if first_start is None: + first_start = start + valid = validation.require( + start == 0, + "non_contiguous_phases", + "python_import must start at offset zero", + f"{phase_location}.start_offset_ns", + ) and valid + if previous_end is not None: + valid = validation.require( + start == previous_end, + "non_contiguous_phases", + "each phase must start at the preceding phase endpoint", + f"{phase_location}.start_offset_ns", + ) and valid + valid = validation.require( + end >= start and duration == end - start, + "invalid_phases", + "phase duration must equal end minus start", + phase_location, + ) and valid + previous_end = end + if phase.get("name") == "first_page": + first_page_end = end + + derived = get_path(launcher, "derived", "cold_process_to_first_page") + if not validation.require( + isinstance(derived, dict), + "derived_total_mismatch", + "cold_process_to_first_page is required", + f"{location}.launcher.derived.cold_process_to_first_page", + ): + return False + precision = launcher.get("clock_precision_ns", 1) + if not isinstance(precision, int) or isinstance(precision, bool) or precision < 0: + precision = 0 + validation.reject( + "derived_total_mismatch", + "clock_precision_ns must be a nonnegative integer", + f"{location}.launcher.clock_precision_ns", + ) + valid = False + derived_start = derived.get("start_offset_ns") + derived_end = derived.get("end_offset_ns") + derived_duration = derived.get("duration_ns") + derived_numbers = all( + isinstance(value, int) and not isinstance(value, bool) and value >= 0 + for value in (derived_start, derived_end, derived_duration) + ) + valid = validation.require( + derived_numbers, + "derived_total_mismatch", + "derived offsets and duration must be finite nonnegative integers", + f"{location}.launcher.derived.cold_process_to_first_page", + ) and valid + if derived_numbers and first_start is not None and first_page_end is not None: + valid = validation.require( + abs(derived_start - first_start) <= precision + and abs(derived_end - first_page_end) <= precision + and abs(derived_duration - (first_page_end - first_start)) <= precision, + "derived_total_mismatch", + "derived total must equal the python_import-to-first_page endpoints", + f"{location}.launcher.derived.cold_process_to_first_page", + ) and valid + valid = validation.require( + derived.get("status") == "ok", + "derived_total_mismatch", + "derived total must have status ok", + f"{location}.launcher.derived.cold_process_to_first_page.status", + ) and valid + valid = validation.require( + launcher.get("probe") + == {"url": "about:blank", "viewport_size": {"width": 1280, "height": 720}}, + "failed_behavior_probe", + "the blank-page URL and viewport assertion must pass", + f"{location}.launcher.probe", + ) and valid + return valid + + +def validate_samples( + artifact: dict[str, Any], + pair_count: int, + validation: Validation, +) -> tuple[list[tuple[int, dict[str, Any], dict[str, Any]]], dict[str, int]]: + samples = artifact.get("samples") + if not validation.require( + isinstance(samples, list), + "missing_samples", + "samples must be a list", + "artifact.samples", + ): + return [], {"before": 0, "after": 0} + validation.require( + len(samples) == pair_count * 2, + "missing_samples", + "the raw artifact must retain one before and one after sample for every pair", + "artifact.samples", + ) + + expected = expected_order(pair_count) if pair_count > 0 else [] + indexed: dict[tuple[int, str], tuple[dict[str, Any], bool]] = {} + passed_counts = {"before": 0, "after": 0} + top_environment = artifact.get("environment") + metadata_container_name = get_path( + artifact, + "provenance", + "metadata_container_name", + ) + container_names: set[str] = ( + {metadata_container_name} + if isinstance(metadata_container_name, str) and bool(metadata_container_name.strip()) + else set() + ) + per_sample_isolation = ( + get_path(artifact, "provenance", "container_isolation") + == "one_fresh_container_per_sample" + ) + validate_environment_record(top_environment, validation, "artifact.environment") + if isinstance(top_environment, dict): + provenance_environment = { + "image_digest": get_path(artifact, "provenance", "image_digest"), + "browser_executable": get_path(artifact, "provenance", "browser", "executable"), + "browser_version": get_path(artifact, "provenance", "browser", "version"), + "python_version": get_path(artifact, "provenance", "python_version"), + "rust_version": get_path(artifact, "provenance", "rust_version"), + "memory_limit": get_path(artifact, "provenance", "memory_limit"), + "memory_swap_limit": get_path(artifact, "provenance", "memory_swap_limit"), + "cpu_quota": get_path(artifact, "provenance", "cpu_quota"), + "cpu": get_path(artifact, "provenance", "cpu"), + "transport": get_path(artifact, "provenance", "transport"), + "launcher_sha256": get_path(artifact, "provenance", "launcher_sha256"), + } + for name, value in provenance_environment.items(): + validation.require( + top_environment.get(name) == value, + "mismatched_environment", + f"declared environment {name} must match provenance", + f"artifact.environment.{name}", + ) + + for index, sample in enumerate(samples): + location = f"artifact.samples[{index}]" + if not isinstance(sample, dict): + validation.reject("invalid_sample", "sample must be an object", location) + continue + revision = sample.get("revision") + pair_id = sample.get("pair_id") + validation.require( + revision in ("before", "after"), + "invalid_sample", + "sample revision must be before or after", + f"{location}.revision", + ) + validation.require( + isinstance(pair_id, int) and not isinstance(pair_id, bool) and 1 <= pair_id <= pair_count, + "invalid_sample", + "sample pair_id is outside the declared matrix", + f"{location}.pair_id", + ) + validation.require( + isinstance(sample.get("started_at"), str) + and bool(sample["started_at"]) + and isinstance(sample.get("command"), list) + and bool(sample["command"]) + and isinstance(sample.get("outer_process_duration_ns"), int) + and not isinstance(sample.get("outer_process_duration_ns"), bool) + and sample["outer_process_duration_ns"] >= 0, + "missing_provenance", + "each raw sample requires its command, start time, and outer duration", + location, + ) + container_name = sample.get("container_name") + container_name_valid = isinstance(container_name, str) and bool(container_name.strip()) + validation.require( + container_name_valid, + "missing_provenance", + "each raw sample requires a recorded container name", + f"{location}.container_name", + ) + if container_name_valid and per_sample_isolation: + validation.require( + container_name not in container_names, + "invalid_container_isolation", + "each fresh sample container must have a unique name", + f"{location}.container_name", + ) + container_names.add(container_name) + command = sample.get("command") + named_command = ( + isinstance(command, list) + and any( + value == "--name" + and command[position + 1] == container_name + for position, value in enumerate(command[:-1]) + ) + ) + validation.require( + named_command, + "invalid_container_isolation", + "the sample command must assign its recorded container name", + f"{location}.command", + ) + if index < len(expected): + for name in ("sequence_index", "pair_id", "order_position", "revision"): + validation.require( + sample.get(name) == expected[index][name], + "unbalanced_order", + f"sample {name} does not match the balanced order", + f"{location}.{name}", + ) + validation.require( + sample.get("status") in ("passed", "failed"), + "invalid_sample", + "sample status must be passed or failed", + f"{location}.status", + ) + if sample.get("status") == "passed": + validation.require( + sample.get("returncode") == 0, + "invalid_sample", + "a passed sample requires return code zero", + f"{location}.returncode", + ) + else: + validation.require( + sample.get("returncode") is None + or ( + isinstance(sample.get("returncode"), int) + and not isinstance(sample.get("returncode"), bool) + and sample["returncode"] != 0 + ), + "invalid_sample", + "a failed sample requires a nonzero return code or a timeout", + f"{location}.returncode", + ) + environment = sample.get("environment") + environment_valid = validate_environment_record(environment, validation, f"{location}.environment") + if environment_valid: + validation.require( + environment == top_environment, + "mismatched_environment", + "every sample must use the declared matched environment", + f"{location}.environment", + ) + timing_valid = validate_launcher(sample, validation, location) + if revision in passed_counts and sample.get("status") == "passed": + passed_counts[revision] += 1 + if isinstance(pair_id, int) and revision in ("before", "after"): + key = (pair_id, revision) + if key in indexed: + validation.reject( + "missing_samples", + "duplicate sample for pair and revision", + location, + ) + else: + indexed[key] = (sample, timing_valid and environment_valid) + + complete_pair_samples: list[tuple[int, dict[str, Any], dict[str, Any]]] = [] + for pair_id in range(1, pair_count + 1): + before = indexed.get((pair_id, "before")) + after = indexed.get((pair_id, "after")) + if before is None or after is None: + validation.reject( + "missing_samples", + "matched pair is incomplete", + f"artifact.samples[pair_id={pair_id}]", + ) + continue + validation.require( + before[0].get("environment") == after[0].get("environment"), + "mismatched_environment", + "before and after samples in a pair must have equal environments", + f"artifact.samples[pair_id={pair_id}]", + ) + if ( + before[0].get("status") == "passed" + and after[0].get("status") == "passed" + and before[1] + and after[1] + ): + complete_pair_samples.append((pair_id, before[0], after[0])) + return complete_pair_samples, passed_counts + + +def validate_reliability( + artifact: dict[str, Any], + pair_count: int, + complete_pairs: int, + passed_counts: dict[str, int], + validation: Validation, +) -> None: + reliability = get_path(artifact, "summary", "reliability") + if not validation.require( + isinstance(reliability, dict), + "missing_success_rate", + "summary reliability and success rates are required", + "artifact.summary.reliability", + ): + return + for revision in ("before", "after"): + record = reliability.get(revision) + expected_passed = passed_counts[revision] + expected = { + "attempted": pair_count, + "succeeded": expected_passed, + "failed": pair_count - expected_passed, + "success_rate": expected_passed / pair_count if pair_count else 0.0, + } + validation.require( + isinstance(record, dict) + and record.get("attempted") == expected["attempted"] + and record.get("succeeded") == expected["succeeded"] + and record.get("failed") == expected["failed"] + and is_number(record.get("success_rate")) + and abs(record["success_rate"] - expected["success_rate"]) <= 1e-12, + "missing_success_rate", + f"{revision} success counts and rate must match retained samples", + f"artifact.summary.reliability.{revision}", + ) + matched = reliability.get("matched_pairs") + expected_matched_rate = complete_pairs / pair_count if pair_count else 0.0 + validation.require( + isinstance(matched, dict) + and matched.get("attempted") == pair_count + and matched.get("complete") == complete_pairs + and matched.get("failed") == pair_count - complete_pairs + and is_number(matched.get("success_rate")) + and abs(matched["success_rate"] - expected_matched_rate) <= 1e-12, + "missing_success_rate", + "matched-pair success counts and rate must match retained samples", + "artifact.summary.reliability.matched_pairs", + ) + + +STATISTIC_REL_TOLERANCE = 1e-9 +STATISTIC_ABS_TOLERANCE = 1e-12 + + +def phase_duration_ns(sample: dict[str, Any], phase: str) -> int | None: + launcher = sample.get("launcher") + if not isinstance(launcher, dict): + return None + if phase == "cold_process_to_first_page": + record = get_path(launcher, "derived", phase) + else: + phases = launcher.get("phases") + if not isinstance(phases, list): + return None + record = next( + ( + value + for value in phases + if isinstance(value, dict) and value.get("name") == phase + ), + None, + ) + if not isinstance(record, dict): + return None + duration = record.get("duration_ns") + if not isinstance(duration, int) or isinstance(duration, bool) or duration < 0: + return None + return duration + + +def statistic_matches(actual: Any, expected: Any) -> bool: + if expected is None: + return actual is None + if isinstance(expected, bool): + return actual is expected + if isinstance(expected, int): + return isinstance(actual, int) and not isinstance(actual, bool) and actual == expected + if isinstance(expected, float): + return is_number(actual) and math.isclose( + float(actual), + expected, + rel_tol=STATISTIC_REL_TOLERANCE, + abs_tol=STATISTIC_ABS_TOLERANCE, + ) + if isinstance(expected, list): + return ( + isinstance(actual, list) + and len(actual) == len(expected) + and all( + statistic_matches(actual_value, expected_value) + for actual_value, expected_value in zip(actual, expected) + ) + ) + return actual == expected + + +def validate_summary( + artifact: dict[str, Any], + complete_pairs: list[tuple[int, dict[str, Any], dict[str, Any]]], + validation: Validation, +) -> None: + phases = get_path(artifact, "summary", "phases") + if not validation.require( + isinstance(phases, dict), + "missing_statistics", + "summary phases must be an object", + "artifact.summary.phases", + ): + return + validation.require( + set(phases) == set(SUMMARY_PHASES), + "missing_statistics", + "summary phases must contain exactly the declared phases", + "artifact.summary.phases", + ) + for phase in SUMMARY_PHASES: + location = f"artifact.summary.phases.{phase}" + record = phases.get(phase) + if not validation.require( + isinstance(record, dict), + "missing_statistics", + f"summary for {phase} is required", + location, + ): + continue + validation.require( + set(record) == {"before", "after", "paired"}, + "missing_statistics", + f"summary for {phase} must contain exactly before, after, and paired", + location, + ) + + pairs_ms: list[tuple[float, float]] = [] + for pair_id, before_sample, after_sample in complete_pairs: + before_ns = phase_duration_ns(before_sample, phase) + after_ns = phase_duration_ns(after_sample, phase) + if before_ns is None or after_ns is None: + validation.reject( + "statistics_mismatch", + "validated raw nanosecond records could not be recomputed", + f"artifact.samples[pair_id={pair_id}]", + ) + continue + pairs_ms.append( + (float(before_ns) / 1_000_000.0, float(after_ns) / 1_000_000.0) + ) + + actual_paired = record.get("paired") + bootstrap_protocol = ( + actual_paired.get("bootstrap_protocol") + if isinstance(actual_paired, dict) + else None + ) + protocol_valid = validation.require( + bootstrap_protocol == BOOTSTRAP_PROTOCOL, + "unknown_bootstrap_protocol", + f"bootstrap_protocol must be {BOOTSTRAP_PROTOCOL}", + f"{location}.paired.bootstrap_protocol", + ) + expected = summarize_paired_ms( + pairs_ms, + phase, + bootstrap_protocol=( + bootstrap_protocol if protocol_valid else BOOTSTRAP_PROTOCOL + ), + ) + for section in ("before", "after", "paired"): + actual_section = record.get(section) + expected_section = expected[section] + section_location = f"{location}.{section}" + if not validation.require( + isinstance(actual_section, dict), + "missing_statistics", + f"{section} statistics must be an object", + section_location, + ): + continue + validation.require( + set(actual_section) == set(expected_section), + "missing_statistics", + f"{section} must contain exactly the declared statistics", + section_location, + ) + for statistic, expected_value in expected_section.items(): + validation.require( + statistic_matches(actual_section.get(statistic), expected_value), + "statistics_mismatch", + f"{statistic} must match recomputation from raw nanosecond records", + f"{section_location}.{statistic}", + ) + + +def nonempty_argument(value: str) -> str: + if not value.strip(): + raise argparse.ArgumentTypeError("value must be nonempty") + return value + + +def parse_args() -> argparse.Namespace: + parser = argparse.ArgumentParser( + description="Fail closed unless a startup-latency artifact is valid Testbox evidence." + ) + parser.add_argument("artifact", help="Raw matrix JSON under .benchmark-data/results/.") + parser.add_argument( + "--source", + required=True, + choices=["testbox", "local"], + help="Operator evidence-source attestation. Only attest testbox for a real Testbox run.", + ) + parser.add_argument( + "--runner", + required=True, + type=nonempty_argument, + help="Nonempty runner label recorded in the validation report.", + ) + parser.add_argument( + "--run-url", + required=True, + type=nonempty_argument, + help="Nonempty Testbox run reference recorded in the validation report.", + ) + parser.add_argument( + "--min-pairs", + type=int, + default=20, + help="Required complete pairs; minimum 20.", + ) + parser.add_argument( + "--require-balanced-order", + action="store_true", + help="Compatibility flag. Balanced order is always required.", + ) + parser.add_argument( + "--require-matched-environment", + action="store_true", + help="Compatibility flag. Matched environments are always required.", + ) + parser.add_argument("--output", help="Validation report path under .benchmark-data/reports/.") + parser.add_argument("--json", action="store_true", help="Print the validation report as JSON.") + return parser.parse_args() + + +def report_path_for(artifact_path: Path, explicit: str | None) -> Path: + path = Path(explicit) if explicit else REPORTS_DIR / f"{artifact_path.stem}-validation.json" + if not path.is_absolute(): + path = ROOT / path + path = path.resolve() + if not path.is_relative_to(REPORTS_DIR.resolve()): + raise ValueError(f"--output must be under {REPORTS_DIR.resolve()}") + return path + + +def main() -> int: + args = parse_args() + artifact_path = Path(args.artifact) + if not artifact_path.is_absolute(): + artifact_path = ROOT / artifact_path + artifact_path = artifact_path.resolve() + validation = Validation() + try: + value = json.loads(artifact_path.read_text(encoding="utf-8")) + except (OSError, ValueError) as exc: + value = {} + validation.reject( + "invalid_artifact", + f"could not read artifact: {type(exc).__name__}: {exc}", + str(artifact_path), + ) + artifact = value if isinstance(value, dict) else {} + if not isinstance(value, dict): + validation.reject("invalid_artifact", "artifact root must be an object", "artifact") + + validate_source(args, validation) + validation.require( + artifact.get("schema_version") == 1 + and artifact.get("kind") == "rustwright_startup_latency_matrix", + "invalid_artifact", + "artifact schema and kind do not match the startup matrix", + "artifact", + ) + pair_count_value = artifact.get("pair_count_requested") + pair_count = pair_count_value if isinstance(pair_count_value, int) and not isinstance(pair_count_value, bool) else 0 + validation.require( + pair_count > 0, + "short_pair_count", + "pair_count_requested must be positive", + "artifact.pair_count_requested", + ) + validation.require( + args.min_pairs >= 20, + "short_pair_count", + "--min-pairs cannot lower the fail-closed floor below 20", + "--min-pairs", + ) + validate_provenance(artifact, validation) + validate_balanced_order(artifact, pair_count, validation) + complete_pair_samples, passed_counts = validate_samples(artifact, pair_count, validation) + complete_pairs = len(complete_pair_samples) + required_pairs = max(20, args.min_pairs) + validation.require( + complete_pairs >= required_pairs, + "short_pair_count", + f"at least {required_pairs} complete matched pairs are required; found {complete_pairs}", + "artifact.samples", + ) + validate_reliability( + artifact, + pair_count, + complete_pairs, + passed_counts, + validation, + ) + validate_summary(artifact, complete_pair_samples, validation) + for location in contains_p95(artifact): + validation.reject( + "p95_forbidden", + "p95 is forbidden for this 20-30 pair cold-start artifact", + location, + ) + + report = { + "schema_version": 1, + "kind": "rustwright_startup_latency_validation", + "created_at": utc_now(), + "status": "passed" if not validation.violations else "failed", + "artifact": str(artifact_path), + "attestation": { + "source": args.source, + "runner": args.runner, + "run_url": args.run_url, + }, + "required_complete_pairs": required_pairs, + "observed_complete_pairs": complete_pairs, + "violations": validation.violations, + } + try: + output_path = report_path_for(artifact_path, args.output) + output_path.parent.mkdir(parents=True, exist_ok=True) + output_path.write_text(json.dumps(report, indent=2, sort_keys=True) + "\n", encoding="utf-8") + report["report_path"] = str(output_path.relative_to(ROOT)) + except (OSError, ValueError) as exc: + validation.reject( + "invalid_report_path", + f"could not write validation report: {type(exc).__name__}: {exc}", + "--output", + ) + report["status"] = "failed" + report["violations"] = validation.violations + + if args.json: + print(json.dumps(report, indent=2, sort_keys=True)) + elif report["status"] == "passed": + print(f"PASS: {complete_pairs} complete matched pairs") + else: + print(f"FAIL: {len(validation.violations)} violation(s)") + for violation in validation.violations: + print(f"- {violation['code']}: {violation['message']} ({violation['location']})") + return 0 if report["status"] == "passed" else 1 + + +if __name__ == "__main__": + raise SystemExit(main()) diff --git a/tools/run_startup_latency_matrix.py b/tools/run_startup_latency_matrix.py new file mode 100755 index 0000000..33a77fc --- /dev/null +++ b/tools/run_startup_latency_matrix.py @@ -0,0 +1,872 @@ +#!/usr/bin/env python3 +"""Build and run a paired Rustwright cold-start latency matrix.""" + +from __future__ import annotations + +import argparse +import datetime as dt +import hashlib +import json +import math +import os +import shlex +import subprocess +import sys +import tarfile +import tempfile +import time +import uuid +from pathlib import Path +from typing import Any, Sequence + +from startup_latency_stats import summarize_paired_ms + + +ROOT = Path(__file__).resolve().parents[1] +LAUNCHER = ROOT / "benchmarks" / "startup_latency.py" +RESULTS_DIR = ROOT / ".benchmark-data" / "results" +REPORTS_DIR = ROOT / ".benchmark-data" / "reports" +REVISION_FETCH_TIMEOUT = 300 +REVISION_UNSHALLOW_TIMEOUT = 1_200 +REVISION_DEEPEN_STEPS = (256, 1_024, 4_096, 16_384) +PHASES = ( + "python_import", + "manager_factory", + "api_startup", + "chromium_facade_first_access", + "browser_launch", + "first_page", + "first_page_probe", + "close", + "cold_process_to_first_page", +) +MEMORY_LIMITS = { + "1g": 1, + "2g": 2, + "3g": 3, + "4g": 4, + "5g": 5, + "6g": 6, + "7g": 7, + "8g": 8, + "1024m": 1, + "2048m": 2, + "3072m": 3, + "4096m": 4, + "5120m": 5, + "6144m": 6, + "7168m": 7, + "8192m": 8, +} + + +class MatrixError(RuntimeError): + pass + + +class MatrixArgumentParser(argparse.ArgumentParser): + def error(self, message: str) -> None: + raise MatrixError(f"argument error: {message}") + + +def utc_now() -> str: + return dt.datetime.now(dt.timezone.utc).isoformat() + + +def sha256_file(path: Path) -> str: + digest = hashlib.sha256() + with path.open("rb") as handle: + for chunk in iter(lambda: handle.read(1024 * 1024), b""): + digest.update(chunk) + return digest.hexdigest() + + +def run_command( + command: Sequence[str], + *, + timeout: int, + cwd: Path = ROOT, + check: bool = True, +) -> subprocess.CompletedProcess[str]: + try: + proc = subprocess.run( + list(command), + cwd=cwd, + text=True, + capture_output=True, + timeout=timeout, + ) + except subprocess.TimeoutExpired as exc: + raise MatrixError(f"command timed out: {shlex.join(command)}") from exc + if check and proc.returncode != 0: + combined = (proc.stdout + "\n" + proc.stderr).strip().splitlines() + tail = "\n".join(combined[-40:]) + raise MatrixError( + f"command failed with exit {proc.returncode}: {shlex.join(command)}\n{tail}" + ) + return proc + + +def revision_exists(revision: str) -> bool: + proc = run_command( + ["git", "cat-file", "-e", f"{revision}^{{commit}}"], + timeout=30, + check=False, + ) + return proc.returncode == 0 + + +def attempt_revision_fetch( + command: Sequence[str], + *, + timeout: int, + failures: list[str], +) -> None: + try: + proc = run_command(command, timeout=timeout, check=False) + except MatrixError as exc: + failures.append(str(exc)) + return + if proc.returncode == 0: + failures.append(f"{shlex.join(command)} completed, but the revision is still absent") + return + combined = (proc.stdout + "\n" + proc.stderr).strip().splitlines() + tail = "\n".join(combined[-10:]) + failures.append(f"{shlex.join(command)} exited {proc.returncode}\n{tail}".rstrip()) + + +def materialize_revision(revision: str) -> None: + if revision_exists(revision): + return + + failures: list[str] = [] + attempt_revision_fetch( + ["git", "fetch", "origin", revision], + timeout=REVISION_FETCH_TIMEOUT, + failures=failures, + ) + if revision_exists(revision): + return + + attempt_revision_fetch( + ["git", "fetch", "--unshallow", "origin"], + timeout=REVISION_UNSHALLOW_TIMEOUT, + failures=failures, + ) + if revision_exists(revision): + return + + for depth in REVISION_DEEPEN_STEPS: + attempt_revision_fetch( + ["git", "fetch", f"--deepen={depth}", "origin"], + timeout=REVISION_FETCH_TIMEOUT, + failures=failures, + ) + if revision_exists(revision): + return + + detail = "\n\n".join(failures) + raise MatrixError( + f"could not resolve Git revision {revision!r} after local lookup, direct fetch, " + f"unshallow, and bounded deepening attempts\n{detail}" + ) + + +def canonical_revision(revision: str) -> str: + proc = run_command( + ["git", "rev-parse", "--verify", f"{revision}^{{commit}}"], + timeout=30, + ) + value = proc.stdout.strip().lower() + if len(value) != 40 or any(char not in "0123456789abcdef" for char in value): + raise MatrixError(f"revision did not resolve to a full SHA: {revision!r}") + return value + + +def archive_revision(revision: str, destination: Path) -> None: + archive_path = destination.with_suffix(".tar") + run_command( + ["git", "archive", "--format=tar", f"--output={archive_path}", revision], + timeout=120, + ) + destination.mkdir(parents=True, exist_ok=False) + with tarfile.open(archive_path, "r") as archive: + archive.extractall(destination, filter="data") + archive_path.unlink() + + +def docker_image_id(image: str, timeout: int) -> str: + proc = run_command( + ["docker", "image", "inspect", image, "--format", "{{.Id}}"], + timeout=timeout, + ) + value = proc.stdout.strip() + if not value.startswith("sha256:"): + raise MatrixError(f"Docker returned an invalid image ID for {image!r}: {value!r}") + return value + + +def build_dual_venv_image( + *, + base_image: str, + base_image_id: str, + before_sha: str, + after_sha: str, + build_timeout: int, + memory_limit: str, +) -> tuple[str, str]: + launcher_sha = sha256_file(LAUNCHER) + identity = hashlib.sha256( + f"{base_image_id}\0{before_sha}\0{after_sha}\0{launcher_sha}".encode() + ).hexdigest()[:20] + derived_image = f"rustwright-startup-latency:{identity}" + setup_name = f"rustwright-startup-build-{os.getpid()}-{uuid.uuid4().hex[:8]}" + + build_root = ROOT / ".benchmark-data" / "tmp" + build_root.mkdir(parents=True, exist_ok=True) + with tempfile.TemporaryDirectory(prefix="startup-build-", dir=build_root) as temporary: + temporary_path = Path(temporary) + before_source = temporary_path / "before" + after_source = temporary_path / "after" + archive_revision(before_sha, before_source) + archive_revision(after_sha, after_source) + + build_script = """ +set -eu +mkdir -p /opt/startup-wheels/before /opt/startup-wheels/after /opt/startup-harness +mv /tmp/startup_latency.py /opt/startup-harness/startup_latency.py +CARGO_TARGET_DIR=/tmp/startup-target-before python -m pip wheel --no-cache-dir --no-build-isolation --no-deps --wheel-dir /opt/startup-wheels/before /inputs/before +CARGO_TARGET_DIR=/tmp/startup-target-after python -m pip wheel --no-cache-dir --no-build-isolation --no-deps --wheel-dir /opt/startup-wheels/after /inputs/after +python -m venv /opt/startup-before +python -m venv /opt/startup-after +/opt/startup-before/bin/python -m pip install --no-index --no-deps /opt/startup-wheels/before/*.whl +/opt/startup-after/bin/python -m pip install --no-index --no-deps /opt/startup-wheels/after/*.whl +rm -rf /tmp/startup-target-before /tmp/startup-target-after +""".strip() + create_command = [ + "docker", + "create", + "--name", + setup_name, + f"--memory={memory_limit}", + f"--memory-swap={memory_limit}", + "--volume", + f"{before_source.resolve()}:/inputs/before:ro", + "--volume", + f"{after_source.resolve()}:/inputs/after:ro", + "--entrypoint", + "/bin/sh", + base_image, + "-c", + build_script, + ] + try: + run_command(create_command, timeout=120) + run_command( + ["docker", "cp", str(LAUNCHER), f"{setup_name}:/tmp/startup_latency.py"], + timeout=120, + ) + run_command(["docker", "start", "--attach", setup_name], timeout=build_timeout) + run_command(["docker", "commit", setup_name, derived_image], timeout=300) + finally: + best_effort_remove_container(setup_name) + + return derived_image, docker_image_id(derived_image, 120) + + +def parse_json_output(output: str) -> dict[str, Any] | None: + for line in reversed(output.splitlines()): + try: + value = json.loads(line) + except (TypeError, ValueError): + continue + if isinstance(value, dict): + return value + return None + + +def query_image_environment( + image: str, + memory_limit: str, + timeout: int, +) -> dict[str, Any]: + query = r''' +import glob +import hashlib +import importlib.metadata +import json +import os +import platform +import subprocess +import sys + + +def output(command): + try: + return subprocess.check_output(command, text=True, stderr=subprocess.STDOUT, timeout=30).strip() + except Exception: + return None + + +def digest(path): + value = hashlib.sha256() + with open(path, "rb") as handle: + for chunk in iter(lambda: handle.read(1024 * 1024), b""): + value.update(chunk) + return value.hexdigest() + + +def package_version(python): + return output([python, "-c", "import importlib.metadata; print(importlib.metadata.version('rustwright'))"]) + +cpu_model = None +try: + with open("/proc/cpuinfo", encoding="utf-8") as handle: + for line in handle: + if line.lower().startswith(("model name", "hardware")) and ":" in line: + cpu_model = line.split(":", 1)[1].strip() + break +except OSError: + pass +cpu_model = cpu_model or platform.processor() or platform.machine() +browser = os.environ.get("RUSTWRIGHT_CHROMIUM") or os.environ.get("CHROME") or os.environ.get("CHROMIUM") +wheels = {} +for revision in ("before", "after"): + matches = glob.glob(f"/opt/startup-wheels/{revision}/*.whl") + wheels[revision] = [ + {"filename": os.path.basename(path), "sha256": digest(path)} + for path in sorted(matches) + ] +print(json.dumps({ + "browser_executable": browser, + "browser_version": output([browser, "--version"]) if browser else None, + "python_version": platform.python_version(), + "python_build": platform.python_build(), + "rust_version": output(["rustc", "--version"]), + "platform": platform.platform(), + "machine": platform.machine(), + "cpu": {"model": cpu_model, "logical_count": os.cpu_count()}, + "library_versions": { + "before": package_version("/opt/startup-before/bin/python"), + "after": package_version("/opt/startup-after/bin/python"), + }, + "wheels": wheels, +}, sort_keys=True)) +'''.strip() + metadata_container_name = ( + f"rustwright-startup-metadata-{os.getpid()}-{uuid.uuid4().hex[:8]}" + ) + command = [ + "docker", + "run", + "--name", + metadata_container_name, + f"--memory={memory_limit}", + f"--memory-swap={memory_limit}", + "--entrypoint", + "/usr/local/bin/python", + image, + "-c", + query, + ] + try: + proc = run_command(command, timeout=timeout) + finally: + best_effort_remove_container(metadata_container_name) + value = parse_json_output(proc.stdout) + if value is None: + raise MatrixError("could not parse environment metadata from the measurement image") + required = ("browser_executable", "browser_version", "python_version", "rust_version", "cpu") + missing = [name for name in required if not value.get(name)] + if missing: + raise MatrixError(f"measurement image metadata is missing: {', '.join(missing)}") + for revision in ("before", "after"): + wheels = value.get("wheels", {}).get(revision) + if not isinstance(wheels, list) or len(wheels) != 1: + raise MatrixError(f"expected one {revision} wheel in the measurement image") + value["metadata_container_name"] = metadata_container_name + value["metadata_command"] = command + return value + + +def balanced_abba_plan(pair_count: int) -> list[dict[str, Any]]: + if pair_count < 1: + raise MatrixError("--pairs must be positive") + if pair_count % 2: + raise MatrixError("--pairs must be even for exact balanced-abba order") + plan: list[dict[str, Any]] = [] + sequence_index = 0 + for pair_id in range(1, pair_count + 1): + order = ("before", "after") if pair_id % 2 else ("after", "before") + for order_position, revision in enumerate(order, start=1): + plan.append( + { + "sequence_index": sequence_index, + "pair_id": pair_id, + "order_position": order_position, + "revision": revision, + } + ) + sequence_index += 1 + return plan + + +def sample_command( + *, + image: str, + memory_limit: str, + revision: str, + core_path: str, + browser_version: str, + transport: str, + container_name: str, + use_existing_container: bool, +) -> list[str]: + python = f"/opt/startup-{revision}/bin/python" + launcher = "/opt/startup-harness/startup_latency.py" + environment_args = [ + "--env", + f"RUSTWRIGHT_STARTUP_TIMING_FILE={core_path}", + "--env", + f"RUSTWRIGHT_BROWSER_VERSION={browser_version}", + "--env", + f"RUSTWRIGHT_CDP_TRANSPORT={transport}", + ] + if use_existing_container: + return [ + "docker", + "exec", + *environment_args, + container_name, + python, + launcher, + ] + return [ + "docker", + "run", + "--name", + container_name, + f"--memory={memory_limit}", + f"--memory-swap={memory_limit}", + *environment_args, + "--entrypoint", + python, + image, + launcher, + ] + + +def run_sample( + *, + item: dict[str, Any], + image: str, + memory_limit: str, + browser_version: str, + transport: str, + environment: dict[str, Any], + timeout: int, + block_container_name: str | None, +) -> dict[str, Any]: + core_path = f"/tmp/rustwright-startup-{item['pair_id']}-{item['sequence_index']}.jsonl" + use_existing_container = block_container_name is not None + container_name = block_container_name or ( + f"rustwright-startup-sample-{item['sequence_index']}-{os.getpid()}-" + f"{uuid.uuid4().hex[:8]}" + ) + command = sample_command( + image=image, + memory_limit=memory_limit, + revision=item["revision"], + core_path=core_path, + browser_version=browser_version, + transport=transport, + container_name=container_name, + use_existing_container=use_existing_container, + ) + started_at = utc_now() + outer_start_ns = time.perf_counter_ns() + try: + try: + proc = subprocess.run( + command, + cwd=ROOT, + text=True, + capture_output=True, + timeout=timeout, + ) + returncode: int | None = proc.returncode + stdout = proc.stdout + stderr = proc.stderr + timeout_error = False + except subprocess.TimeoutExpired as exc: + returncode = None + stdout = exc.stdout if isinstance(exc.stdout, str) else "" + stderr = exc.stderr if isinstance(exc.stderr, str) else "" + timeout_error = True + outer_duration_ns = time.perf_counter_ns() - outer_start_ns + finally: + if not use_existing_container: + best_effort_remove_container(container_name) + launcher = parse_json_output(stdout) + passed = ( + not timeout_error + and returncode == 0 + and isinstance(launcher, dict) + and launcher.get("status") == "ok" + ) + sample: dict[str, Any] = { + **item, + "status": "passed" if passed else "failed", + "started_at": started_at, + "outer_process_duration_ns": outer_duration_ns, + "returncode": returncode, + "command": command, + "container_name": container_name, + "environment": environment, + "launcher": launcher, + } + if not passed: + sample["failure"] = { + "timed_out": timeout_error, + "stderr_tail": "\n".join(stderr.splitlines()[-40:]), + "stdout_tail": "\n".join(stdout.splitlines()[-40:]), + } + return sample + + +def start_revision_block_containers( + image: str, + memory_limit: str, +) -> dict[str, str]: + names: dict[str, str] = {} + try: + for revision in ("before", "after"): + name = f"rustwright-startup-{revision}-{os.getpid()}-{uuid.uuid4().hex[:8]}" + command = [ + "docker", + "run", + "--detach", + "--name", + name, + f"--memory={memory_limit}", + f"--memory-swap={memory_limit}", + "--entrypoint", + "/bin/sh", + image, + "-c", + "while true; do sleep 3600; done", + ] + names[revision] = name + run_command(command, timeout=120) + except BaseException: + stop_revision_block_containers(names) + raise + return names + + +def best_effort_remove_container(name: str) -> None: + try: + run_command(["docker", "rm", "-f", name], timeout=120, check=False) + except Exception: + pass + + +def stop_revision_block_containers(names: dict[str, str]) -> None: + for name in names.values(): + best_effort_remove_container(name) + + +def phase_duration_ms(sample: dict[str, Any], phase: str) -> float | None: + if sample.get("status") != "passed": + return None + launcher = sample.get("launcher") + if not isinstance(launcher, dict): + return None + if phase == "cold_process_to_first_page": + record = launcher.get("derived", {}).get(phase) + else: + records = launcher.get("phases") + if not isinstance(records, list): + return None + record = next( + (value for value in records if isinstance(value, dict) and value.get("name") == phase), + None, + ) + if not isinstance(record, dict): + return None + duration_ns = record.get("duration_ns") + if not isinstance(duration_ns, (int, float)) or isinstance(duration_ns, bool): + return None + if not math.isfinite(float(duration_ns)) or duration_ns < 0: + return None + return float(duration_ns) / 1_000_000.0 + + +def summarize(samples: list[dict[str, Any]], pair_count: int) -> dict[str, Any]: + by_pair: dict[int, dict[str, dict[str, Any]]] = {} + for sample in samples: + by_pair.setdefault(sample["pair_id"], {})[sample["revision"]] = sample + + phase_summary: dict[str, Any] = {} + complete_pair_ids = [ + pair_id + for pair_id, pair in sorted(by_pair.items()) + if pair.get("before", {}).get("status") == "passed" + and pair.get("after", {}).get("status") == "passed" + ] + for phase in PHASES: + pairs_ms: list[tuple[float, float]] = [] + for pair_id in complete_pair_ids: + pair = by_pair[pair_id] + before = phase_duration_ms(pair["before"], phase) + after = phase_duration_ms(pair["after"], phase) + if before is not None and after is not None: + pairs_ms.append((before, after)) + phase_summary[phase] = summarize_paired_ms(pairs_ms, phase) + + reliability: dict[str, Any] = {} + for revision in ("before", "after"): + selected = [sample for sample in samples if sample["revision"] == revision] + succeeded = sum(sample.get("status") == "passed" for sample in selected) + attempted = len(selected) + reliability[revision] = { + "attempted": attempted, + "succeeded": succeeded, + "failed": attempted - succeeded, + "success_rate": succeeded / attempted if attempted else 0.0, + } + reliability["matched_pairs"] = { + "attempted": pair_count, + "complete": len(complete_pair_ids), + "failed": pair_count - len(complete_pair_ids), + "success_rate": len(complete_pair_ids) / pair_count if pair_count else 0.0, + } + return {"phases": phase_summary, "reliability": reliability} + + +def ensure_under(path: Path, directory: Path, label: str) -> Path: + resolved = path if path.is_absolute() else ROOT / path + resolved = resolved.resolve() + directory = directory.resolve() + if not resolved.is_relative_to(directory): + raise MatrixError(f"{label} must be under {directory}") + return resolved + + +def default_output_path() -> Path: + timestamp = dt.datetime.now(dt.timezone.utc).strftime("%Y%m%dT%H%M%SZ") + return RESULTS_DIR / f"startup-latency-{timestamp}.json" + + +def write_json(path: Path, value: dict[str, Any]) -> None: + path.parent.mkdir(parents=True, exist_ok=True) + path.write_text(json.dumps(value, indent=2, sort_keys=True) + "\n", encoding="utf-8") + + +def parse_args() -> argparse.Namespace: + parser = MatrixArgumentParser( + description=( + "Build two Rustwright revisions in one Docker image and run a paired cold-start matrix." + ), + epilog=( + "The default per-sample-container mode gives the strongest isolation: every sample gets " + "a fresh capped container, Python process, and browser. Use revision-block-container only " + "when the image cannot support per-sample containers. That fallback still starts a fresh " + "Python process and browser for each sample, but container filesystem and kernel state " + "persist for one before or after revision block. The checker rejects fallback artifacts " + "as publication evidence." + ), + ) + parser.add_argument("--before-rev", required=True, help="Baseline Git revision.") + parser.add_argument("--after-rev", required=True, help="Candidate Git revision.") + parser.add_argument("--pairs", type=int, default=30, help="Matched pair count. Must be even; default 30.") + parser.add_argument("--order", choices=["balanced-abba"], default="balanced-abba") + parser.add_argument( + "--output", + help="Raw JSON path under .benchmark-data/results/. A timestamped path is the default.", + ) + parser.add_argument( + "--image", + default=os.environ.get("RUSTWRIGHT_DOCKER_IMAGE", "rustwright-verify-testbox"), + help="Prepared base image. Defaults to RUSTWRIGHT_DOCKER_IMAGE or rustwright-verify-testbox.", + ) + parser.add_argument( + "--isolation", + choices=["per-sample-container", "revision-block-container"], + default="per-sample-container", + help="Container isolation mode. Use revision-block-container only as a diagnostic fallback.", + ) + parser.add_argument( + "--memory-limit", + default=os.environ.get("TEST_DOCKER_MEMORY_LIMIT", "8g").lower(), + help="Docker memory and swap cap. Must be 8 GiB or less; default 8g.", + ) + parser.add_argument("--sample-timeout", type=int, default=180) + parser.add_argument("--build-timeout", type=int, default=3600) + parser.add_argument("--json", action="store_true", help="Print the summary report as JSON.") + return parser.parse_args() + + +def main() -> int: + args = parse_args() + if args.memory_limit not in MEMORY_LIMITS or MEMORY_LIMITS[args.memory_limit] > 8: + raise MatrixError("--memory-limit must be 8 GiB or less in whole-GiB units") + if args.sample_timeout <= 0 or args.build_timeout <= 0: + raise MatrixError("timeouts must be positive") + transport = os.environ.get("RUSTWRIGHT_CDP_TRANSPORT") or "websocket" + if transport not in {"websocket", "pipe"}: + raise MatrixError("RUSTWRIGHT_CDP_TRANSPORT must be websocket or pipe") + + started_at = utc_now() + exact_command = shlex.join([sys.executable, *sys.argv]) + materialize_revision(args.before_rev) + materialize_revision(args.after_rev) + before_sha = canonical_revision(args.before_rev) + after_sha = canonical_revision(args.after_rev) + plan = balanced_abba_plan(args.pairs) + base_image_id = docker_image_id(args.image, 120) + derived_image, image_digest = build_dual_venv_image( + base_image=args.image, + base_image_id=base_image_id, + before_sha=before_sha, + memory_limit=args.memory_limit, + after_sha=after_sha, + build_timeout=args.build_timeout, + ) + image_metadata = query_image_environment(derived_image, args.memory_limit, args.sample_timeout) + launcher_sha = sha256_file(LAUNCHER) + environment = { + "image_digest": image_digest, + "browser_executable": image_metadata["browser_executable"], + "browser_version": image_metadata["browser_version"], + "python_version": image_metadata["python_version"], + "rust_version": image_metadata["rust_version"], + "memory_limit": args.memory_limit, + "memory_swap_limit": args.memory_limit, + "cpu_quota": "unbounded_by_runner", + "cpu": image_metadata["cpu"], + "transport": transport, + "launcher_sha256": launcher_sha, + } + environment_id = hashlib.sha256( + json.dumps(environment, sort_keys=True, separators=(",", ":")).encode() + ).hexdigest() + environment["environment_id"] = environment_id + + samples: list[dict[str, Any]] = [] + block_containers: dict[str, str] = {} + try: + if args.isolation == "revision-block-container": + block_containers = start_revision_block_containers(derived_image, args.memory_limit) + for item in plan: + samples.append( + run_sample( + item=item, + image=derived_image, + memory_limit=args.memory_limit, + browser_version=image_metadata["browser_version"], + transport=transport, + environment=environment, + timeout=args.sample_timeout, + block_container_name=block_containers.get(item["revision"]), + ) + ) + finally: + stop_revision_block_containers(block_containers) + + order_sequence = [item["revision"] for item in plan] + provenance = { + "before_sha": before_sha, + "after_sha": after_sha, + "base_image": args.image, + "base_image_digest": base_image_id, + "measurement_image": derived_image, + "image_digest": image_digest, + "wheels": image_metadata["wheels"], + "metadata_container_name": image_metadata["metadata_container_name"], + "metadata_command": image_metadata["metadata_command"], + "browser": { + "executable": image_metadata["browser_executable"], + "version": image_metadata["browser_version"], + }, + "python_version": image_metadata["python_version"], + "python_build": image_metadata["python_build"], + "rust_version": image_metadata["rust_version"], + "library_versions": image_metadata["library_versions"], + "memory_limit": args.memory_limit, + "memory_swap_limit": args.memory_limit, + "cpu_quota": "unbounded_by_runner", + "cpu": image_metadata["cpu"], + "platform": image_metadata["platform"], + "machine": image_metadata["machine"], + "exact_command": exact_command, + "start_time": started_at, + "order_sequence": order_sequence, + "parallelism": "sequential", + "concurrency": 1, + "container_isolation": ( + "one_fresh_container_per_sample" + if args.isolation == "per-sample-container" + else "one_persistent_container_per_revision_block" + ), + "fixture_hash": launcher_sha, + "launcher_sha256": launcher_sha, + "transport": transport, + } + summary = summarize(samples, args.pairs) + output_path = ensure_under( + Path(args.output) if args.output else default_output_path(), + RESULTS_DIR, + "--output", + ) + report_path = ensure_under( + REPORTS_DIR / f"{output_path.stem}-summary.json", + REPORTS_DIR, + "summary output", + ) + artifact = { + "schema_version": 1, + "kind": "rustwright_startup_latency_matrix", + "created_at": utc_now(), + "pair_count_requested": args.pairs, + "order_scheme": args.order, + "isolation_mode": args.isolation, + "provenance": provenance, + "environment": environment, + "order_sequence": plan, + "samples": samples, + "summary": summary, + "result_path": str(output_path.relative_to(ROOT)), + "report_path": str(report_path.relative_to(ROOT)), + } + report = { + "schema_version": 1, + "kind": "rustwright_startup_latency_summary", + "created_at": artifact["created_at"], + "result_path": artifact["result_path"], + "provenance": provenance, + "summary": summary, + } + write_json(output_path, artifact) + write_json(report_path, report) + + if args.json: + print(json.dumps(report, indent=2, sort_keys=True)) + else: + reliability = summary["reliability"]["matched_pairs"] + print(f"Raw result: {artifact['result_path']}") + print(f"Summary: {artifact['report_path']}") + print( + f"Complete pairs: {reliability['complete']}/{reliability['attempted']} " + f"({reliability['success_rate']:.1%})" + ) + failures = [sample for sample in samples if sample.get("status") != "passed"] + return 3 if failures else 0 + + +if __name__ == "__main__": + try: + raise SystemExit(main()) + except MatrixError as exc: + print(json.dumps({"status": "error", "error_type": type(exc).__name__, "error_message": str(exc)})) + raise SystemExit(1) diff --git a/tools/startup_latency_stats.py b/tools/startup_latency_stats.py new file mode 100644 index 0000000..8cf7e8f --- /dev/null +++ b/tools/startup_latency_stats.py @@ -0,0 +1,112 @@ +"""Shared statistics for the cold-start latency matrix and checker.""" + +from __future__ import annotations + +import random +import statistics +from collections.abc import Sequence +from typing import Any + + +BOOTSTRAP_RESAMPLES = 10_000 +BOOTSTRAP_PROTOCOL = "paired-delta-random-v1" +_BOOTSTRAP_SEED_NAMESPACE = "startup-latency" + + +def percentile(values: Sequence[float], probability: float) -> float: + """Return a linear-interpolated percentile for a nonempty sequence.""" + if not values: + raise ValueError("percentile requires at least one value") + if not 0.0 <= probability <= 1.0: + raise ValueError("percentile probability must be between zero and one") + ordered = sorted(values) + if len(ordered) == 1: + return ordered[0] + position = (len(ordered) - 1) * probability + lower = int(position) + upper = min(lower + 1, len(ordered) - 1) + fraction = position - lower + return ordered[lower] + (ordered[upper] - ordered[lower]) * fraction + + +def distribution(values: Sequence[float]) -> dict[str, Any]: + """Return the published distribution statistics for millisecond values.""" + if not values: + return { + "count": 0, + "median_ms": None, + "p25_ms": None, + "p75_ms": None, + "mad_ms": None, + } + median = statistics.median(values) + return { + "count": len(values), + "median_ms": median, + "p25_ms": percentile(values, 0.25), + "p75_ms": percentile(values, 0.75), + "mad_ms": statistics.median(abs(value - median) for value in values), + } + + +def bootstrap_seed(phase: str, pair_count: int) -> str: + """Return the declared deterministic bootstrap seed for one phase.""" + return f"{_BOOTSTRAP_SEED_NAMESPACE}:{phase}:{pair_count}" + + +def bootstrap_median_ci( + values: Sequence[float], + phase: str, + protocol: str = BOOTSTRAP_PROTOCOL, +) -> list[float] | None: + """Return the seeded 95% bootstrap interval for the median.""" + if protocol != BOOTSTRAP_PROTOCOL: + raise ValueError(f"unknown bootstrap protocol: {protocol}") + if not values: + return None + generator = random.Random(bootstrap_seed(phase, len(values))) + estimates: list[float] = [] + size = len(values) + # random() has a stable cross-version stream; randrange/_randbelow does not. + for _ in range(BOOTSTRAP_RESAMPLES): + estimates.append( + statistics.median( + values[min(int(generator.random() * size), size - 1)] + for _ in range(size) + ) + ) + return [percentile(estimates, 0.025), percentile(estimates, 0.975)] + + +def summarize_paired_ms( + pairs: Sequence[tuple[float, float]], + phase: str, + *, + bootstrap_protocol: str = BOOTSTRAP_PROTOCOL, +) -> dict[str, Any]: + """Return all published statistics for paired before/after milliseconds.""" + before_values = [before for before, _after in pairs] + after_values = [after for _before, after in pairs] + deltas = [after - before for before, after in pairs] + percentages = [ + ((after - before) / before) * 100.0 + for before, after in pairs + if before > 0 + ] + return { + "before": distribution(before_values), + "after": distribution(after_values), + "paired": { + "complete_pairs": len(pairs), + "median_delta_ms": statistics.median(deltas) if deltas else None, + "median_delta_percent": statistics.median(percentages) if percentages else None, + "bootstrap_95_ci_ms": bootstrap_median_ci( + deltas, + phase, + bootstrap_protocol, + ), + "bootstrap_resamples": BOOTSTRAP_RESAMPLES, + "bootstrap_seed": bootstrap_seed(phase, len(pairs)), + "bootstrap_protocol": bootstrap_protocol, + }, + }