"""Diagnostic: trace MLS broadcast event delivery through the WASM relay-proxy. Publishes a kind 1059 event to a local relay and traces whether the browser's relay-proxy receives and dispatches it. Uses native mlstest binary for signing. Run: ./test/run.sh -k mls_broadcast --headed -s """ import json import os import signal import subprocess import time import pytest from selenium import webdriver from selenium.webdriver.common.by import By from selenium.webdriver.firefox.options import Options from selenium.webdriver.firefox.service import Service from selenium.webdriver.support.ui import WebDriverWait from conftest import Helpers, RELAY_BIN, STATIC_DIR PROJECT_ROOT = os.path.dirname(os.path.dirname(os.path.abspath(__file__))) MLSTEST_BIN = os.path.join(PROJECT_ROOT, "mlstest") MLS_DATA_DIR = "/tmp/smesh-mlsbcast-test" MLS_PORT = 23336 def _start_relay(): if not os.path.exists(RELAY_BIN): pytest.skip(f"Relay binary not found: {RELAY_BIN}") if os.path.exists(MLS_DATA_DIR): subprocess.run(["rm", "-rf", MLS_DATA_DIR], check=True) os.makedirs(MLS_DATA_DIR, exist_ok=True) env = os.environ.copy() env["ORLY_DATA_DIR"] = MLS_DATA_DIR env["ORLY_LISTEN"] = "127.0.0.1" env["ORLY_PORT"] = str(MLS_PORT) env["ORLY_STATIC_DIR"] = STATIC_DIR env["ORLY_HTTP_GUARD_ENABLED"] = "false" env["ORLY_MARMOT_OPEN"] = "true" proc = subprocess.Popen( [RELAY_BIN], env=env, stdout=subprocess.PIPE, stderr=subprocess.PIPE ) import urllib.request url = f"http://127.0.0.1:{MLS_PORT}" for _ in range(30): try: urllib.request.urlopen(url, timeout=1) break except Exception: time.sleep(0.2) else: proc.kill() pytest.fail("Relay failed to start") return {"proc": proc, "url": url, "ws": f"ws://127.0.0.1:{MLS_PORT}"} def _stop_relay(info): proc = info["proc"] if proc.poll() is not None: stderr = proc.stderr.read().decode(errors="replace") if stderr: print(f"\n=== RELAY STDERR ===\n{stderr[-3000:]}\n=== END ===\n") return proc.send_signal(signal.SIGTERM) try: proc.wait(timeout=5) except subprocess.TimeoutExpired: proc.kill() def _make_browser(headed): opts = Options() if not headed: opts.add_argument("--headless") opts.set_preference("xpinstall.signatures.required", False) opts.set_preference("extensions.autoDisableScopes", 0) opts.set_preference("devtools.console.stdout.content", True) svc = Service(log_output="/dev/null") driver = webdriver.Firefox(options=opts, service=svc) driver.set_page_load_timeout(60) driver.set_script_timeout(30) driver.implicitly_wait(3) return driver def _bech32_encode(hrp, data_bytes): CHARSET = "qpzry9x8gf2tvdw0s3jn54khce6mua7l" def convertbits(data, frombits, tobits, pad=True): acc, bits, ret = 0, 0, [] maxv = (1 << tobits) - 1 for value in data: acc = (acc << frombits) | value bits += frombits while bits >= tobits: bits -= tobits ret.append((acc >> bits) & maxv) if pad and bits: ret.append((acc << (tobits - bits)) & maxv) return ret def polymod(values): GEN = [0x3b6a57b2, 0x26508e6d, 0x1ea119fa, 0x3d4233dd, 0x2a1462b3] chk = 1 for v in values: b = chk >> 25 chk = ((chk & 0x1ffffff) << 5) ^ v for i in range(5): chk ^= GEN[i] if ((b >> i) & 1) else 0 return chk def create_checksum(hrp, data): values = [ord(c) >> 5 for c in hrp] + [0] + [ord(c) & 31 for c in hrp] + data p = polymod(values + [0, 0, 0, 0, 0, 0]) ^ 1 return [(p >> 5 * (5 - i)) & 31 for i in range(6)] data5 = convertbits(list(data_bytes), 8, 5) checksum = create_checksum(hrp, data5) return hrp + "1" + "".join(CHARSET[d] for d in data5 + checksum) def _install_console_interceptor(driver): driver.execute_script(""" if (!window.__bcast_logs) { window.__bcast_logs = []; var origLog = console.log; var origWarn = console.warn; var origErr = console.error; console.log = function() { var msg = Array.prototype.slice.call(arguments).join(' '); window.__bcast_logs.push(msg); origLog.apply(console, arguments); }; console.warn = function() { var msg = '[WARN] ' + Array.prototype.slice.call(arguments).join(' '); window.__bcast_logs.push(msg); origWarn.apply(console, arguments); }; console.error = function() { var msg = '[ERROR] ' + Array.prototype.slice.call(arguments).join(' '); window.__bcast_logs.push(msg); origErr.apply(console, arguments); }; } """) def _get_logs(driver): return driver.execute_script("return window.__bcast_logs || [];") def _clear_logs(driver): driver.execute_script("window.__bcast_logs = [];") def _setup_user(driver, relay_url): """Load app, create vault with default identity, return hex pubkey.""" driver.get(relay_url) h = Helpers(driver) h.wait_wasm_ready() h.wait_signer_ready() pk = h.ensure_identity() assert pk and len(pk) == 64, f"Failed to get pubkey: {pk}" return pk @pytest.fixture def bcast_env(request): headed = request.config.getoption("--headed", default=False) if not os.path.exists(MLSTEST_BIN): pytest.skip(f"mlstest binary not found: {MLSTEST_BIN}") relay = _start_relay() driver = _make_browser(headed) yield {"relay": relay, "driver": driver} driver.quit() _stop_relay(relay) def test_mls_broadcast_trace(bcast_env): """Trace kind 1059 broadcast delivery through the WASM relay-proxy.""" relay = bcast_env["relay"] driver = bcast_env["driver"] url = relay["url"] ws_url = relay["ws"] # 1. Setup identity pk = _setup_user(driver, url) print(f"\nUser pubkey: {pk}") # 2. Install console interceptor _install_console_interceptor(driver) # 3. Navigate to DM with a dummy peer to trigger MLS subscription dummy_pk_bytes = bytes(range(1, 33)) dummy_npub = _bech32_encode("npub", dummy_pk_bytes) print(f"Navigating to /msg/{dummy_npub}") driver.get(f"{url}/msg/{dummy_npub}") time.sleep(3) # Re-install interceptor after navigation _install_console_interceptor(driver) # 4. Wait for MLS subscription to be established # The MLS worker boots, sends M_INIT, which triggers MLS_SUB to relay-proxy print("Waiting for MLS subscription...") time.sleep(5) # 5. Check logs so far logs_before = _get_logs(driver) print(f"\n=== Console logs after MLS setup ({len(logs_before)} entries) ===") for log in logs_before: if any(k in log for k in ["MLS", "mls", "relay-proxy", "M_INIT", "M_SUBSCRIBE", "M_INCOMING"]): print(f" {log}") print("=== end setup logs ===\n") # 6. Clear logs, publish kind 1059 from native tool _clear_logs(driver) print(f"Publishing kind 1059 with #p={pk} via mlstest...") result = subprocess.run( [MLSTEST_BIN, ws_url, pk], capture_output=True, text=True, timeout=15 ) print(f"mlstest stdout: {result.stdout.strip()}") print(f"mlstest stderr: {result.stderr.strip()}") assert result.returncode == 0, f"mlstest failed: {result.stderr}" # 7. Wait for broadcast to propagate time.sleep(3) # 8. Read console logs and check each stage logs_after = _get_logs(driver) print(f"\n=== Console logs after publish ({len(logs_after)} entries) ===") for log in logs_after: print(f" {log}") print("=== end publish logs ===\n") # 9. Diagnostic analysis has_mls_event = any("[wasm-host] relay-proxy -> MLS worker: M_INCOMING" in l for l in logs_after) has_mls_dropped = any("MLS_EVENT dropped" in l for l in logs_after) has_event_any = any("EVENT" in l for l in logs_after) print("=== DIAGNOSTIC RESULTS ===") print(f" MLS_EVENT received by supervisor and forwarded: {has_mls_event}") print(f" MLS_EVENT dropped (worker not booted): {has_mls_dropped}") print(f" Any EVENT-related log: {has_event_any}") if has_mls_event: print(" VERDICT: relay-proxy -> supervisor -> MLS worker chain is WORKING") print(" The broadcast delivery is functional. Bug is downstream in MLS worker.") elif has_mls_dropped: print(" VERDICT: relay-proxy sent MLS_EVENT but MLS worker was not booted") print(" Fix: ensure _ensureMlsWorker() is called before MLS subscriptions") elif has_event_any: print(" VERDICT: relay-proxy received events but did not dispatch MLS_EVENT") print(" Check: mlsSubIDs map, subscription ID matching, wireConn onEvent handler") else: print(" VERDICT: no event-related logs at all") print(" Possible causes:") print(" - relay-proxy WebSocket did not receive the broadcast") print(" - relay-proxy MLS subscription was not created") print(" - relay subscription uses wrong URL (ws vs wss mismatch)") print(" Check relay stderr for broadcast diagnostics") # 10. Also check relay stderr for broadcast diagnostic logs relay_proc = relay["proc"] # Don't wait for the process, just peek at any available stderr import select if hasattr(relay_proc.stderr, 'fileno'): r, _, _ = select.select([relay_proc.stderr], [], [], 0.5) if r: stderr_peek = relay_proc.stderr.read1(4096).decode(errors="replace") print(f"\n=== Relay stderr peek ===\n{stderr_peek}\n=== end ===") print("=== END DIAGNOSTIC ===") # The test passes regardless - it's diagnostic, not assertive # The output tells us where the chain breaks