/** * test_micropython_wifi_trace.mjs — Phase 7.1 reproduction + trace capture * * Drives the simulation backend WebSocket directly (bypasses the velxio * frontend's WiFi-stub prelude) and injects a minimal MicroPython * program that touches `network.WLAN(STA_IF)`. The QEMU build under * test has DEBUG=1 in hw/misc/esp32_wifi.c, esp32_phya.c, esp32_ana.c, * so every register read/write through those peripherals is fprintf'd * to the worker subprocess's stderr — which is piped to uvicorn and * shows up in `docker logs velxio-app` with the [esp32_worker] prefix. * * Expected outcome (pre-fix): chip hangs/reboots somewhere inside * network.WLAN(STA_IF), no `VLX_DONE` marker printed. Trace captures * the LAST register accesses before the hang — those are where the * emulation falls short. * * Run: * docker logs velxio-app --since 1s > /tmp/before.log 2>&1 * node --experimental-websocket test/test_micropython_wifi_trace/test.mjs \ * --backend=http://localhost:3080 --timeout=60 * docker logs velxio-app 2>&1 | grep -E '\[(wifi|phya|ana )\]' > /tmp/wifi-trace.log */ const BACKEND = process.env.BACKEND_URL ?? process.argv.find(a => a.startsWith('--backend='))?.slice(10) ?? 'http://localhost:3080'; const WS_BASE = BACKEND.replace(/^https?:/, m => m === 'https:' ? 'wss:' : 'ws:'); const SESSION = `test-mp-wifi-trace-${Date.now()}`; const TIMEOUT_S = parseInt( process.argv.find(a => a.startsWith('--timeout='))?.slice(10) ?? '60' ); const FIRMWARE_URL = 'https://micropython.org/resources/firmware/ESP32_GENERIC-20230426-v1.20.0.bin'; const FLASH_OFFSET = 0x1000; const FLASH_SIZE = 4 * 1024 * 1024; // Minimal program: import network + instantiate WLAN. That's it. // network.WLAN(STA_IF) is where MP triggers esp_wifi_init internally — // that's the call that hangs in unmodified picsimlab QEMU. const INJECT_CODE = [ 'print("VLX_PRE")', 'import network', 'from time import sleep', 'print("VLX_IMPORT_OK")', 'w = network.WLAN(network.STA_IF)', 'print("VLX_WLAN_OK")', 'w.active(True)', 'print("VLX_ACTIVE_OK")', 'print("VLX_STATUS", w.status())', 'print("VLX_CONFIG_MAC", w.config("mac"))', 'w.connect("ssid", "pass")', 'print("VLX_CONNECT_CALL_OK")', 'for i in range(5):', ' print("VLX_LOOP", i, "isconn=", w.isconnected())', ' sleep(0.5)', 'print("VLX_DONE")', ].join('\n'); const T0 = Date.now(); const ts = () => `[+${((Date.now() - T0) / 1000).toFixed(3)}s]`; const C = { INFO: '\x1b[36m', WARN: '\x1b[33m', ERROR: '\x1b[31m', OK: '\x1b[32m', RESET: '\x1b[0m', }; const log = (lvl, ...a) => console.log(`${C[lvl] ?? ''}${ts()} [${lvl}]${C.RESET}`, ...a); const info = (...a) => log('INFO', ...a); const ok = (...a) => log('OK', ...a); const warn = (...a) => log('WARN', ...a); const err = (...a) => log('ERROR', ...a); async function downloadFirmware() { info(`Downloading MicroPython firmware ...`); const res = await fetch(FIRMWARE_URL); if (!res.ok) throw new Error(`HTTP ${res.status}`); const bytes = new Uint8Array(await res.arrayBuffer()); ok(`Downloaded ${bytes.length} bytes`); return bytes; } function buildFlashImage(firmware) { const image = new Uint8Array(FLASH_SIZE).fill(0xFF); image.set(firmware, FLASH_OFFSET); return image; } const toBase64 = (bytes) => Buffer.from(bytes).toString('base64'); function runSimulation(firmware_b64) { return new Promise((resolve) => { const wsUrl = `${WS_BASE}/api/simulation/ws/${SESSION}`; info(`Connecting WebSocket → ${wsUrl}`); const ws = new WebSocket(wsUrl); const result = { replReady: false, codeInjected: false, markers: new Set(), reboot: false, systemEvents: [], wsCloseCode: null, timedOut: false, }; let replState = 'idle'; let serialBuf = ''; const globalTimer = setTimeout(() => { info(`Global timeout (${TIMEOUT_S}s)`); result.timedOut = true; try { ws.close(); } catch {} }, TIMEOUT_S * 1000); function sendCodeInRawRepl() { if (result.codeInjected) return; result.codeInjected = true; info('Stage 3: raw REPL confirmed → sending code (64-byte chunks)'); const codeBytes = Array.from(new TextEncoder().encode(INJECT_CODE)); const CHUNK = 64, DELAY = 150; let offset = 0; const sendChunk = () => { if (offset >= codeBytes.length) { setTimeout(() => { ws.send(JSON.stringify({ type: 'esp32_serial_input', data: { bytes: [0x04] } })); info('Ctrl+D sent — code executing'); }, 300); return; } const chunk = codeBytes.slice(offset, offset + CHUNK); ws.send(JSON.stringify({ type: 'esp32_serial_input', data: { bytes: chunk } })); offset += CHUNK; setTimeout(sendChunk, DELAY); }; sendChunk(); } ws.addEventListener('open', () => { ok('WebSocket connected'); ws.send(JSON.stringify({ type: 'start_esp32', data: { board: 'esp32', firmware_b64, sensors: [], wifi_enabled: true, // CRITICAL: must be true so QEMU adds the WiFi NIC }, })); info('Sent start_esp32 with wifi_enabled=true'); }); ws.addEventListener('message', ev => { let msg; try { msg = JSON.parse(ev.data); } catch { return; } const { type, data } = msg; if (type === 'system') { result.systemEvents.push(data); info(`system: ${JSON.stringify(data)}`); if (data?.event === 'reboot') { warn('!!! REBOOT detected (likely TWDT or panic)'); result.reboot = true; } return; } if (type === 'serial_output') { const text = data?.data ?? ''; serialBuf += text; for (const ch of text) process.stdout.write(ch); if (replState === 'idle' && serialBuf.includes('Type "help()"')) { replState = 'banner_seen'; info('Stage 1: banner seen → poking UART with \\r'); setTimeout(() => ws.send(JSON.stringify({ type: 'esp32_serial_input', data: { bytes: [0x0D] } })), 800); } if (replState === 'banner_seen' && serialBuf.includes('>>>')) { replState = 'prompt_seen'; result.replReady = true; serialBuf = ''; ok('Stage 2: >>> seen → sending Ctrl+A'); setTimeout(() => ws.send(JSON.stringify({ type: 'esp32_serial_input', data: { bytes: [0x01] } })), 200); } if (replState === 'prompt_seen' && serialBuf.includes('raw REPL')) { replState = 'raw_repl_entered'; serialBuf = ''; setTimeout(sendCodeInRawRepl, 200); } for (const m of ['VLX_PRE', 'VLX_IMPORT_OK', 'VLX_WLAN_OK', 'VLX_DONE']) { if (text.includes(m)) result.markers.add(m); } if (result.markers.has('VLX_DONE')) { ok('Reached VLX_DONE — test complete'); setTimeout(() => { try { ws.close(); } catch {} }, 400); } if (serialBuf.length > 4096) serialBuf = serialBuf.slice(-1024); } }); ws.addEventListener('close', ev => { clearTimeout(globalTimer); result.wsCloseCode = ev.code; info(`WebSocket closed (code=${ev.code})`); resolve(result); }); ws.addEventListener('error', ev => err('WebSocket error', ev.message ?? '')); }); } async function main() { console.log('\n' + '='.repeat(70)); console.log(' Phase 7.1 — MicroPython network.WLAN(STA_IF) trace capture'); console.log('='.repeat(70) + '\n'); info(`Backend: ${BACKEND}`); info(`Timeout: ${TIMEOUT_S}s`); const fw = await downloadFirmware(); const image = buildFlashImage(fw); const b64 = toBase64(image); const r = await runSimulation(b64); console.log('\n' + '─'.repeat(70)); console.log(' Results'); console.log('─'.repeat(70)); console.log(` REPL ready: ${r.replReady}`); console.log(` Code injected: ${r.codeInjected}`); console.log(` Markers reached: ${JSON.stringify([...r.markers])}`); console.log(` System reboot: ${r.reboot}`); console.log(` System events: ${r.systemEvents.length}`); console.log(` WS close code: ${r.wsCloseCode ?? '(open)'}`); console.log(` Timed out: ${r.timedOut}`); console.log('─'.repeat(70) + '\n'); console.log('Now run:'); console.log(` docker logs velxio-app 2>&1 | grep -E '\\[(wifi|phya|ana )\\]' | tail -200`); console.log('to see the captured WiFi register trace.\n'); process.exit(r.markers.has('VLX_DONE') ? 0 : 1); } main().catch(e => { err('Fatal:', e.message); process.exit(2); });