1#!/usr/bin/env python3
2"""Local CEF startup harness with synthetic fixtures (stdlib only).
3
4Scenarios:
5 process-warm one unrecorded warm-up, then new processes sharing an
6 isolated previously initialized CEF root-cache profile
7 profile-fresh new process, new profile each sample
8 relay-window a real long-lived owner browser holds the relay; samples
9 launch browse with DUMBER_BROWSER_FRESH_WINDOW=1 in that
10 same isolated profile
11 reopen-window like relay-window, but each sample first closes all owner
12 windows through the diagnostic relay action, then reopens
13 through the relay; verifies the same owner process serves
14 the reopen without a second CEF initialization
15
16Second-window contract (relay-window, reopen-window): the owner captures
17its own log, readiness is its first presentation (never a fixed sleep),
18and every sample records owner_cef_init_count, which must stay at 1.
19Cold-process numbers (process-warm, profile-fresh) and resident-reopen
20observations are reported separately and never averaged together.
21--idle-timeout-ms forwards the product residency knob into generated
22configs (default 0 = exit with last window; reopen-window only reuses
23the same process with a nonzero timeout). Second-window latency is
24first_document_observation_ms (spawn to first fixture document request
25on the harness clock); paint-level timing stays open until page
26beacons are delivered.
27
28Fixtures (loopback only): static, delayed, redirect, cache.
29
30Protocol: fixture pages report PerformanceObserver results through a
31token-authenticated loopback beacon (/__beacon with run/nav/event/value
32parameters) served by the harness HTTP server. Beacon arrivals carry the
33harness monotonic timestamp. External spawn-to-arrival is recorded as an
34explicitly named observation duration, including output-delivery overhead;
35it is never presented as an exact child event timestamp.
36
37Clock domains are kept separate: child t_ms values are never subtracted from
38the harness wall clock. GTK after-paint is labeled GTK paint, never compositor
39presentation. Missing target FCP remains incomplete; the harness never stops
40on a blank GTK summary.
41"""
42
43import argparse
44import hashlib
45import json
46import os
47import re
48import secrets
49import shutil
50import socket
51import subprocess
52import sys
53import tempfile
54import threading
55import time
56from http.server import BaseHTTPRequestHandler, ThreadingHTTPServer
57from urllib.parse import parse_qs, urlparse
58
59TOKEN_RE = re.compile(r"^[0-9a-f]{16}$")
60NAV_RE = re.compile(r"^[0-9a-f]{16}$")
61BEACON_EVENTS = ("first-contentful-paint", "largest-contentful-paint", "fixture-load")
62DEFAULT_POST_NAV_CUTOFF_SECONDS = 5.0
63
64# Deterministic 1x1 RGBA PNG so image endpoints exercise a successful decode
65# and paint instead of the decode-failure path.
66FIXTURE_PNG = bytes.fromhex(
67 "89504e470d0a1a0a"
68 "0000000d49484452000000010000000108060000001f15c489"
69 "0000000b4944415478da6360000300000700012122db13"
70 "0000000049454e44ae426082"
71)
72
73
74def post_nav_cutoff_seconds():
75 try:
76 value = float(os.environ.get("DUMBER_MEASURE_CUTOFF_SECONDS", DEFAULT_POST_NAV_CUTOFF_SECONDS))
77 except ValueError:
78 return DEFAULT_POST_NAV_CUTOFF_SECONDS
79 return min(30.0, max(0.1, value))
80
81
82def navigation_deadline_seconds():
83 # Bounded wait for the correlated document after spawn when no
84 # document has arrived yet. Overridable for fast unit tests.
85 try:
86 value = float(os.environ.get("DUMBER_MEASURE_NAV_DEADLINE_SECONDS", ""))
87 if value > 0:
88 return min(60.0, value)
89 except ValueError:
90 pass
91 return post_nav_cutoff_seconds() + 5.0
92
93
94def is_residency_valid(result, scenario):
95 # Fixture completeness (document count, beacons) is not residency
96 # validity. A resident sample is valid only when the launcher handed
97 # off cleanly to a live, unchanged owner that initialized CEF exactly
98 # once, the launcher itself never initialized CEF (a fallback cold
99 # start would hide in the dead owner's log), and a reopen additionally
100 # completed its close. Returns True/False, or None outside resident
101 # scenarios.
102 if scenario not in ("relay-window", "reopen-window"):
103 return None
104 if result.get("fallback_spawn") or not result.get("relayed"):
105 return False
106 if result.get("launcher_returncode") != 0:
107 return False
108 if result.get("owner_cef_init_count") != 1:
109 return False
110 if result.get("launcher_cef_init_count", 0) != 0:
111 return False
112 if scenario == "reopen-window":
113 reopen = result.get("reopen") or {}
114 if not (reopen.get("close_acknowledged")
115 and reopen.get("quiescence_settled", False)
116 and reopen.get("same_process")
117 and reopen.get("owner_alive_after")):
118 return False
119 return True
120
121
122class FixtureState:
123 def __init__(self):
124 self.lock = threading.Lock()
125 self.document_requests = []
126 self.subresource_requests = []
127 self.beacons = []
128 self.first_document_monotonic = None
129
130
131def build_fixture_html(kind, run_token, nav_token):
132 observer = (
133 "<script>(function(){"
134 "function beacon(event, value){"
135 "fetch('/__beacon?run=%s&nav=%s&event='+event+'&value='+value,"
136 "{cache:'no-store'}).catch(function(){});"
137 "}"
138 "try{"
139 "var po=new PerformanceObserver(function(list){"
140 "list.getEntries().forEach(function(en){"
141 "if(en.name==='first-contentful-paint'){beacon('first-contentful-paint',Math.round(en.startTime));}"
142 "else if(en.entryType==='largest-contentful-paint'){beacon('largest-contentful-paint',Math.round(en.startTime));}"
143 "}});"
144 "po.observe({type:'paint',buffered:true});"
145 "po.observe({type:'largest-contentful-paint',buffered:true});"
146 "}catch(e){}"
147 "window.addEventListener('load',function(){"
148 "setTimeout(function(){beacon('fixture-load',0);},100);});"
149 "})();</script>" % (run_token, nav_token)
150 )
151 if kind == "static":
152 return (
153 "<!doctype html><html><head><title>static</title>"
154 '<link rel="stylesheet" href="/app.css">'
155 "</head><body><h1>static</h1>"
156 '<img src="/pixel.png">'
157 + observer
158 + "</body></html>"
159 )
160 if kind == "delayed":
161 return (
162 "<!doctype html><html><head><title>delayed</title></head>"
163 "<body><h1>delayed</h1>" + observer + "</body></html>"
164 )
165 if kind == "redirect":
166 return (
167 "<!doctype html><html><head><title>target</title></head>"
168 "<body><h1>target</h1>" + observer + "</body></html>"
169 )
170 if kind == "cache":
171 return (
172 "<!doctype html><html><head><title>cache</title>"
173 '<script src="/cacheable.js"></script>'
174 "</head><body><h1>cache</h1>"
175 '<img src="/cacheable.png">'
176 + observer
177 + "</body></html>"
178 )
179 raise ValueError("unknown fixture: " + kind)
180
181
182class Handler(BaseHTTPRequestHandler):
183 state = None
184 fixture = "static"
185 run_token = ""
186 nav_token = ""
187 delay_seconds = 0.3
188
189 def log_message(self, *args):
190 pass
191
192 def _record(self, document):
193 with self.state.lock:
194 entry = {"path": self.path, "time": time.monotonic()}
195 if document:
196 self.state.document_requests.append(entry)
197 if self.state.first_document_monotonic is None:
198 self.state.first_document_monotonic = entry["time"]
199 else:
200 self.state.subresource_requests.append(entry)
201
202 def _document_tokens_valid(self, parsed):
203 # Document routes carry the sample tokens by construction; an
204 # uncorrelated request (stale tab, foreign client, port reuse)
205 # must neither establish the first-document timestamp nor be
206 # served the current sample's tokens.
207 query = parse_qs(parsed.query)
208 run = query.get("run", [None])[0]
209 nav = query.get("nav", [None])[0]
210 return (
211 isinstance(run, str) and TOKEN_RE.fullmatch(run) and run == self.run_token
212 and isinstance(nav, str) and NAV_RE.fullmatch(nav) and nav == self.nav_token
213 )
214
215 def do_GET(self):
216 parsed = urlparse(self.path)
217 path = parsed.path
218 if path == "/__beacon":
219 self._handle_beacon(parsed)
220 return
221 if path in ("/", "/index.html", "/target", "/redirect"):
222 if not self._document_tokens_valid(parsed):
223 self.send_response(404)
224 self.end_headers()
225 return
226 self._record(True)
227 if path == "/redirect":
228 target = "/target?run=%s&nav=%s" % (self.run_token, self.nav_token)
229 self.send_response(302)
230 self.send_header("Location", target)
231 self.end_headers()
232 return
233 if self.fixture == "delayed" and path == "/":
234 time.sleep(self.delay_seconds)
235 body = build_fixture_html(
236 "static" if self.fixture == "redirect" and path == "/" else self.fixture,
237 self.run_token,
238 self.nav_token,
239 ).encode()
240 self.send_response(200)
241 self.send_header("Content-Type", "text/html")
242 self.send_header("Content-Length", str(len(body)))
243 self.end_headers()
244 self.wfile.write(body)
245 return
246 if path in ("/app.css", "/pixel.png", "/cacheable.js", "/cacheable.png"):
247 self._record(False)
248 if path.endswith(".png"):
249 body = FIXTURE_PNG
250 else:
251 body = b"/* fixture */"
252 self.send_response(200)
253 if path.endswith(".css"):
254 self.send_header("Content-Type", "text/css")
255 elif path.endswith(".js"):
256 self.send_header("Content-Type", "application/javascript")
257 else:
258 self.send_header("Content-Type", "image/png")
259 if self.fixture == "cache":
260 self.send_header("Cache-Control", "private, max-age=3600")
261 else:
262 self.send_header("Cache-Control", "no-store")
263 self.send_header("Content-Length", str(len(body)))
264 self.end_headers()
265 self.wfile.write(body)
266 return
267 self._record(False)
268 self.send_response(404)
269 self.end_headers()
270
271 def _handle_beacon(self, parsed):
272 query = parse_qs(parsed.query)
273 run = query.get("run", [None])[0]
274 nav = query.get("nav", [None])[0]
275 event = query.get("event", [None])[0]
276 value_raw = query.get("value", [None])[0]
277 valid = (
278 isinstance(run, str) and TOKEN_RE.fullmatch(run) and run == self.run_token
279 and isinstance(nav, str) and NAV_RE.fullmatch(nav) and nav == self.nav_token
280 and event in BEACON_EVENTS
281 )
282 try:
283 value = int(value_raw) if valid else None
284 valid = valid and value is not None and value >= 0
285 except (TypeError, ValueError):
286 valid = False
287 if not valid:
288 self.send_response(400)
289 self.end_headers()
290 return
291 with self.state.lock:
292 self.state.beacons.append({
293 "event": event,
294 "value_ms": value,
295 "arrival_monotonic": time.monotonic(),
296 })
297 self.send_response(204)
298 self.end_headers()
299
300
301def make_sample_handler(state, fixture, run_token, nav_token):
302 # Per-sample handler state: the base Handler only carries defaults.
303 # Binding state on a fresh subclass per sample keeps surviving request
304 # threads of a previous sample from adopting a later sample's tokens.
305 return type("SampleHandler", (Handler,), {
306 "state": state,
307 "fixture": fixture,
308 "run_token": run_token,
309 "nav_token": nav_token,
310 })
311
312
313def parse_child_output(lines):
314 milestones = []
315 for line in lines:
316 try:
317 event = json.loads(line)
318 except (json.JSONDecodeError, ValueError):
319 continue
320 if isinstance(event, dict) and event.get("message") == "startup_trace: milestone":
321 milestones.append(event)
322 return milestones
323
324
325DISPLAY_PASSTHROUGH_VARS = ("DBUS_SESSION_BUS_ADDRESS", "XAUTHORITY")
326
327
328def _escape_toml_basic(value):
329 # Full TOML basic-string escaping: backslash, quote, and every
330 # control character (raw newlines/tabs/other C0 controls are invalid
331 # in basic strings). Paths with such characters stay representable
332 # instead of producing broken configuration.
333 out = []
334 for char in value:
335 code = ord(char)
336 if char == "\\":
337 out.append("\\\\")
338 elif char == '"':
339 out.append('\\"')
340 elif char == "\n":
341 out.append("\\n")
342 elif char == "\t":
343 out.append("\\t")
344 elif char == "\r":
345 out.append("\\r")
346 elif char == "\b":
347 out.append("\\b")
348 elif char == "\f":
349 out.append("\\f")
350 elif code < 0x20 or code == 0x7F:
351 out.append("\\u%04X" % code)
352 else:
353 out.append(char)
354 return "".join(out)
355
356
357def write_child_config(config_home, cef_dir, idle_timeout_ms=0):
358 """Force JSON debug logging so milestone parsing works.
359
360 Without this, isolated XDG homes fall back to text logs and
361 parse_child_output finds zero milestones. Idempotent: relay owners
362 share one config across samples. idle_timeout_ms selects the product
363 residency knob (0 = product default, exit with last window)."""
364 config_dir = os.path.join(config_home, "dumber")
365 os.makedirs(config_dir, exist_ok=True)
366 path = os.path.join(config_dir, "config.toml")
367 content = (
368 '[logging]\nlevel = "debug"\nformat = "json"\n'
369 'enable_file_log = false\n\n[engine.cef]\ncef_dir = "%s"\n'
370 'idle_runtime_timeout_ms = %d\n'
371 % (_escape_toml_basic(cef_dir), idle_timeout_ms)
372 )
373 with open(path, "w") as handle:
374 handle.write(content)
375 return path
376
377
378def ensure_wayland_socket(runtime_dir, env):
379 """Point a relative Wayland display at the real compositor socket.
380
381 Isolating XDG_RUNTIME_DIR breaks relative WAYLAND_DISPLAY values
382 (the compositor socket lives in the real runtime dir). Symlinking the
383 socket into the isolated dir is not an option: isolated test paths
384 easily exceed the 108-byte unix-socket limit and CEF aborts with
385 "File name too long". Instead, when the display is a relative name
386 whose socket exists in the real runtime dir, override WAYLAND_DISPLAY
387 with its absolute path, which Wayland clients use as-is. The isolated
388 runtime dir stays untouched. Returns True when rendering connectivity
389 is preserved or Wayland is not in use."""
390 display = env.get("WAYLAND_DISPLAY", "")
391 if not display or "/" in display:
392 return True
393 os.makedirs(runtime_dir, exist_ok=True)
394 real_runtime = os.environ.get("XDG_RUNTIME_DIR", "/run/user/%d" % os.getuid())
395 source = os.path.join(real_runtime, display)
396 if os.path.exists(source):
397 env["WAYLAND_DISPLAY"] = source
398 return True
399 return False
400
401
402def count_cef_inits(lines):
403 """Count CEF initialization completions in child output lines.
404
405 Each process initializes CEF at most once: a resident owner serving
406 N second windows must still show exactly one cef_initialized
407 milestone. Only the milestone event counts; the InitWithApp log line
408 describes the same init and is ignored."""
409 count = 0
410 for line in lines:
411 try:
412 event = json.loads(line)
413 except (json.JSONDecodeError, ValueError):
414 continue
415 if (
416 isinstance(event, dict)
417 and event.get("message") == "startup_trace: milestone"
418 and event.get("milestone") == "cef_initialized"
419 ):
420 count += 1
421 return count
422
423
424def wait_for_owner_log_line(log_path, needle, timeout_seconds=30.0):
425 """Wait until the owner log contains needle. Bounded; False on timeout."""
426 end = time.monotonic() + timeout_seconds
427 while time.monotonic() < end:
428 try:
429 with open(log_path, errors="replace") as handle:
430 for line in handle:
431 if needle in line:
432 return True
433 except OSError:
434 pass
435 time.sleep(0.2)
436 return False
437
438
439def scenario_env(cef_dir, dirs, extra=None, idle_timeout_ms=0):
440 env = {
441 "HOME": os.environ.get("HOME", ""),
442 "PATH": os.environ.get("PATH", ""),
443 "LANG": os.environ.get("LANG", "C.UTF-8"),
444 "DISPLAY": os.environ.get("DISPLAY", ""),
445 "WAYLAND_DISPLAY": os.environ.get("WAYLAND_DISPLAY", ""),
446 "XDG_CONFIG_HOME": dirs["config"],
447 "XDG_DATA_HOME": dirs["data"],
448 "XDG_STATE_HOME": dirs["state"],
449 "XDG_CACHE_HOME": dirs["cache"],
450 "XDG_RUNTIME_DIR": dirs["runtime"],
451 "CEF_DIR": cef_dir,
452 "DUMBER_CEF_DIR": cef_dir,
453 "DUMBER_CEF_ROOT_CACHE_PATH": dirs["root_cache"],
454 }
455 if extra:
456 env.update(extra)
457 for name in DISPLAY_PASSTHROUGH_VARS:
458 value = os.environ.get(name)
459 if value:
460 env[name] = value
461 for key in ("config", "data", "state", "cache", "runtime"):
462 os.makedirs(dirs[key], exist_ok=True)
463 os.makedirs(dirs["root_cache"], exist_ok=True)
464 write_child_config(dirs["config"], cef_dir, idle_timeout_ms)
465 ensure_wayland_socket(dirs["runtime"], env)
466 return env
467
468
469def wait_for_relay_socket(search_root, timeout_seconds=30.0):
470 # The relay socket lives under XDG_STATE_HOME
471 # (<state>/[dumber/]runtime/<engine>/browser-launch.sock), not the
472 # XDG_RUNTIME dir: walk the state tree. Keep scenario outputs shallow:
473 # unix-socket paths are limited to 108 bytes and deep evidence dirs
474 # make the relay unreachable.
475 end = time.monotonic() + timeout_seconds
476 while time.monotonic() < end:
477 for root, _, files in os.walk(search_root):
478 if "browser-launch.sock" in files:
479 path = os.path.join(root, "browser-launch.sock")
480 sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
481 sock.settimeout(2.0)
482 try:
483 sock.connect(path)
484 return path
485 except OSError:
486 pass
487 finally:
488 sock.close()
489 time.sleep(0.2)
490 return None
491
492
493def start_relay_owner(binary, cef_dir, scenario_dir, diagnostic_close=False,
494 idle_timeout_ms=0):
495 dirs = {
496 "config": os.path.join(scenario_dir, "owner-config"),
497 "data": os.path.join(scenario_dir, "owner-data"),
498 "state": os.path.join(scenario_dir, "owner-state"),
499 "cache": os.path.join(scenario_dir, "owner-cache"),
500 "runtime": os.path.join(scenario_dir, "owner-runtime"),
501 "root_cache": os.path.join(scenario_dir, "shared-profile"),
502 "owner_log": os.path.join(scenario_dir, "owner.log"),
503 }
504 # scenario_env only reads the six XDG/root-cache keys; owner_log
505 # rides along for CEF-init counting without affecting the child env.
506 env = scenario_env(cef_dir, dirs, idle_timeout_ms=idle_timeout_ms)
507 if diagnostic_close:
508 # Owned window-close mechanism for the reopen scenario only: the
509 # relay honors it solely in processes carrying this variable. It is
510 # never a general unauthenticated shutdown command.
511 env = dict(env)
512 env["DUMBER_DIAGNOSTIC_WINDOW_CLOSE"] = "1"
513 log_file = open(dirs["owner_log"], "w")
514 try:
515 proc = subprocess.Popen(
516 [binary, "browse", "about:blank"],
517 stdout=log_file,
518 stderr=subprocess.STDOUT,
519 text=True,
520 bufsize=1,
521 env=env,
522 )
523 except OSError:
524 log_file.close()
525 return None, None, None
526 if proc.poll() is not None:
527 log_file.close()
528 return None, None, None
529 # Readiness is the owner's first presentation, not a fixed sleep:
530 # only then is the relay guaranteed to serve second windows.
531 ready = wait_for_owner_log_line(
532 dirs["owner_log"], "startup_trace: first presentation")
533 log_file.close()
534 if not ready or proc.poll() is not None:
535 stop_proc(proc)
536 return None, None, None
537 socket_path = wait_for_relay_socket(dirs["state"])
538 if socket_path is None:
539 proc.terminate()
540 try:
541 proc.wait(timeout=5)
542 except subprocess.TimeoutExpired:
543 proc.kill()
544 return None, None, None
545 return proc, dirs, socket_path
546
547
548def stop_proc(proc):
549 if proc is None or proc.poll() is not None:
550 return
551 proc.terminate()
552 try:
553 proc.wait(timeout=5)
554 except subprocess.TimeoutExpired:
555 proc.kill()
556 proc.wait(timeout=5)
557
558
559def send_diagnostic_close(socket_path, timeout_seconds=10.0):
560 """Ask the relay owner to close all windows. Returns True only on an
561 explicit acknowledgement. Never a general shutdown command: owners
562 honor it solely with DUMBER_DIAGNOSTIC_WINDOW_CLOSE=1."""
563 request = json.dumps({"request_id": secrets.token_hex(8), "action": "close-all-windows"}) + "\n"
564 sock = socket.socket(socket.AF_UNIX, socket.SOCK_STREAM)
565 sock.settimeout(timeout_seconds)
566 try:
567 sock.connect(socket_path)
568 sock.sendall(request.encode())
569 received = b""
570 while b"\n" not in received:
571 chunk = sock.recv(4096)
572 if not chunk:
573 break
574 received += chunk
575 try:
576 response = json.loads(received.decode())
577 except ValueError:
578 return False
579 return bool(response.get("accepted")) and not response.get("error")
580 except OSError:
581 return False
582 finally:
583 sock.close()
584
585
586def child_pids(root_pid):
587 """Direct child pids of root_pid via /proc (stdlib only)."""
588 children = []
589 try:
590 entries = os.listdir("/proc")
591 except OSError:
592 return children
593 for entry in entries:
594 if not entry.isdigit():
595 continue
596 try:
597 with open("/proc/%s/stat" % entry) as handle:
598 parts = handle.read().rsplit(")", 1)[1].split()
599 if int(parts[1]) == root_pid:
600 children.append(int(entry))
601 except (OSError, ValueError, IndexError):
602 continue
603 return children
604
605
606def proc_starttime(pid):
607 """Process start time (jiffies since boot) via /proc, or None.
608 Combined with the pid it forms an independently observed identity that
609 survives Popen-handle reuse and detects pid recycling."""
610 try:
611 with open("/proc/%d/stat" % pid) as handle:
612 parts = handle.read().rsplit(")", 1)[1].split()
613 return int(parts[19])
614 except (OSError, ValueError, IndexError):
615 return None
616
617
618def wait_for_child_quiescence(owner_pid, settle_seconds=2.0, timeout_seconds=15.0):
619 """Wait until the owner's child count is stable across settle_seconds.
620 Window close is asynchronous: the relay acknowledgement only means the
621 request was accepted, so reopening must wait for an observable steady
622 state instead of a fixed sleep. Returns (stable_count, settled):
623 settled is False on timeout, and a timeout must fail the reopen, not
624 silently pass. Child counts stay diagnostics only: CEF process
625 topology does not map one-to-one to windows, so stability alone never
626 proves zero windows or resident-idle entry."""
627 end = time.monotonic() + timeout_seconds
628 last_change = time.monotonic()
629 last_count = len(child_pids(owner_pid))
630 while time.monotonic() < end:
631 time.sleep(0.5)
632 count = len(child_pids(owner_pid))
633 if count != last_count:
634 last_count = count
635 last_change = time.monotonic()
636 elif time.monotonic() - last_change >= settle_seconds:
637 return count, True
638 return len(child_pids(owner_pid)), False
639
640
641def proc_rss_kb(pid):
642 """Resident memory of pid in KiB via /proc, or None."""
643 try:
644 with open("/proc/%d/status" % pid) as handle:
645 for line in handle:
646 if line.startswith("VmRSS:"):
647 return int(line.split()[1])
648 except (OSError, ValueError, IndexError):
649 pass
650 return None
651
652
653def run_sample(binary, cef_dir, scenario, fixture, run_index, owner=None, owner_dirs=None,
654 shared_root_cache=None, owner_socket=None, idle_timeout_ms=0):
655 run_token = secrets.token_hex(8)
656 nav_token = secrets.token_hex(8)
657 cutoff = post_nav_cutoff_seconds()
658 state = FixtureState()
659 server = ThreadingHTTPServer(("127.0.0.1", 0),
660 make_sample_handler(state, fixture, run_token, nav_token))
661 port = server.server_address[1]
662 thread = threading.Thread(target=server.serve_forever, kwargs={"poll_interval": 0.05})
663 thread.daemon = True
664 thread.start()
665 run_dir = tempfile.mkdtemp(prefix="cef-startup-run-%02d-" % run_index)
666 try:
667 if fixture == "redirect":
668 url = "http://127.0.0.1:%d/redirect?run=%s&nav=%s" % (port, run_token, nav_token)
669 else:
670 url = "http://127.0.0.1:%d/?run=%s&nav=%s" % (port, run_token, nav_token)
671 if scenario in ("relay-window", "reopen-window") and owner_dirs is not None:
672 dirs = dict(owner_dirs)
673 extra = {"DUMBER_BROWSER_FRESH_WINDOW": "1"}
674 else:
675 dirs = {
676 "config": os.path.join(run_dir, "config"),
677 "data": os.path.join(run_dir, "data"),
678 "state": os.path.join(run_dir, "state"),
679 "cache": os.path.join(run_dir, "cache"),
680 "runtime": os.path.join(run_dir, "runtime"),
681 "root_cache": shared_root_cache or os.path.join(run_dir, "cef-root-cache"),
682 }
683 extra = {}
684 env = scenario_env(cef_dir, dirs, extra, idle_timeout_ms)
685 owner_alive_at_start = owner is not None and owner.poll() is None
686 reopen = None
687 if scenario == "reopen-window" and owner is not None and owner_socket:
688 owner_pid = owner.pid
689 owner_start = proc_starttime(owner_pid)
690 children_before = child_pids(owner_pid)
691 rss_before = proc_rss_kb(owner_pid)
692 acknowledged = send_diagnostic_close(owner_socket)
693 # The acknowledgement only means accepted: wait for an
694 # observable steady state before measuring the reopen.
695 # An unsettled timeout fails the reopen via quiescence_settled.
696 quiescent_children, settled = wait_for_child_quiescence(owner_pid)
697 reopen = {
698 "owner_pid": owner_pid,
699 "owner_starttime": owner_start,
700 "close_acknowledged": acknowledged,
701 "quiescence_settled": settled,
702 "browser_child_count_before": len(children_before),
703 "browser_child_count_quiescent": quiescent_children,
704 "owner_rss_kb_before": rss_before,
705 }
706 spawn_ts = time.monotonic()
707 proc = subprocess.Popen(
708 [binary, "browse", url],
709 stdout=subprocess.PIPE,
710 stderr=subprocess.STDOUT,
711 text=True,
712 bufsize=1,
713 env=env,
714 )
715 arrivals = []
716
717 def pump():
718 try:
719 for line in proc.stdout:
720 arrivals.append((time.monotonic(), line))
721 except ValueError:
722 pass
723
724 pump_thread = threading.Thread(target=pump)
725 pump_thread.daemon = True
726 pump_thread.start()
727 nav_deadline = navigation_deadline_seconds()
728 # A live owner serves the navigation after the launcher exits:
729 # in that case launcher exit must not end collection before the
730 # correlated document arrives. Without a live owner the sample
731 # is its own browser and exit ends it.
732 defers_to_owner = bool(owner_alive_at_start and owner_dirs is not None
733 and scenario in ("relay-window", "reopen-window"))
734 hard_end = spawn_ts + cutoff + 25.0
735 while True:
736 now = time.monotonic()
737 with state.lock:
738 navigated_at = state.first_document_monotonic
739 fixture_done = any(
740 b["event"] == "fixture-load" for b in state.beacons
741 )
742 exited = proc.poll() is not None
743 if navigated_at is not None:
744 if fixture_done and now >= navigated_at + cutoff:
745 break
746 if now >= navigated_at + cutoff + 5.0:
747 break
748 elif now >= spawn_ts + nav_deadline or (exited and not defers_to_owner):
749 break
750 if now >= hard_end:
751 break
752 time.sleep(0.05)
753 self_exited = proc.poll() is not None
754 if proc.poll() is None:
755 proc.terminate()
756 try:
757 proc.wait(timeout=5)
758 except subprocess.TimeoutExpired:
759 proc.kill()
760 proc.wait(timeout=5)
761 launcher_returncode = proc.returncode
762 pump_thread.join(timeout=5)
763 try:
764 proc.stdout.close()
765 except (AttributeError, ValueError):
766 pass
767 decision_ts = time.monotonic()
768 milestones = parse_child_output([line for _, line in arrivals])
769 with state.lock:
770 beacons = list(state.beacons)
771 document_count = len(state.document_requests)
772 subresource_count = len(state.subresource_requests)
773 first_document_at = state.first_document_monotonic
774 fcp = [b for b in beacons if b["event"] == "first-contentful-paint"]
775 lcp = [b for b in beacons if b["event"] == "largest-contentful-paint"]
776 if fcp:
777 observation_ms = int((fcp[0]["arrival_monotonic"] - spawn_ts) * 1000)
778 elif beacons:
779 observation_ms = int((beacons[-1]["arrival_monotonic"] - spawn_ts) * 1000)
780 else:
781 observation_ms = int((decision_ts - spawn_ts) * 1000)
782 expected_document_requests = 2 if fixture == "redirect" else 1
783 complete = document_count == expected_document_requests and len(fcp) > 0
784 if scenario in ("relay-window", "reopen-window"):
785 relayed = bool(owner_alive_at_start and self_exited)
786 else:
787 relayed = False
788 result = {
789 "run": run_index,
790 "scenario": scenario,
791 "fixture": fixture,
792 "run_token": run_token,
793 "nav_token": nav_token,
794 "observation_spawn_to_summary_ms": observation_ms,
795 "document_requests": document_count,
796 "subresource_requests": subresource_count,
797 "target_fcp_ms": fcp[0]["value_ms"] if fcp else None,
798 "target_lcp_through_cutoff_ms": lcp[-1]["value_ms"] if lcp else None,
799 "startup_milestones": len(milestones),
800 "launcher_returncode": launcher_returncode,
801 "launcher_cef_init_count": count_cef_inits([line for _, line in arrivals]),
802 "first_document_observation_ms": (
803 int((first_document_at - spawn_ts) * 1000)
804 if first_document_at is not None and first_document_at >= spawn_ts
805 else None
806 ),
807 "complete": complete,
808 "relayed": relayed,
809 "fallback_spawn": scenario in ("relay-window", "reopen-window") and not relayed,
810 }
811 if scenario in ("relay-window", "reopen-window") and owner_dirs is not None:
812 # Residency proof: the owner must initialize CEF exactly once
813 # no matter how many second windows it serves. A second init
814 # here means the sample paid a full cold start, not a reopen.
815 try:
816 with open(owner_dirs.get("owner_log", ""), errors="replace") as owner_log:
817 result["owner_cef_init_count"] = count_cef_inits(owner_log)
818 except OSError:
819 result["owner_cef_init_count"] = None
820 if reopen is not None:
821 # Owner identity is verified independently of the Popen handle:
822 # the same pid with a different start time is a recycled pid,
823 # not the same process. Unverifiable identity counts as different.
824 start_now = proc_starttime(reopen["owner_pid"]) if owner is not None else None
825 owner_alive = owner is not None and owner.poll() is None
826 same = bool(
827 owner_alive
828 and reopen["owner_starttime"] is not None
829 and start_now == reopen["owner_starttime"]
830 )
831 reopen["owner_alive_after"] = owner_alive
832 reopen["same_process"] = same
833 reopen["browser_child_count_after"] = len(child_pids(owner.pid)) if owner_alive else 0
834 reopen["owner_rss_kb_after"] = proc_rss_kb(owner.pid) if owner_alive else None
835 result["reopen"] = reopen
836 result["residency_valid"] = is_residency_valid(result, scenario)
837 return result
838 finally:
839 server.shutdown()
840 server.server_close()
841 thread.join(timeout=5)
842 shutil.rmtree(run_dir, ignore_errors=True)
843
844
845def main():
846 parser = argparse.ArgumentParser(description="Measure CEF startup against synthetic fixtures.")
847 parser.add_argument("--binary", required=True)
848 parser.add_argument("--cef-dir", required=True)
849 parser.add_argument(
850 "--scenario",
851 required=True,
852 choices=("process-warm", "profile-fresh", "relay-window", "reopen-window"),
853 )
854 parser.add_argument(
855 "--fixture",
856 required=True,
857 choices=("static", "delayed", "redirect", "cache"),
858 )
859 parser.add_argument("--runs", type=int, default=30)
860 parser.add_argument("--output", required=True)
861 parser.add_argument("--idle-timeout-ms", type=int, default=0,
862 help="resident CEF idle timeout for generated configs "
863 "(0..300000, 0 is the product default)")
864 args = parser.parse_args()
865
866 if args.idle_timeout_ms < 0 or args.idle_timeout_ms > 300000:
867 print("measure: --idle-timeout-ms must be 0..300000", file=sys.stderr)
868 raise SystemExit(2)
869
870 if args.runs < 1 or args.runs > 100:
871 print("measure: --runs must be 1..100", file=sys.stderr)
872 raise SystemExit(2)
873 if not os.path.isabs(args.output) or os.path.exists(args.output) or os.path.islink(args.output):
874 print("measure: --output must be a fresh absolute directory", file=sys.stderr)
875 raise SystemExit(2)
876 parent = os.path.dirname(args.output)
877 if not os.path.isdir(parent) or os.path.islink(parent):
878 print("measure: --output parent must be an existing directory", file=sys.stderr)
879 raise SystemExit(2)
880 if not (os.path.isfile(args.binary) and os.access(args.binary, os.X_OK)):
881 print("measure: --binary must be executable", file=sys.stderr)
882 raise SystemExit(2)
883 if not os.path.isdir(args.cef_dir):
884 print("measure: --cef-dir must be a directory", file=sys.stderr)
885 raise SystemExit(2)
886 with open(args.binary, "rb") as candidate:
887 # Chunked streaming hash: hashlib.file_digest needs 3.11+, this
888 # stays compatible with older 3.x interpreters.
889 digest = hashlib.sha256()
890 for chunk in iter(lambda: candidate.read(65536), b""):
891 digest.update(chunk)
892 binary_sha256 = digest.hexdigest()
893
894 os.makedirs(args.output)
895 # Privacy: only summary.json and run-*.json are safe to share (timings,
896 # counts, hashes). owner.log and generated configs are machine-local:
897 # raw child logs and the selected --cef-dir path may contain local
898 # usernames or paths. Never publish the whole directory.
899 owner = None
900 owner_dirs = None
901 owner_socket = None
902 shared_root_cache = None
903 warmup_discarded = False
904 if args.scenario == "process-warm":
905 shared_root_cache = os.path.join(args.output, "warm-profile", "cef-root-cache")
906 os.makedirs(shared_root_cache)
907 if args.scenario == "relay-window":
908 scenario_dir = os.path.join(args.output, "relay-scenario")
909 os.makedirs(scenario_dir)
910 owner, owner_dirs, owner_socket = start_relay_owner(
911 args.binary, args.cef_dir, scenario_dir,
912 idle_timeout_ms=args.idle_timeout_ms)
913 if args.scenario == "reopen-window":
914 scenario_dir = os.path.join(args.output, "reopen-scenario")
915 os.makedirs(scenario_dir)
916 owner, owner_dirs, owner_socket = start_relay_owner(
917 args.binary, args.cef_dir, scenario_dir, diagnostic_close=True,
918 idle_timeout_ms=args.idle_timeout_ms)
919
920 results = []
921 try:
922 if args.scenario == "process-warm":
923 # One unrecorded warm-up initializes the shared profile; only the
924 # recorded samples below count toward the report. A failed
925 # warm-up aborts the scenario: later runs must never use an
926 # uninitialized profile.
927 warmup = run_sample(args.binary, args.cef_dir, args.scenario, args.fixture,
928 0, shared_root_cache=shared_root_cache,
929 idle_timeout_ms=args.idle_timeout_ms)
930 if not warmup["complete"]:
931 print("measure: process-warm warm-up was incomplete", file=sys.stderr)
932 raise SystemExit(1)
933 warmup_discarded = True
934 for index in range(1, args.runs + 1):
935 result = run_sample(
936 args.binary, args.cef_dir, args.scenario, args.fixture, index,
937 owner=owner, owner_dirs=owner_dirs, shared_root_cache=shared_root_cache,
938 owner_socket=owner_socket, idle_timeout_ms=args.idle_timeout_ms,
939 )
940 results.append(result)
941 with open(os.path.join(args.output, "run-%02d.json" % index), "w") as handle:
942 json.dump(result, handle, indent=2, sort_keys=True)
943 finally:
944 stop_proc(owner)
945
946 summary = {
947 "binary_sha256": binary_sha256,
948 "scenario": args.scenario,
949 "fixture": args.fixture,
950 "runs": len(results),
951 "complete_runs": sum(1 for r in results if r["complete"]),
952 "incomplete_runs": sum(1 for r in results if not r["complete"]),
953 "duplicate_document_runs": sum(
954 1
955 for r in results
956 if r["document_requests"] != (2 if args.fixture == "redirect" else 1)
957 ),
958 "warmup_discarded": warmup_discarded,
959 "relay_owner_ready": owner is not None,
960 "idle_timeout_ms": args.idle_timeout_ms,
961 }
962 if args.scenario in ("relay-window", "reopen-window") and owner_dirs is not None:
963 # Second-window contract, kept separate from cold-process numbers:
964 # one owner CEF init total, plus the request-to-FCP distribution
965 # of resident reopens. Missing FCP stays missing, never averaged in.
966 try:
967 with open(owner_dirs.get("owner_log", ""), errors="replace") as owner_log:
968 summary["owner_cef_init_count"] = count_cef_inits(owner_log)
969 except OSError:
970 summary["owner_cef_init_count"] = None
971 fcp_observations = sorted(
972 r["first_document_observation_ms"]
973 for r in results
974 if r.get("residency_valid") and r["first_document_observation_ms"] is not None
975 )
976 summary["resident_valid_runs"] = sum(1 for r in results if r.get("residency_valid"))
977 summary["resident_invalid_runs"] = sum(1 for r in results if r.get("residency_valid") is False)
978 summary["second_window_complete_runs"] = len(fcp_observations)
979 if fcp_observations:
980 # Spawn to first document request, same harness clock. This is
981 # request arrival, not document completion or paint; for the
982 # redirect fixture it measures the initial redirect request.
983 summary["second_window_spawn_to_first_document_observation_ms"] = {
984 "min": fcp_observations[0],
985 "median": fcp_observations[len(fcp_observations) // 2],
986 "max": fcp_observations[-1],
987 }
988 with open(os.path.join(args.output, "summary.json"), "w") as handle:
989 json.dump(summary, handle, indent=2, sort_keys=True)
990 print("measure artifacts: %s" % args.output)
991
992
993if __name__ == "__main__":
994 main()