diff --git a/test/test_official_console_acceptance.py b/test/test_official_console_acceptance.py index 292fc011b..84c0d26ca 100644 --- a/test/test_official_console_acceptance.py +++ b/test/test_official_console_acceptance.py @@ -19,6 +19,49 @@ acceptance = importlib.util.module_from_spec(spec) spec.loader.exec_module(acceptance) +class UsbLoggingReplyTests(unittest.TestCase): + PRIMARY = "primary USB serial port (tty/COM name is host-assigned)" + DEDICATED = "dedicated USB CDC 1, interface 02 (Linux: *-if02; tty/COM name is host-assigned)" + + def test_infrastructure_and_exact_companion_getters_preserve_each_mode(self): + for mode in ("off", "on", "stream"): + replies = ("> " + mode, + f"usb.logging {mode}; port: {self.PRIMARY}", + f"usb.logging {mode}; port: {self.DEDICATED}") + for reply in replies: + with self.subTest(mode=mode, reply=reply): + self.assertEqual(acceptance.usb_logging_mode(reply), mode) + acceptance.require_usb_logging_mode(reply, mode, "mode_mismatch") + + def test_wrong_live_mode_remains_a_failure_for_initial_and_reopen_checks(self): + for error_code in ("logging_mode_must_be_preconfigured", "logging_mode_changed"): + for actual in ("on", "stream"): + for reply in ("> " + actual, f"usb.logging {actual}; port: {self.PRIMARY}"): + with self.subTest(error_code=error_code, actual=actual), \ + self.assertRaisesRegex(RuntimeError, "^" + error_code + "$"): + acceptance.require_usb_logging_mode(reply, "off", error_code) + + def test_malformed_pending_or_unrelated_replies_are_rejected_without_echoing_input(self): + invalid = (None, "", "off", "> OFF", "> off trailing", "OK - USB logging off (saved)", + "usb.logging off", "usb.logging off; port: unknown private endpoint", + f"usb.logging off; port: {self.PRIMARY} (reboot required to change USB interfaces)", + f"usb.logging off; port: {self.PRIMARY}\n> on", + f"usb.logging off; port: {self.PRIMARY} ", + f"> usb.logging off; port: {self.PRIMARY}") + for reply in invalid: + with self.subTest(reply=reply), \ + self.assertRaisesRegex(RuntimeError, "^usb_logging_reply_format_unrecognized$"): + acceptance.usb_logging_mode(reply) + + def test_companion_port_descriptions_match_the_shipping_source(self): + root = HIL.parents[1] + source = (root / "src/helpers/UsbLogging.cpp").read_text() + companion = (root / "examples/companion_radio/MyMesh.cpp").read_text() + self.assertIn('return "' + self.PRIMARY + '";', source) + self.assertIn('return "' + self.DEDICATED + '";', source) + self.assertIn('"usb.logging %s; port: %s%s"', companion) + + class OwnedStartupTests(unittest.TestCase): def fixture(self, *, fail_first_page=False, wrong_profile=False, pages=1): requests, sockets, connections = [], [], [] @@ -248,6 +291,76 @@ class SafeJavaScriptFailureTests(unittest.TestCase): self.assertEqual(error.safe_details["message_sha256"], acceptance.hashlib.sha256(message.encode()).hexdigest()) self.assertNotIn("secret", str(error) + json.dumps(error.safe_details)) + @unittest.skipUnless(shutil.which("node"), "Node required for offline PAGE protocol test") + def test_companion_handshakes_reopen_and_logging_gate_without_idle_writes(self): + script = acceptance.PAGE.split('', 1)[0] + script = script.replace("import {SerialConsole} from './console.js';", "") + setup = r''' +import assert from 'node:assert/strict'; +globalThis.window=globalThis; +Object.defineProperty(globalThis,'navigator',{value:{serial:{getPorts:async()=>[ + {getInfo:()=>({usbVendorId:0x303a,usbProductId:0x1001})} +]}}}); +const realTimeout=globalThis.setTimeout; +globalThis.setTimeout=(fn,ms)=>realTimeout(fn,[10000,5000].includes(ms)?5:ms); +let mode='binary',dropStopAck=false,closed=0; +const sent=[]; +class SerialConsole { + constructor(port){this.port=port;this.connected=false;} + async connect(){this.connected=true;} + async disconnect(){this.connected=false;++closed;} + async reset(){throw Error('reset_must_never_be_called');} + async sendCommand(command){ + sent.push(command); + if(command==='+++MESHCORE-TERM-START') {mode='ascii';return;} + if(command==='+++MESHCORE-TERM-STOP') { + assert.equal(mode,'ascii');mode='binary'; + if(!dropStopAck)this.onOutput('OK - Binary mode\n'); + return; + } + if(mode!=='ascii')return; + this.onOutput('> '+command+'\n');this.onOutput(' -> bench reply\n'); + } +} +''' + checks = r''' +// Direct remains inert and cannot accidentally make a binary Companion ASCII. +await hil.open(0x303a,0x1001); +assert.deepEqual(sent,[]); +await assert.rejects(hil.query('board'),/framed_reply_deadline/); +await hil.close(); +const start=sent.length; +for(let open=0;open<2;++open){ + await hil.open(0x303a,0x1001,'companion'); + assert.equal(sent.at(-1),'+++MESHCORE-TERM-START'); + assert.equal((await hil.query('board')).body,'bench reply'); + hil.loggingMode='off'; // Actual Python path sets this from the strict getter. + const writes=hil.writes,setup=hil.setup_writes; + await hil.idle(0); + assert.equal(hil.writes,writes);assert.equal(hil.setup_writes,setup); + const result=await hil.close(); + assert.equal(result.binary_mode_restored,true);assert.equal(mode,'binary'); +} +assert.deepEqual(sent.slice(start),[ + '+++MESHCORE-TERM-START','board','+++MESHCORE-TERM-STOP', + '+++MESHCORE-TERM-START','board','+++MESHCORE-TERM-STOP']); +assert.equal(hil.setup_writes,4); +await hil.open(0x303a,0x1001,'companion'); +hil.loggingMode='on'; +const before=sent.length; +assert.equal((await hil.close()).binary_mode_restored,false); +assert.equal(sent.length,before);assert.equal(mode,'ascii'); +// Missing ACK is failure, but cannot prevent owned native streams closing. +await hil.open(0x303a,0x1001,'companion'); +hil.loggingMode='off';dropStopAck=true; +const closedBefore=closed; +await assert.rejects(hil.close(),/terminal_mode_exit_deadline/); +assert.equal(closed,closedBefore+1);assert.equal(hil.client,null); +''' + ran = subprocess.run([shutil.which("node"), "--input-type=module", "-"], + input=setup + script + checks, capture_output=True, text=True, timeout=10) + self.assertEqual(ran.returncode, 0, ran.stderr) + @unittest.skipUnless(shutil.which("node"), "Node required for offline PAGE protocol test") def test_page_accepts_exact_prompt_echo_and_requires_complete_response(self): # Execute the actual PAGE module body with an inert SDK-shaped class. diff --git a/tools/hil/official_console_acceptance.py b/tools/hil/official_console_acceptance.py index b1a32a1a4..cd675607b 100755 --- a/tools/hil/official_console_acceptance.py +++ b/tools/hil/official_console_acceptance.py @@ -33,8 +33,11 @@ PAGE = r'''Native official console a <script type="module"> import {SerialConsole} from './console.js'; window.hil = {ready:false, client:null, task:null, writes:0, replies:0, - pending:null, disconnected:false}; -hil.open = async function(vid,pid) { + setup_writes:0, pending:null, controlPending:null, disconnected:false, + terminalMode:'direct', loggingMode:null}; +hil.open = async function(vid,pid,terminalMode='direct') { + if(!['direct','companion'].includes(terminalMode)) throw Error('invalid_terminal_mode'); + hil.terminalMode=terminalMode;hil.loggingMode=null; const ports=await navigator.serial.getPorts(); if(ports.length!==1) throw Error('exactly_one_pregranted_native_port_required'); const info=ports[0].getInfo(); @@ -45,6 +48,10 @@ hil.open = async function(vid,pid) { // A terminal prompt and the subsequent input echo share a CRLF line. // Accept that exact prefix as well as the bare echo after a fresh open. const line=text.replace(/\r?\n$/, ''); + if(hil.controlPending && line==='OK - Binary mode' && text.endsWith('\n')) { + const waiter=hil.controlPending;hil.controlPending=null; + clearTimeout(waiter.timer);waiter.resolve(); + } if(hil.pending && (line===hil.pending.command || line==='> '+hil.pending.command || line==='>'+hil.pending.command)) hil.pending.echo_seen=true; // The unmodified official CRLF transformer delivers these complete lines. @@ -60,6 +67,12 @@ hil.open = async function(vid,pid) { if(hil.disconnected||performance.now()>end) throw Error('native_console_open_failed'); await new Promise(resolve=>setTimeout(resolve,10)); } + if(terminalMode==='companion') { + ++hil.writes;++hil.setup_writes; + // The shipping binary parser consumes this exact CRLF control sequence + // and leaves following bytes buffered for its ASCII terminal consumer. + await hil.client.sendCommand('+++MESHCORE-TERM-START'); + } return {native_ports:ports.length, connected:hil.client.connected}; }; hil.query = async function(command) { @@ -84,9 +97,28 @@ hil.idle = async function(seconds) { connected:hil.client.connected}; }; hil.close = async function() { - if(hil.client) {await hil.client.disconnect();await hil.task;} - hil.client=null;hil.task=null;hil.disconnected=false; - return {native_streams_closed:true}; + let binary_mode_restored=false; + try { + // Only a successfully queried logging-OFF Companion can return to binary. + // A primary logging-ON stream must remain an ASCII logging terminal. + if(hil.client?.connected && hil.terminalMode==='companion' && hil.loggingMode==='off') { + const confirmed=new Promise((resolve,reject)=>{ + const timer=setTimeout(()=>{hil.controlPending=null;reject(Error('terminal_mode_exit_deadline'));},5000); + hil.controlPending={resolve,reject,timer}; + }); + ++hil.writes;++hil.setup_writes; + try {await hil.client.sendCommand('+++MESHCORE-TERM-STOP');} + catch(error) { + if(hil.controlPending){clearTimeout(hil.controlPending.timer);hil.controlPending=null;} + throw error; + } + await confirmed;binary_mode_restored=true; + } + } finally { + try {if(hil.client) {await hil.client.disconnect();await hil.task;}} + finally {hil.client=null;hil.task=null;hil.disconnected=false;} + } + return {native_streams_closed:true,binary_mode_restored}; }; hil.ready=true; </script>''' @@ -170,6 +202,29 @@ def require(condition, message): raise RuntimeError(message) +def usb_logging_mode(reply): + """Normalize the exact infrastructure and Companion getter replies. + + A pending interface restart is deliberately rejected: the requested live + logging mode must already be configured before this read-only idle test. + """ + if reply in ("> off", "> on", "> stream"): + return reply[2:] + ports = ( + "primary USB serial port (tty/COM name is host-assigned)", + "dedicated USB CDC 1, interface 02 (Linux: *-if02; tty/COM name is host-assigned)", + ) + if isinstance(reply, str): + for mode in ("off", "on", "stream"): + if any(reply == f"usb.logging {mode}; port: {port}" for port in ports): + return mode + raise RuntimeError("usb_logging_reply_format_unrecognized") + + +def require_usb_logging_mode(reply, expected, error_code): + require(usb_logging_mode(reply) == expected, error_code) + + def sha256(path): digest = hashlib.sha256() with open(path, "rb") as stream: @@ -387,7 +442,7 @@ def execute(args, report): time.sleep(0.1) require(page.evaluate("!!window.hil?.ready"), "official_module_did_not_load") report["phase"] = "native_serial_open" - page.evaluate(f"hil.open({device.vid},{device.pid})") + page.evaluate(f"hil.open({device.vid},{device.pid},{json.dumps(args.terminal_mode)})") def query(command): report["phase"] = "native_query:" + command @@ -400,9 +455,10 @@ def execute(args, report): board, _ = query("board") version, _ = query("ver") logging, _ = query("get usb.logging") + page.evaluate("hil.loggingMode=" + json.dumps(usb_logging_mode(logging))) require(board == args.expected_board, "runtime_board_mismatch") require(version == args.expected_version, "runtime_version_mismatch") - require(logging == "> " + args.logging, "logging_mode_must_be_preconfigured") + require_usb_logging_mode(logging, args.logging, "logging_mode_must_be_preconfigured") before, _ = query("stats-core") before = json.loads(before) report["before"] = before @@ -422,17 +478,21 @@ def execute(args, report): report["phase"] = "native_serial_first_close" report["first_close"] = page.evaluate("hil.close()") report["phase"] = "native_serial_reopen" - page.evaluate(f"hil.open({device.vid},{device.pid})") + page.evaluate(f"hil.open({device.vid},{device.pid},{json.dumps(args.terminal_mode)})") reopened, elapsed = query("stats-core") reopened = json.loads(reopened) require(reopened["uptime_secs"] >= after["uptime_secs"], "reopen_reset_or_uptime_regression") require(query("board")[0] == args.expected_board and query("ver")[0] == args.expected_version, "runtime_identity_changed_on_reopen") - require(query("get usb.logging")[0] == "> " + args.logging, "logging_mode_changed") + reopened_logging = query("get usb.logging")[0] + page.evaluate("hil.loggingMode=" + json.dumps(usb_logging_mode(reopened_logging))) + require_usb_logging_mode(reopened_logging, args.logging, "logging_mode_changed") report.update(reopened=reopened, reopened_reply_ms=elapsed, command_writes=page.evaluate("hil.writes"), complete_CRLF_replies=page.evaluate("hil.replies")) report["phase"] = "native_serial_final_close" report["final_close"] = page.evaluate("hil.close()") + report.update(command_writes=page.evaluate("hil.writes"), + setup_writes=page.evaluate("hil.setup_writes")) report["native_streams_closed"] = True report["phase"] = "complete" finally: @@ -454,6 +514,8 @@ def main(argv=None): parser.add_argument("--expected-board", required=True) parser.add_argument("--expected-version", required=True, help="Exact full ver reply, including Build suffix") parser.add_argument("--logging", choices=("on", "off"), required=True) + parser.add_argument("--terminal-mode", choices=("direct", "companion"), default="direct", + help="Companion sends the shipping TERM-START on every open and TERM-STOP on logging-OFF close") parser.add_argument("--idle-seconds", type=int, default=600) parser.add_argument("--console-source", type=Path, required=True) parser.add_argument("--artifact-manifest", type=Path, required=True) @@ -469,6 +531,8 @@ def main(argv=None): parser.error("serial must be an exact single-line USB identity") if not args.execute: print(json.dumps({"execute": False, "idle_seconds": args.idle_seconds, + "terminal_mode": args.terminal_mode, + "Companion_handoff_writes_outside_idle": args.terminal_mode == "companion", "console_sha256": CONSOLE_SHA256, "native_WebSerial": True, "commands": ["board", "ver", "get usb.logging", "stats-core"], "settings_mutation": False, "reset_hooks": False})) @@ -482,6 +546,7 @@ def main(argv=None): "started_utc": datetime.now(timezone.utc).isoformat(), "scope": "pinned-official-console-native-WebSerial-open-idle-reopen", "settings_mutation": False, "reset_hooks": False, + "terminal_mode": args.terminal_mode, "firmware_artifact_binding": "external manifest plus exact runtime board/version; no flash read"} status = 1 try: