diff --git a/packages/selenium-devtools-py/scripts/gen_contract.py b/packages/selenium-devtools-py/scripts/gen_contract.py index 1f5a6b85..8620d984 100644 --- a/packages/selenium-devtools-py/scripts/gen_contract.py +++ b/packages/selenium-devtools-py/scripts/gen_contract.py @@ -71,6 +71,22 @@ def _ws_scopes(routes_ts: str) -> dict[str, str]: return dict(re.findall(r"(\w+):\s*'([^']+)'", m.group(1))) +def _trace_export_scopes(trace_export_ts: str) -> dict[str, str]: + """`TRACE_EXPORT_SCOPE` — the worker↔backend frames that ask the backend to + build a trace and answer with where it landed. Python cannot run the + transforms itself, so these two strings are the whole route to a trace.""" + m = re.search( + r"export const TRACE_EXPORT_SCOPE = \{(.*?)\n\} as const", + trace_export_ts, + re.DOTALL, + ) + if not m: + raise SystemExit( + "could not find `TRACE_EXPORT_SCOPE` in shared/trace-export.ts" + ) + return dict(re.findall(r"(\w+):\s*'([^']+)'", m.group(1))) + + def _collector_path(collector_ts: str) -> str: """The route the backend serves the page-side collector from.""" m = re.search(r"export const COLLECTOR_API = \{(.*?)\} as const", collector_ts, re.DOTALL) @@ -161,6 +177,9 @@ def main() -> int: data_keys = _trace_log_keys(types_ts) runner_ids = _test_runner_ids(types_ts) collector_path = _collector_path((shared / "src" / "collector.ts").read_text()) + trace_export = _trace_export_scopes( + (shared / "src" / "trace-export.ts").read_text() + ) routes_ts = (shared / "src" / "routes.ts").read_text() control = _ws_scopes(routes_ts) worker_query = _worker_query(routes_ts) @@ -209,6 +228,14 @@ def main() -> int: "three to report into the dashboard that launched it." ) + missing_export = [k for k in ("request", "result") if k not in trace_export] + if missing_export: + raise SystemExit( + f"contract drift: TRACE_EXPORT_SCOPE key(s) {missing_export} no " + f"longer in shared (present: {sorted(trace_export)}). Python has no " + "other route to a trace — it cannot run the transforms itself." + ) + if REQUIRED_RUNNER_ID not in runner_ids: raise SystemExit( f"contract drift: runner id {REQUIRED_RUNNER_ID!r} is no longer in " @@ -241,6 +268,9 @@ def main() -> int: f'RERUN_SLOT_TEST_ID = "{rerun_slot["testId"]}"', f'ENV_RUNNER_CWD = "{runner_cwd_env}"', "", + f'SCOPE_TRACE_EXPORT = "{trace_export["request"]}"', + f'SCOPE_TRACE_EXPORTED = "{trace_export["result"]}"', + "", f'ENV_REUSE = "{reuse_env["REUSE"]}"', f'ENV_REUSE_HOST = "{reuse_env["HOST"]}"', f'ENV_REUSE_PORT = "{reuse_env["PORT"]}"', diff --git a/packages/selenium-devtools-py/src/selenium_devtools/__init__.py b/packages/selenium-devtools-py/src/selenium_devtools/__init__.py index 308957f6..ecce0f22 100644 --- a/packages/selenium-devtools-py/src/selenium_devtools/__init__.py +++ b/packages/selenium-devtools-py/src/selenium_devtools/__init__.py @@ -18,13 +18,22 @@ import os import subprocess import sys +import threading from typing import Optional -from . import backend, instrumentation, lifecycle, rerun +from . import backend, instrumentation, lifecycle, rerun, trace_export from ._contract import CONTRACT_VERSION from .capturer import SessionCapturer -from .run_id import reset_run_id -from .constants import DEFAULT_HOST, DEFAULT_PORT, ENV_HOST, ENV_PORT, LOGGER_NAME +from .output_dir import resolve_adapter_output_dir +from .run_id import reset_run_id, resolve_run_id +from .constants import ( + DEFAULT_HOST, + DEFAULT_PORT, + ENV_HOST, + ENV_PORT, + ENV_TRACE, + LOGGER_NAME, +) from .logcapture import LogCapturer from .terminal import TerminalCapturer from .transport import WSClient @@ -66,14 +75,95 @@ def _restore_excepthook() -> None: _active: dict = { "capturer": None, "transport": None, "process": None, "url": None, "handle": None, "terminal": None, "logs": None, "excepthook": None, + "trace": False, "traced": False, } +def _trace_enabled(trace: Optional[bool]) -> bool: + """Whether this run writes a trace archive. The argument wins over the + environment so a script can opt out of an exported default.""" + if trace is not None: + return trace + return os.environ.get(ENV_TRACE, "").lower() in ("1", "true", "yes") + + +#: Serializes exports. Teardown can run on the WS reader thread while a caller +#: is mid-export on the main one, and `trace_export` holds ONE pending slot: a +#: second request replaces it, so the first caller's reply is dropped and it +#: waits out the full timeout while the backend writes the same archive twice. +#: Holding it across the wait is also what stops a MAIN-THREAD teardown closing +#: the transport out from under an export still listening on it. Off-thread +#: callers must not wait on it at all — see export_trace. +_export_lock = threading.Lock() + + +def export_trace(output_dir: Optional[str] = None) -> Optional[str]: + """Write this run's trace archive now. No-op unless trace mode is on. + + Called when the RUN finishes rather than when the process tears down. An + interactive run blocks on the dashboard window in between, and CI has no + window at all; an artifact that depends on either is an artifact that is + missing exactly when it is wanted. + + Only a SUCCESSFUL export closes the door on the teardown fallback. This is + public, so a caller may run it early, get nothing, and still expect an + archive at the end — latching on the attempt would spend that one chance on + a transport that was not ready. The cost is that an unresponsive backend is + waited on twice, once here and once at teardown; losing the artifact + outright is the worse of the two, and by then the run is already broken. + """ + # Off the main thread this never waits. Teardown can arrive on the WS + # reader thread — `_trigger_shutdown` runs it there when nobody is parked + # in wait_for_shutdown — and that thread is the ONLY one that can deliver + # the reply an in-flight export is blocked on. Waiting for that export from + # here deadlocks both until the timeout, and the shutdown's `os._exit` + # timer may kill the process first. An interrupted run losing its archive + # is the better failure; by construction it was interrupted. + on_main = threading.current_thread() is threading.main_thread() + if not _export_lock.acquire(blocking=on_main): + _log.debug("a trace export is already in flight; not starting another") + return None + try: + if not _active["trace"] or _active["traced"]: + return None + path = _export_trace( + _active["capturer"], + output_dir + if output_dir is not None + else instrumentation.resolved_output_dir(), + ) + if path is not None: + _active["traced"] = True + return path + finally: + _export_lock.release() + + +def _export_trace( + capturer: Optional[SessionCapturer], output_dir: Optional[str] +) -> Optional[str]: + """Ask the backend for this run's archive. Never raises — a run that + captured everything and failed to write a file still passed.""" + try: + session_id = ( + getattr(capturer, "session_id", None) or resolve_run_id() + ) + return trace_export.export( + _active["transport"], + output_dir=output_dir or resolve_adapter_output_dir(), + session_id=session_id, + ) + except Exception as exc: # noqa: BLE001 + _log.warning("trace export skipped (%s)", exc) + return None + + def enable( host: Optional[str] = None, port: Optional[int] = None, *, webdriver_cls: Optional[type] = None, + trace: Optional[bool] = None, ) -> Optional[SessionCapturer]: """Connect to the backend and instrument Selenium. Idempotent. @@ -85,6 +175,10 @@ def enable( if _active["capturer"] is not None: return _active["capturer"] + # Decided before anything reads it: the screencast recorder, the dashboard + # window and the teardown export all branch on this. + trace_mode = _trace_enabled(trace) + # Before the backend is launched: the directory a rerun spawns in travels # through the environment the backend process inherits. A framework plugin # has already published richer commands by now and this leaves those alone. @@ -118,7 +212,7 @@ def enable( return None capturer = SessionCapturer(transport) - instrumentation.install(capturer, webdriver_cls) + instrumentation.install(capturer, webdriver_cls, trace=trace_mode) # Plain scripts only: a framework plugin calls # `set_external_suites`, which turns this back off. instrumentation.start_assertion_tracing(capturer) @@ -132,12 +226,16 @@ def enable( url = f"http://{host}:{port}" _active.update( capturer=capturer, transport=transport, process=process, url=url, - terminal=term, logs=logs, + terminal=term, logs=logs, trace=trace_mode, traced=False, ) # Open the dashboard window and wire exit/signal + control-frame teardown so # closing the window (clientDisconnected) or ending the process both tidy up. - handle = lifecycle.open_dashboard(url) if lifecycle.auto_open_enabled() else None + handle = ( + lifecycle.open_dashboard(url) + if lifecycle.auto_open_enabled(trace=trace_mode) + else None + ) _active["handle"] = handle lifecycle.register_exit_handlers(disable, handle) return capturer @@ -156,6 +254,10 @@ def disable() -> None: # learns afterwards could still be sent. `finalize_run` therefore reads # the live exception itself. Must precede transport.close() either way. instrumentation.finalize_run(capturer) + # Read before uninstall clears it: the trace belongs beside this run's + # video, and the fallback is the cwd — the repo root, for a runner invoked + # from one. + output_dir = instrumentation.resolved_output_dir() instrumentation.uninstall() term = _active["terminal"] if term is not None: # restore stdout/stderr before tearing the transport down @@ -163,6 +265,11 @@ def disable() -> None: logs = _active["logs"] if logs is not None: # detach the logging handler + restore logger levels logs.stop() + # Fallback for a plain script that never called export_trace() itself. + # Before the transport closes: the answer comes back on this same socket. + # Through export_trace, not around it: one lock and one latch, so a public + # call still in flight is waited for rather than raced. + export_trace(output_dir) transport = _active["transport"] if transport is not None: transport.close() @@ -179,9 +286,10 @@ def disable() -> None: process.wait(timeout=5) except subprocess.TimeoutExpired: process.kill() # backend ignored SIGTERM — force it + trace_export.reset() _active.update( capturer=None, transport=None, process=None, url=None, handle=None, - terminal=None, logs=None, excepthook=None, + terminal=None, logs=None, excepthook=None, trace=False, traced=False, ) diff --git a/packages/selenium-devtools-py/src/selenium_devtools/_contract.py b/packages/selenium-devtools-py/src/selenium_devtools/_contract.py index 186baf2e..8857e937 100644 --- a/packages/selenium-devtools-py/src/selenium_devtools/_contract.py +++ b/packages/selenium-devtools-py/src/selenium_devtools/_contract.py @@ -25,6 +25,9 @@ RERUN_SLOT_TEST_ID = "{{testId}}" ENV_RUNNER_CWD = "DEVTOOLS_RUNNER_CWD" +SCOPE_TRACE_EXPORT = "traceExport" +SCOPE_TRACE_EXPORTED = "traceExported" + ENV_REUSE = "DEVTOOLS_APP_REUSE" ENV_REUSE_HOST = "DEVTOOLS_APP_HOST" ENV_REUSE_PORT = "DEVTOOLS_APP_PORT" diff --git a/packages/selenium-devtools-py/src/selenium_devtools/constants.py b/packages/selenium-devtools-py/src/selenium_devtools/constants.py index f02b518a..b3ead544 100644 --- a/packages/selenium-devtools-py/src/selenium_devtools/constants.py +++ b/packages/selenium-devtools-py/src/selenium_devtools/constants.py @@ -76,6 +76,15 @@ # floor its dependencies require; below it the process starts and then dies on # syntax it cannot parse, which surfaces here only as "exited before reporting # a port". Checked up front so the message names the real problem. +# How long to wait for the backend to answer a trace export. The archive is +# assembled from a whole run's frames, so it is not instant; but a run that +# captured everything and then hung waiting for a file is worse than one that +# reports the wait timed out. +TRACE_EXPORT_TIMEOUT_S = 60.0 + +#: Opt in to writing a trace archive at the end of the run. +ENV_TRACE = "DEVTOOLS_TRACE" + MIN_NODE_MAJOR = 18 NODE_VERSION_TIMEOUT_S = 5.0 diff --git a/packages/selenium-devtools-py/src/selenium_devtools/instrumentation.py b/packages/selenium-devtools-py/src/selenium_devtools/instrumentation.py index 98d356f9..3edea737 100644 --- a/packages/selenium-devtools-py/src/selenium_devtools/instrumentation.py +++ b/packages/selenium-devtools-py/src/selenium_devtools/instrumentation.py @@ -57,6 +57,11 @@ _skip_frames_cache: Optional[tuple] = None +class _SkipScreencast(Exception): + """Control-flow marker: no recorder for this session. Named rather than a + branch so the reason lands in one place with the other bring-up failures.""" + + def _skip_frames() -> tuple: """Call-source skip fragments: the adapter package + the REAL selenium library dir (resolved from selenium.__file__), cached. Resolving the actual @@ -241,6 +246,10 @@ def _capture_source(capturer: SessionCapturer, call_src: Optional[str]) -> None: # Set by enable()'s excepthook when an exception reaches top level. The # synthetic suite's final state reads this rather than assuming success. "run_failed": False, + # Trace mode. The archive carries per-command screenshots, not the + # screencast — `screencastFrames` does not cross the wire yet — so + # recording one writes a .webm nothing reads. Set by install(). + "trace": False, } @@ -316,6 +325,18 @@ def _attach_performance( _log.debug("could not replace the navigation row: %s", exc) +def resolved_output_dir() -> Optional[str]: + """The ``test-results`` dir this run resolved from its first test file, or + None if no command carried a user call source. Screencast videos already + write here; a trace belongs beside them rather than in the cwd, which for a + runner invoked from a repo root is the repo root. + + Cleared by ``uninstall``, so a caller tearing a run down must read it before + that rather than after. + """ + return _state.get("output_dir") + + def _begin_screencast_run(entry: Optional[dict], shot: Optional[str] = None) -> None: """Let a pushed stream start keeping frames. Idempotent, never raises. @@ -496,6 +517,10 @@ def _ensure_session_setup(driver: Any, capturer: SessionCapturer) -> Optional[di except Exception as exc: # noqa: BLE001 — capture must never break the test _log.warning("BiDi attach threw: %s", exc) try: + if _state["trace"]: + # The archive's frames are the per-command screenshots; the video is + # a live-dashboard artifact, and trace mode opens no dashboard. + raise _SkipScreencast recorder = ScreencastRecorder() recorder.start(driver) entry["screencast"] = recorder @@ -520,6 +545,8 @@ def _ensure_session_setup(driver: Any, capturer: SessionCapturer) -> Optional[di entry["screencast_push"] = push if push is None: _log.info("screencast recording started (one frame per command)") + except _SkipScreencast: + _log.info("trace mode — skipping the screencast recording") except Exception as exc: # noqa: BLE001 _log.warning("screencast start threw: %s", exc) try: @@ -695,7 +722,12 @@ def finalize_run(capturer: SessionCapturer) -> None: _send_default_suite(capturer, _live_run_state()) -def install(capturer: SessionCapturer, webdriver_cls: Optional[type] = None) -> None: +def install( + capturer: SessionCapturer, + webdriver_cls: Optional[type] = None, + *, + trace: bool = False, +) -> None: if _state["installed"]: return if webdriver_cls is None: @@ -775,6 +807,7 @@ def patched_execute(self, driver_command: str, params: Any = None): # noqa: ANN _state.update( installed=True, cls=webdriver_cls, orig=orig_execute, sessions=weakref.WeakKeyDictionary(), output_dir=None, default_suite=None, + trace=trace, ) diff --git a/packages/selenium-devtools-py/src/selenium_devtools/lifecycle.py b/packages/selenium-devtools-py/src/selenium_devtools/lifecycle.py index bfe5402f..d328a193 100644 --- a/packages/selenium-devtools-py/src/selenium_devtools/lifecycle.py +++ b/packages/selenium-devtools-py/src/selenium_devtools/lifecycle.py @@ -28,6 +28,8 @@ import threading from typing import Callable, Optional +from . import trace_export +from ._contract import SCOPE_TRACE_EXPORTED from .constants import ENV_OPEN, LOGGER_NAME # ── Local timing constants (lifecycle-specific) ────────────────────────────── @@ -143,9 +145,16 @@ def _default_opener(url: str) -> BrowserHandle: _FALSY = ("0", "false", "no", "off", "") -def auto_open_enabled() -> bool: +def auto_open_enabled(*, trace: bool = False) -> bool: """Whether the dashboard window should auto-open. Default ON, opt-out only. + Trace mode opens none. The artifact is the output there, and the run blocks + on the window until a human closes it — so a window would turn writing a + file into an interactive session. The backend still starts, because it is + what builds the archive; only the window is suppressed. That is as close to + the JS adapters' backend-free trace mode as an adapter that cannot run the + transforms itself can get. + Rule: open unless ``DEVTOOLS_OPEN`` is set to a falsy value (``0``/``false``/``no``/``off``/empty), or this process is a rerun child — the window that pressed Rerun is already up and watching the very backend @@ -157,6 +166,9 @@ def auto_open_enabled() -> bool: with no attached TTY — so the user opened the URL in their main Chrome instead. CI/headless runs disable it explicitly with ``DEVTOOLS_OPEN=0``. """ + if trace: + return False + from . import backend # local: keeps module import order free of a cycle if backend.reuse_target() is not None: @@ -245,7 +257,13 @@ def on_control(scope: str, data: dict) -> None: ``clientDisconnected`` means the user closed the dashboard window, so we tear capture down and exit the process (on a short timer, off the WS reader thread, so that thread can unwind cleanly). ``clientConnected`` is a no-op. + + ``traceExported`` answers a request the teardown is blocked on, so it is + routed rather than acted on here. """ + if scope == SCOPE_TRACE_EXPORTED: + trace_export.on_result(data) + return if scope == "clientDisconnected": _log.info("dashboard closed; shutting down") _trigger_shutdown(exit_after=True) diff --git a/packages/selenium-devtools-py/src/selenium_devtools/pytest_plugin.py b/packages/selenium-devtools-py/src/selenium_devtools/pytest_plugin.py index b98eb774..3327b774 100644 --- a/packages/selenium-devtools-py/src/selenium_devtools/pytest_plugin.py +++ b/packages/selenium-devtools-py/src/selenium_devtools/pytest_plugin.py @@ -526,6 +526,11 @@ def pytest_sessionfinish(session, exitstatus) -> None: # noqa: ANN001 capturer = devtools.get_capturer() if capturer is not None: _publish(capturer) + # Before the window wait: the archive belongs to the RUN, and everything + # below this line is about the user's session with the dashboard. Blocking + # it behind a window close would mean CI — which opens none — only ever got + # the artifact during process teardown. + devtools.export_trace() # Keep the dashboard open for inspection after the run — exit when the user # closes the window (clientDisconnected). Only when we actually opened a # window; CI (DEVTOOLS_OPEN=0) tears down immediately. diff --git a/packages/selenium-devtools-py/src/selenium_devtools/trace_export.py b/packages/selenium-devtools-py/src/selenium_devtools/trace_export.py new file mode 100644 index 00000000..1a3026d9 --- /dev/null +++ b/packages/selenium-devtools-py/src/selenium_devtools/trace_export.py @@ -0,0 +1,135 @@ +"""Ask the backend to build this run's trace archive. + +Python cannot run the transforms: they are TypeScript in ``packages/trace`` — +the zip writer, action events, HAR, mutation reattribution — and porting them +would be the second copy of ~2,000 lines, with a third waiting for the next +language. That is what #298 decided against. The backend already accumulates +every frame this run sent (it does so for Preserve & Rerun), so it assembles +the artifact and answers with where it landed. + +Two consequences worth knowing: + +* **The export is a request, not a local write.** It travels on the worker + socket and the answer comes back on the reader thread, so the caller blocks + on an event rather than a return value. +* **A run has one artifact.** The backend's accumulator is run-scoped, so the + archive covers the run rather than a session or a test. Per-test slicing is a + later ticket; it needs boundaries only the adapter knows. + +Nothing here may raise into the user's test — a run that captured everything +and failed to write an archive is still a run that passed. +""" + +from __future__ import annotations + +import logging +import threading +import uuid +from dataclasses import dataclass +from typing import Any, Optional + +from ._contract import SCOPE_TRACE_EXPORT +from .constants import LOGGER_NAME, TRACE_EXPORT_TIMEOUT_S + +_log = logging.getLogger(f"{LOGGER_NAME}.trace") + + +@dataclass +class _Pending: + """The one export in flight. A run produces a single archive, so this is a + module-level slot rather than a registry keyed by id — but the id is still + checked, so a late reply from a previous run cannot resolve this one.""" + + request_id: str + done: threading.Event + path: Optional[str] = None + error: Optional[str] = None + + +_pending: Optional[_Pending] = None +_lock = threading.Lock() + + +def on_result(data: Any) -> None: + """Handle a ``traceExported`` frame. Runs on the transport's reader thread. + + Ignores anything that does not answer the request actually in flight: the + socket outlives a single export, and resolving on id alone is what keeps a + stale reply from unblocking the wrong caller. + """ + if not isinstance(data, dict): + return + with _lock: + pending = _pending + if pending is None or data.get("requestId") != pending.request_id: + return + path = data.get("path") + error = data.get("error") + pending.path = path if isinstance(path, str) else None + pending.error = error if isinstance(error, str) else None + pending.done.set() + + +def reset() -> None: + """Forget any in-flight export. Called when a run tears down so the next + one cannot be resolved by the previous one's reply.""" + global _pending + with _lock: + _pending = None + + +def export( + transport: Any, + *, + output_dir: str, + session_id: str, + timeout: float = TRACE_EXPORT_TIMEOUT_S, +) -> Optional[str]: + """Request the archive and block until the backend answers. + + Returns the path written, or None — no backend, a refused request, a + backend that reported a failure, or one that did not answer in time. Every + one of those is logged and none of them raises: the archive is the point of + the run only when the run itself succeeded. + """ + global _pending + if transport is None or not getattr(transport, "connected", False): + _log.debug("no dashboard connection; skipping trace export") + return None + + pending = _Pending(request_id=uuid.uuid4().hex, done=threading.Event()) + with _lock: + _pending = pending + + sent = False + try: + sent = transport.send_json( + SCOPE_TRACE_EXPORT, + { + "requestId": pending.request_id, + "outputDir": output_dir, + "sessionId": session_id, + }, + ) + except Exception as exc: # noqa: BLE001 — a failed export is not a failed run + _log.warning("could not ask for a trace export: %s", exc) + if not sent: + reset() + return None + + if not pending.done.wait(timeout): + _log.warning( + "the dashboard did not answer the trace export within %.0fs; " + "the run is unaffected", + timeout, + ) + reset() + return None + + reset() + if pending.error: + _log.warning("trace export failed: %s", pending.error) + return None + if pending.path: + _log.info("trace written to %s", pending.path) + return pending.path diff --git a/packages/selenium-devtools-py/tests/test_trace_export.py b/packages/selenium-devtools-py/tests/test_trace_export.py new file mode 100644 index 00000000..68259388 --- /dev/null +++ b/packages/selenium-devtools-py/tests/test_trace_export.py @@ -0,0 +1,590 @@ +"""Asking the backend to build this run's trace. + +Python cannot run the transforms, so the archive arrives by request-and-reply +over the worker socket. What matters is less the happy path than the ways it +can go wrong: the reply lands on another thread, the socket outlives a single +export, the backend can refuse, and none of it may take the run down. +""" + +import threading +import time +import unittest +from unittest import mock + +from selenium_devtools import lifecycle, trace_export +from selenium_devtools._contract import SCOPE_TRACE_EXPORT, SCOPE_TRACE_EXPORTED + + +class FakeTransport: + """Answers the export on a separate thread, as the real reader does.""" + + def __init__( + self, *, connected=True, reply=None, sends=True, raises=False, delay=0.0 + ): + self.connected = connected + self.sent = [] + self._reply = reply + self._sends = sends + self._raises = raises + # A reply that lands before export() gets to wait would let a version + # that never waits pass — measured: removing the wait kept every test + # green, because the answering thread usually won the race. + self._delay = delay + + def send_json(self, scope, data): + if self._raises: + raise OSError("socket gone") + self.sent.append((scope, data)) + if self._reply is not None and self._sends: + answer = dict(self._reply) + answer.setdefault("requestId", data["requestId"]) + def answer_later(): + if self._delay: + time.sleep(self._delay) + trace_export.on_result(answer) + + threading.Thread(target=answer_later, daemon=True).start() + return self._sends + + def close(self): + self.connected = False + + +class TestRequestingAnExport(unittest.TestCase): + def tearDown(self): + trace_export.reset() + + def test_the_path_the_backend_reports_is_returned(self): + # Answered late on purpose: the caller has to wait for it. + tx = FakeTransport(reply={"path": "/out/trace-sess-1.zip"}, delay=0.15) + + path = trace_export.export(tx, output_dir="/out", session_id="sess-1") + + self.assertEqual(path, "/out/trace-sess-1.zip") + scope, data = tx.sent[0] + self.assertEqual(scope, SCOPE_TRACE_EXPORT) + self.assertEqual(data["outputDir"], "/out") + self.assertEqual(data["sessionId"], "sess-1") + self.assertTrue(data["requestId"]) + + def test_a_reported_failure_is_none_rather_than_a_raise(self): + tx = FakeTransport(reply={"error": "nothing captured for this run"}) + + self.assertIsNone( + trace_export.export(tx, output_dir="/out", session_id="s") + ) + + # A run that captured everything and could not write an archive still + # passed; none of these may reach the user's test. + def test_no_connection_no_send_and_a_throwing_socket_all_decline(self): + for tx in ( + None, + FakeTransport(connected=False), + FakeTransport(sends=False), + FakeTransport(raises=True), + ): + with self.subTest(transport=tx): + self.assertIsNone( + trace_export.export(tx, output_dir="/out", session_id="s") + ) + + def test_a_backend_that_never_answers_times_out_and_returns(self): + tx = FakeTransport(reply=None) # accepts the send, never replies + + path = trace_export.export( + tx, output_dir="/out", session_id="s", timeout=0.05 + ) + + self.assertIsNone(path) + # And the slot is clear, so the next run is not resolved by this one. + self.assertIsNone(trace_export._pending) + + +class TestOnlyTheRequestInFlightIsAnswered(unittest.TestCase): + """The socket outlives a single export, so a reply has to be matched.""" + + def tearDown(self): + trace_export.reset() + + def test_a_reply_carrying_another_request_id_is_ignored(self): + tx = FakeTransport(reply={"requestId": "someone-else", "path": "/x.zip"}) + + path = trace_export.export( + tx, output_dir="/out", session_id="s", timeout=0.05 + ) + + self.assertIsNone(path) + + def test_a_reply_with_no_export_in_flight_is_harmless(self): + trace_export.on_result({"requestId": "stale", "path": "/x.zip"}) + trace_export.on_result("not-a-dict") + trace_export.on_result(None) + + def test_reset_stops_a_late_reply_resolving_the_next_run(self): + tx = FakeTransport(reply=None) + trace_export.export(tx, output_dir="/out", session_id="s", timeout=0.05) + late = dict(tx.sent[0][1]) + + trace_export.on_result({"requestId": late["requestId"], "path": "/x.zip"}) + + self.assertIsNone(trace_export._pending) + + +class TestTheReplyIsRouted(unittest.TestCase): + """The frame arrives as a control message, so the handler has to route it — + a correct export module reached through nothing is still no archive.""" + + def tearDown(self): + trace_export.reset() + + def test_the_control_handler_hands_the_frame_to_the_exporter(self): + with mock.patch.object(trace_export, "on_result") as routed: + lifecycle.on_control(SCOPE_TRACE_EXPORTED, {"requestId": "r1"}) + routed.assert_called_once_with({"requestId": "r1"}) + + def test_it_does_not_trigger_the_dashboard_shutdown_path(self): + with mock.patch.object(lifecycle, "_trigger_shutdown") as shutdown: + lifecycle.on_control(SCOPE_TRACE_EXPORTED, {"requestId": "r1"}) + shutdown.assert_not_called() + + def test_the_dashboard_closing_still_shuts_down(self): + with mock.patch.object(lifecycle, "_trigger_shutdown") as shutdown: + lifecycle.on_control("clientDisconnected", {}) + shutdown.assert_called_once() + + + +class TestTheRunTriggersTheExport(unittest.TestCase): + """A correct exporter nothing calls writes no archive — and one called on + every run writes archives for people who never asked for a trace.""" + + def setUp(self): + import selenium_devtools as pkg + + self.pkg = pkg + self.saved = dict(pkg._active) + + def tearDown(self): + self.pkg._active.clear() + self.pkg._active.update(self.saved) + trace_export.reset() + + def _teardown_with(self, *, trace): + tx = FakeTransport(reply={"path": "/out/trace.zip"}) + self.pkg._active.update( + capturer=None, transport=tx, process=None, url=None, handle=None, + terminal=None, logs=None, excepthook=None, trace=trace, + ) + with mock.patch.object(trace_export, "export", return_value="/out/t.zip") as ex: + self.pkg.disable() + return ex + + def test_trace_mode_exports_on_teardown(self): + self._teardown_with(trace=True).assert_called_once() + + def test_a_normal_run_exports_nothing(self): + self._teardown_with(trace=False).assert_not_called() + + # The archive is built by the backend from what this run streamed, and the + # answer comes back on the same socket — so closing it first would time out + # every export. + def test_the_export_happens_before_the_transport_closes(self): + order = [] + tx = FakeTransport() + tx.close = lambda: order.append("closed") + self.pkg._active.update( + capturer=None, transport=tx, process=None, url=None, handle=None, + terminal=None, logs=None, excepthook=None, trace=True, + ) + with mock.patch.object( + trace_export, "export", side_effect=lambda *a, **k: order.append("export") + ): + self.pkg.disable() + self.assertEqual(order, ["export", "closed"]) + + +class TestWhereTheArchiveLands(unittest.TestCase): + """Beside the run's video, not in the cwd. + + `uninstall()` clears the resolved output dir, and it runs before the + export — so reading it at export time yields None and the archive falls + back to the cwd, which for a runner invoked from a repo root is the repo + root. That is how a stray test-results/ appears there. + """ + + def setUp(self): + import selenium_devtools as pkg + + self.pkg = pkg + self.saved = dict(pkg._active) + + def tearDown(self): + self.pkg._active.clear() + self.pkg._active.update(self.saved) + trace_export.reset() + + def test_the_dir_resolved_during_the_run_is_the_one_used(self): + # The accessor is deliberately NOT mocked: what this pins is the ORDER, + # and a stubbed reader answers the same whenever it is called. + from selenium_devtools import instrumentation + + tx = FakeTransport() + instrumentation._state["output_dir"] = "/spec/test-results" + self.pkg._active.update( + capturer=None, transport=tx, process=None, url=None, handle=None, + terminal=None, logs=None, excepthook=None, trace=True, + ) + try: + with mock.patch.object(trace_export, "export", return_value=None) as ex: + self.pkg.disable() + finally: + instrumentation._state["output_dir"] = None + + self.assertEqual(ex.call_args.kwargs["output_dir"], "/spec/test-results") + + def test_a_run_that_resolved_nothing_still_gets_a_directory(self): + from selenium_devtools import instrumentation + + tx = FakeTransport() + self.pkg._active.update( + capturer=None, transport=tx, process=None, url=None, handle=None, + terminal=None, logs=None, excepthook=None, trace=True, + ) + with mock.patch.object( + instrumentation, "resolved_output_dir", return_value=None + ), mock.patch.object(trace_export, "export", return_value=None) as ex: + self.pkg.disable() + + self.assertTrue(ex.call_args.kwargs["output_dir"].endswith("test-results")) + + +class TestWhoDecidesTraceMode(unittest.TestCase): + def _enabled(self, arg, env): + import selenium_devtools as pkg + + with mock.patch.dict("os.environ", {"DEVTOOLS_TRACE": env} if env else {}, + clear=True): + return pkg._trace_enabled(arg) + + def test_the_argument_wins_over_the_environment(self): + # So a script can opt out of an exported default. + self.assertFalse(self._enabled(False, "1")) + self.assertTrue(self._enabled(True, "")) + + def test_the_environment_decides_when_the_argument_is_absent(self): + for value, expected in [ + ("1", True), ("true", True), ("TRUE", True), ("yes", True), + ("0", False), ("", False), ("off", False), + ]: + with self.subTest(value=value): + self.assertIs(self._enabled(None, value), expected) + + def test_it_is_off_by_default(self): + self.assertFalse(self._enabled(None, None)) + + +if __name__ == "__main__": + unittest.main() + + +class TestTheArchiveBelongsToTheRun(unittest.TestCase): + """Not to the dashboard window. + + `pytest_sessionfinish` blocks on the window before tearing down, so an + export that ran at teardown waited for a human — and in CI, which opens no + window, it happened during process shutdown instead. Neither is when the + run's data became complete. + """ + + def setUp(self): + import selenium_devtools as pkg + + self.pkg = pkg + self.saved = dict(pkg._active) + + def tearDown(self): + self.pkg._active.clear() + self.pkg._active.update(self.saved) + trace_export.reset() + + def _armed(self, *, trace=True, traced=False): + self.pkg._active.update( + capturer=None, transport=FakeTransport(), process=None, url=None, + handle=None, terminal=None, logs=None, excepthook=None, + trace=trace, traced=traced, + ) + + def test_export_trace_writes_once_and_only_once(self): + self._armed() + with mock.patch.object(trace_export, "export", return_value="/o/t.zip") as ex: + first = self.pkg.export_trace() + second = self.pkg.export_trace() + self.assertEqual(first, "/o/t.zip") + self.assertIsNone(second) + ex.assert_called_once() + + # Only a SUCCESSFUL export closes the door. This is public API, so a caller + # may run it early, get nothing, and still expect an archive at the end; + # latching on the attempt spends that one chance on a transport that was + # not ready. + def test_a_failed_export_leaves_the_teardown_fallback_armed(self): + self._armed() + with mock.patch.object(trace_export, "export", return_value=None): + self.assertIsNone(self.pkg.export_trace()) + self.assertFalse(self.pkg._active["traced"]) + + def test_teardown_still_writes_after_a_failed_attempt(self): + self._armed() + with mock.patch.object(trace_export, "export", return_value=None): + self.pkg.export_trace() + with mock.patch.object(trace_export, "export", return_value="/o/t.zip") as ex: + self.pkg.disable() + ex.assert_called_once() + + def test_a_successful_export_closes_it(self): + self._armed() + with mock.patch.object(trace_export, "export", return_value="/o/t.zip"): + self.pkg.export_trace() + self.assertTrue(self.pkg._active["traced"]) + + def test_it_does_nothing_when_trace_mode_is_off(self): + self._armed(trace=False) + with mock.patch.object(trace_export, "export") as ex: + self.assertIsNone(self.pkg.export_trace()) + ex.assert_not_called() + + def test_teardown_does_not_export_again(self): + # The plugin exports at session finish; disable() must not repeat it. + self._armed(traced=True) + with mock.patch.object(trace_export, "export") as ex: + self.pkg.disable() + ex.assert_not_called() + + def test_teardown_still_covers_a_caller_that_never_asked(self): + # A plain script calls neither export_trace() nor the plugin. + self._armed() + with mock.patch.object(trace_export, "export", return_value=None) as ex: + self.pkg.disable() + ex.assert_called_once() + + +class TestTraceModeOpensNoWindow(unittest.TestCase): + """The artifact is the output, and `pytest_sessionfinish` blocks on the + window until a human closes it — so a window turns writing a file into an + interactive session. The backend still starts: it is what builds the + archive.""" + + def test_trace_mode_suppresses_the_window(self): + from selenium_devtools import lifecycle + + self.assertFalse(lifecycle.auto_open_enabled(trace=True)) + + def test_a_normal_run_still_opens_one(self): + from selenium_devtools import backend, lifecycle + + with mock.patch.dict("os.environ", {}, clear=True), mock.patch.object( + backend, "reuse_target", return_value=None + ): + self.assertTrue(lifecycle.auto_open_enabled(trace=False)) + + def test_the_existing_opt_outs_still_win(self): + from selenium_devtools import backend, lifecycle + + with mock.patch.dict("os.environ", {"DEVTOOLS_OPEN": "0"}, clear=True), \ + mock.patch.object(backend, "reuse_target", return_value=None): + self.assertFalse(lifecycle.auto_open_enabled(trace=False)) + # A rerun child reports into the window that launched it. + with mock.patch.dict("os.environ", {}, clear=True), mock.patch.object( + backend, "reuse_target", return_value=("127.0.0.1", 1234) + ): + self.assertFalse(lifecycle.auto_open_enabled(trace=False)) + + +class TestTraceModeRecordsNoVideo(unittest.TestCase): + """The archive's frames are the per-command screenshots. The screencast is + a live-dashboard artifact and `screencastFrames` does not cross the wire + yet (#290), so recording one in trace mode writes a .webm nothing reads.""" + + def setUp(self): + from selenium_devtools import instrumentation + + self.instr = instrumentation + instrumentation.uninstall() + + def tearDown(self): + self.instr.uninstall() + + def test_install_records_the_mode(self): + from selenium_devtools.capturer import SessionCapturer + + self.instr.install(SessionCapturer(FakeTransport()), FakeDriverForTrace, + trace=True) + self.assertTrue(self.instr._state["trace"]) + + def test_a_normal_run_still_records(self): + from selenium_devtools.capturer import SessionCapturer + + self.instr.install(SessionCapturer(FakeTransport()), FakeDriverForTrace) + self.assertFalse(self.instr._state["trace"]) + + def _bring_up(self, *, trace): + """Run the real session bring-up and report the entry it built.""" + from selenium_devtools.capturer import SessionCapturer + + cap = SessionCapturer(FakeTransport()) + driver = FakeDriverForTrace() + self.instr.install(cap, FakeDriverForTrace, trace=trace) + with mock.patch.object(self.instr, "ScreencastRecorder") as recorder, \ + mock.patch.object(self.instr, "start_push_screencast", + return_value=None), \ + mock.patch.object(self.instr, "bidi"), \ + mock.patch.object(self.instr, "bidi_preload"), \ + mock.patch.object(self.instr, "collector_source_text", + return_value=None): + entry = self.instr._ensure_session_setup(driver, cap) + return entry, recorder + + def test_no_recorder_is_created_in_trace_mode(self): + entry, recorder = self._bring_up(trace=True) + recorder.assert_not_called() + if entry is not None: + self.assertIsNone(entry.get("screencast")) + + def test_a_live_run_creates_one(self): + # Guards the gate against being always-on: a normal run still records. + _, recorder = self._bring_up(trace=False) + recorder.assert_called_once() + + +class FakeDriverForTrace: + """Minimal stand-in. Needs a session_id: bring-up returns early without + one, which would make the gating assertions pass for the wrong reason.""" + + def __init__(self): + self.session_id = "sess-trace" + self.caps = {"browserName": "chrome"} + + def execute(self, command, params=None): + return {"value": None} + + def get_screenshot_as_base64(self): + return "c2hvdA==" + + +class TestConcurrentExportsAreSerialized(unittest.TestCase): + """`trace_export` holds ONE pending slot. + + Two overlapping exports both replace it, so the first caller's reply is + dropped and it waits out the full 60s timeout while the backend builds the + same archive twice at the same path. Reachable because teardown can run on + the WS reader thread — `lifecycle._trigger_shutdown` hands it to whoever is + parked, and runs it itself when nobody is — while a caller is mid-export on + the main thread. + """ + + def setUp(self): + import selenium_devtools as pkg + + self.pkg = pkg + self.saved = dict(pkg._active) + pkg._active.update( + capturer=None, transport=FakeTransport(), process=None, url=None, + handle=None, terminal=None, logs=None, excepthook=None, + trace=True, traced=False, + ) + + def tearDown(self): + self.pkg._active.clear() + self.pkg._active.update(self.saved) + trace_export.reset() + + def test_only_one_request_is_sent_when_two_callers_overlap(self): + started = threading.Event() + release = threading.Event() + calls = [] + + def slow_export(*args, **kwargs): + calls.append(kwargs.get("session_id")) + started.set() + release.wait(2) + return "/out/trace.zip" + + with mock.patch.object(trace_export, "export", side_effect=slow_export): + first = threading.Thread(target=self.pkg.export_trace) + first.start() + self.assertTrue(started.wait(2), "first export never started") + # Second caller arrives while the first is still waiting on the + # backend — it must not replace the pending slot. + second_result = [] + second = threading.Thread( + target=lambda: second_result.append(self.pkg.export_trace()) + ) + second.start() + release.set() + first.join(3) + second.join(3) + + self.assertEqual(len(calls), 1, "a second request was sent") + self.assertEqual(second_result, [None]) + self.assertTrue(self.pkg._active["traced"]) + + def test_main_thread_teardown_waits_for_an_export_in_flight(self): + # Safe to wait here: the reader thread is free to deliver the reply. + order = [] + release = threading.Event() + started = threading.Event() + + def slow_export(*args, **kwargs): + started.set() + release.wait(2) + order.append("export-done") + return "/out/trace.zip" + + tx = self.pkg._active["transport"] + tx.close = lambda: order.append("closed") + + with mock.patch.object(trace_export, "export", side_effect=slow_export): + worker = threading.Thread(target=self.pkg.export_trace) + worker.start() + self.assertTrue(started.wait(2)) + releaser = threading.Timer(0.05, release.set) + releaser.start() + self.pkg.disable() # on the MAIN thread + worker.join(3) + releaser.cancel() + + self.assertEqual(order, ["export-done", "closed"]) + + # The deadlock this exists to prevent: `_trigger_shutdown` runs teardown on + # the WS reader thread when nobody is parked in wait_for_shutdown, and that + # thread is the only one that can deliver the reply the in-flight export is + # blocked on. Waiting there stalls both until the timeout, and the + # shutdown's os._exit timer may kill the process first. + def test_off_thread_teardown_never_waits_on_an_export(self): + started = threading.Event() + release = threading.Event() + finished = threading.Event() + + def slow_export(*args, **kwargs): + started.set() + release.wait(5) + return "/out/trace.zip" + + with mock.patch.object(trace_export, "export", side_effect=slow_export): + worker = threading.Thread(target=self.pkg.export_trace) + worker.start() + self.assertTrue(started.wait(2)) + + # Stands in for the reader thread arriving with clientDisconnected. + def off_thread_teardown(): + self.pkg.export_trace() + finished.set() + + threading.Thread(target=off_thread_teardown).start() + returned = finished.wait(1.0) + release.set() + worker.join(5) + + self.assertTrue( + returned, "off-thread export blocked on the in-flight one" + ) diff --git a/packages/shared/src/trace-actions.ts b/packages/shared/src/trace-actions.ts index 59b34899..4b3fc0e2 100644 --- a/packages/shared/src/trace-actions.ts +++ b/packages/shared/src/trace-actions.ts @@ -112,7 +112,39 @@ export const ACTION_MAP: Record = { // isSelected share the command name across runners and need no alias. getCssValue: { class: 'Element', method: 'getCSSProperty' }, getRect: { class: 'Element', method: 'getRect' }, - getCurrentUrl: { class: 'Page', method: 'getUrl' } + getCurrentUrl: { class: 'Page', method: 'getUrl' }, + // Raw W3C protocol names. The JS adapters wrap a client library and report + // its method names, but an adapter that patches the protocol chokepoint — + // the Python one, and any future language binding — reports what WebDriver + // itself calls the command. Unmapped commands are dropped from a trace + // outright (`trace-action-events.ts` skips them), so without these a Python + // run exported 7 actions where the live dashboard had shown ~60: `get`, + // `getCurrentUrl` and `getTitle` survived only because those three names + // happen to be shared with the vocabulary above. + // + // `findElement`/`findElements` are deliberately absent, matching the JS + // adapters: locating an element is plumbing for the action that follows, not + // an action a reader wants a row for. So is `w3cExecuteScript`: selenium + // implements `is_displayed()` and the expected-condition waits by running its + // own JS atoms through it, so mapping it filled the trace with + // `Page.evaluate("/* isDisplayed */ …")` rows the test never wrote. The JS + // Selenium adapter's `executeScript` is unmapped for the same reason, and a + // user's own `execute_script` is the cost both pay. + clickElement: { class: 'Element', method: 'click' }, + sendKeysToElement: { class: 'Element', method: 'fill' }, + clearElement: { class: 'Element', method: 'clear' }, + getElementText: { class: 'Element', method: 'getText' }, + getElementAttribute: { class: 'Element', method: 'getAttribute' }, + getElementProperty: { class: 'Element', method: 'getProperty' }, + getElementValueOfCssProperty: { class: 'Element', method: 'getCSSProperty' }, + getElementTagName: { class: 'Element', method: 'getTagName' }, + getElementRect: { class: 'Element', method: 'getRect' }, + isElementEnabled: { class: 'Element', method: 'isEnabled' }, + isElementSelected: { class: 'Element', method: 'isSelected' }, + goBack: { class: 'Page', method: 'goBack' }, + goForward: { class: 'Page', method: 'goForward' }, + switchToWindow: { class: 'Page', method: 'switchToWindow' }, + switchToParentFrame: { class: 'Frame', method: 'goto' } } /** Trace methods (ACTION_MAP values) that act at a point on the page — the diff --git a/packages/shared/tests/action-mapping.test.ts b/packages/shared/tests/action-mapping.test.ts index ca9ebd00..edcb7de2 100644 --- a/packages/shared/tests/action-mapping.test.ts +++ b/packages/shared/tests/action-mapping.test.ts @@ -161,3 +161,60 @@ describe('ACTION_MAP forward/reverse integrity', () => { expect(urlCommands[0]).toBe('getUrl') }) }) + +// The JS adapters wrap a client library and report its method names; an adapter +// that patches the protocol chokepoint reports what WebDriver calls the command. +// Unmapped commands are dropped from a trace outright, so a Python run exported +// 7 actions where the live dashboard had shown ~60 — `get`, `getCurrentUrl` and +// `getTitle` survived only by sharing a name with the vocabulary above. +describe('raw W3C protocol names', () => { + it('maps element commands onto the same actions the JS adapters produce', () => { + const pairs: [string, string][] = [ + ['clickElement', 'click'], + ['sendKeysToElement', 'fill'], + ['clearElement', 'clear'], + ['getElementText', 'getText'], + ['getElementAttribute', 'getAttribute'], + ['getElementTagName', 'getTagName'], + ['isElementEnabled', 'isEnabled'], + ['isElementSelected', 'isSelected'] + ] + for (const [command, method] of pairs) { + expect(mapCommandToAction(command)).toEqual({ + class: 'Element', + method + }) + } + }) + + it('agrees with the client-library name for the same concept', () => { + // One name per concept: a click is a click whichever adapter reported it. + for (const [w3c, js] of [ + ['clickElement', 'click'], + ['sendKeysToElement', 'sendKeys'], + ['getElementText', 'getText'], + ['getElementAttribute', 'getAttribute'] + ]) { + expect(mapCommandToAction(w3c)).toEqual(mapCommandToAction(js)) + } + }) + + // Locating an element is plumbing for the action that follows. The JS + // adapters emit no row for it and neither should a protocol-level one. + it('leaves finds and window bookkeeping unmapped', () => { + for (const command of [ + 'findElement', + 'findElements', + 'findChildElement', + 'w3cGetCurrentWindowHandle', + // selenium runs its own atoms through this — is_displayed(), and every + // expected-condition wait — so a mapped one fills the trace with + // `evaluate("/* isDisplayed */ …")` rows the test never wrote. The JS + // adapter's `executeScript` is unmapped too. + 'w3cExecuteScript', + 'w3cExecuteScriptAsync' + ]) { + expect(mapCommandToAction(command)).toBeNull() + } + }) +})