diff --git a/test/test_micropython_i2c_minimal/README.md b/test/test_micropython_i2c_minimal/README.md new file mode 100644 index 00000000..cd7060ef --- /dev/null +++ b/test/test_micropython_i2c_minimal/README.md @@ -0,0 +1,80 @@ +# test_micropython_i2c_minimal + +Phase 1 reproduction test for the MicroPython + I2C reboot bug on ESP32 QEMU. + +## Why this exists + +The example `100d-esp32-oled-smart-ui-eyes-animation-time-and-weather-micropython` +reboots the ESP32 silently when MicroPython touches `machine.I2C(0, ...)`. +Arduino C++ + `Wire.h` works on the same OLED. Hypothesis (see +`velxio-prod/project/phase-06-esp32-micropython-i2c-fix.md`): the picsimlab +QEMU emulation never raises the `tx_done` IRQ that the ESP-IDF i2c_master +driver waits on → MicroPython hangs → watchdog timeout → soft reset. + +This test runs the **smallest possible** MicroPython program that hits the +hardware I2C peripheral, with NO ssd1306 driver and NO helper libraries, +so we can confirm the bug is at the QEMU / firmware boundary (not in the +OLED driver or the example's code). + +## What it does + +1. Downloads MicroPython v1.20.0 firmware (same one the velxio frontend ships). +2. Builds a 4 MB flash image with the firmware at offset 0x1000. +3. Opens a WebSocket to `BACKEND/api/simulation/ws/`. +4. Sends `start_esp32` with the firmware + a registered SSD1306 slave at 0x3C. +5. Once the REPL prompt appears, injects the minimal program via raw-REPL + Ctrl+D: + ```python + from machine import Pin, I2C + print("velxio_i2c_pre") + i2c = I2C(0, scl=Pin(22), sda=Pin(21)) + print("velxio_i2c_ctor_ok") + devs = i2c.scan() + print("velxio_i2c_scan_ok", devs) + try: + i2c.writeto(0x3C, b"\xA0") + print("velxio_i2c_write_ok") + except OSError as e: + print("velxio_i2c_write_err", e) + print("velxio_i2c_done") + ``` +6. Watches the serial output + system events. Reports the LAST marker + reached (`pre`, `ctor_ok`, `scan_ok`, `write_ok`/`write_err`, `done`) + to localize exactly which I2C call triggers the reboot. + +## Expected outcomes + +| Before the fix | After the fix | +|---|---| +| Markers stop at `ctor_ok` or `scan_ok` | All 4 markers + `done` reached | +| `system: {event: reboot}` event arrives | No reboot event | +| WebSocket closes with code 1006 within ~5s of running | Test completes cleanly | + +## How to run + +Backend must be running at `http://localhost:8001` (default) — on the prod +server with `docker compose up -d`. + +```bash +cd /home/dave/velxio-prod/velxio +node test/test_micropython_i2c_minimal/test.mjs +``` + +Optional flags: +- `--timeout=60` (default 60s) +- `--backend=http://localhost:8001` + +Exit code 0 = full success (all markers + done). Non-zero = reboot or +incomplete. The report block at the end summarizes which marker was the +LAST one reached, which localizes the bug. + +## Related files + +- `velxio/test/backend/e2e/test_micropython_esp32.mjs` — the upstream + template this is based on (boots MicroPython + injects a sanity check; + doesn't touch I2C). +- `velxio/backend/app/services/esp32_worker.py` — `_on_i2c_event` + callback (line ~928) that QEMU invokes per I2C event. +- `velxio/backend/app/services/esp32_i2c_slaves.py` — `I2CWriteSink` + (line ~309) is what the SSD1306 slave registration uses. +- `velxio-prod/project/phase-06-esp32-micropython-i2c-fix.md` — phase + tracking + plan. diff --git a/test/test_micropython_i2c_minimal/test.mjs b/test/test_micropython_i2c_minimal/test.mjs new file mode 100644 index 00000000..8fb7977b --- /dev/null +++ b/test/test_micropython_i2c_minimal/test.mjs @@ -0,0 +1,334 @@ +/** + * test_micropython_i2c_minimal.mjs — Phase 1 reproduction test + * + * Boots ESP32 MicroPython via velxio QEMU, registers an SSD1306 I2C slave + * at 0x3C, then runs the SMALLEST possible MicroPython program that + * touches `machine.I2C(0, ...).scan()` and writes one byte. The goal is + * to confirm in isolation (no SSD1306 driver, no helper libs) that the + * reboot reproduces, narrowing the bug to the QEMU I2C peripheral + * emulation itself (not the ssd1306.py driver or the example's main.py). + * + * EXPECTED FAIL (before the QEMU fix lands): + * - REPL boots, code injection succeeds + * - Right after `i2c = I2C(0, ...)` the chip reboots (system event=reboot) + * - WebSocket closes with code 1006 + * + * EXPECTED PASS (after the fix): + * - `i2c.scan()` returns `[60]` (0x3C — the registered SSD1306 slave) + * - `i2c.writeto(0x3C, b'\\x00')` returns OK (no OSError) + * - `velxio_i2c_done` marker printed + * - No reboot, no premature WS close + * + * Heavily based on `test/backend/e2e/test_micropython_esp32.mjs` (same + * firmware download + 4 MB flash image + raw-REPL injection state machine). + * + * Run: + * node test/test_micropython_i2c_minimal/test.mjs [--timeout=60] [--backend=http://localhost:8001] + */ + +// ─── Config ─────────────────────────────────────────────────────────────────── +const BACKEND = process.env.BACKEND_URL + ?? process.argv.find(a => a.startsWith('--backend='))?.slice(10) + ?? 'http://localhost:8001'; +const WS_BASE = BACKEND.replace(/^https?:/, m => m === 'https:' ? 'wss:' : 'ws:'); +const SESSION = `test-mp-i2c-${Date.now()}`; +const TIMEOUT_S = parseInt( + process.argv.find(a => a.startsWith('--timeout='))?.slice(10) ?? '60' +); + +// Same MicroPython firmware as the frontend ships +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 I2C test — no ssd1306 driver, no helper libs. Just touches the +// hardware I2C peripheral the same way ssd1306.py does on its first +// write. Each step prints a tag so we can pinpoint which call rebooted. +const INJECT_CODE = [ + 'from machine import Pin, I2C', + 'print("velxio_i2c_pre")', // marker before I2C touch + 'i2c = I2C(0, scl=Pin(22), sda=Pin(21))', + 'print("velxio_i2c_ctor_ok")', // ctor survived + 'devs = i2c.scan()', + 'print("velxio_i2c_scan_ok", devs)', // scan survived + result + 'try:', + ' i2c.writeto(0x3C, b"\\xA0")', // single byte write — same as ssd1306 init does first + ' print("velxio_i2c_write_ok")', // write survived + 'except OSError as e:', + ' print("velxio_i2c_write_err", e)', + 'print("velxio_i2c_done")', +].join('\n'); + +// ─── Logging ────────────────────────────────────────────────────────────────── +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', SERIAL: '\x1b[35m', 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); +const serial = (...a) => log('SERIAL', ...a); + +// ─── Firmware fetch + 4MB flash image (copied from test_micropython_esp32.mjs) ─ +async function downloadFirmware() { + info(`Downloading MicroPython firmware from ${FIRMWARE_URL} ...`); + const ctrl = new AbortController(); + const t = setTimeout(() => ctrl.abort(), 60_000); + try { + const res = await fetch(FIRMWARE_URL, { signal: ctrl.signal }); + if (!res.ok) throw new Error(`HTTP ${res.status}`); + const bytes = new Uint8Array(await res.arrayBuffer()); + clearTimeout(t); + ok(`Downloaded ${bytes.length} bytes`); + return bytes; + } finally { clearTimeout(t); } +} + +function buildFlashImage(firmware) { + const image = new Uint8Array(FLASH_SIZE).fill(0xFF); + image.set(firmware, FLASH_OFFSET); + if (image[FLASH_OFFSET] !== 0xE9) { + warn(`Unexpected magic at 0x${FLASH_OFFSET.toString(16)}: 0x${image[FLASH_OFFSET].toString(16)}`); + } + return image; +} + +const toBase64 = (bytes) => Buffer.from(bytes).toString('base64'); + +// ─── Simulation ─────────────────────────────────────────────────────────────── +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 markers = new Set(); + let replState = 'idle'; + let replReady = false; + let codeInjected = false; + let i2cScanResult = null; + let writeErr = null; + let serialBuf = ''; + let systemReboot = false; + let wsCloseCode = null; + const systemEvents = []; + + const globalTimer = setTimeout(() => { + info(`Global timeout (${TIMEOUT_S}s)`); + ws.close(); + finish({ timedOut: true }); + }, TIMEOUT_S * 1000); + + function finish(extra = {}) { + clearTimeout(globalTimer); + resolve({ + replReady, codeInjected, + markers: [...markers], + i2cScanResult, writeErr, + systemReboot, systemEvents, wsCloseCode, + ...extra, + }); + } + + function sendCodeInRawRepl() { + if (codeInjected) return; + 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, + // CRITICAL: register the SSD1306 slave at 0x3C so the worker + // ACKs the write. virtualPin = 200 + addr (per the ProtocolParts + // pattern in the frontend). + sensors: [{ sensor_type: 'ssd1306', pin: 200 + 0x3C, addr: 0x3C }], + wifi_enabled: false, + }, + })); + info('Sent start_esp32 with sensors=[{ssd1306@0x3C}]'); + }); + + ws.addEventListener('message', ev => { + let msg; + try { msg = JSON.parse(ev.data); } catch { return; } + const { type, data } = msg; + + if (type === 'system') { + systemEvents.push(data); + info(`system: ${JSON.stringify(data)}`); + if (data?.event === 'reboot' || data?.status === 'reboot' || String(data).includes('reboot')) { + warn('!!! ESP32 REBOOTED — this is the bug we are chasing'); + systemReboot = true; + } + return; + } + + if (type === 'serial_output') { + const text = data?.data ?? ''; + serialBuf += text; + for (const ch of text) process.stdout.write(ch); + + // 4-stage state machine (same as the frontend Esp32Bridge) + 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'; + 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); + } + + // Scan line-by-line for our injection markers + let nl; + while ((nl = serialBuf.indexOf('\n')) !== -1) { + const line = serialBuf.slice(0, nl).replace(/\r$/, ''); + serialBuf = serialBuf.slice(nl + 1); + if (!line.trim()) continue; + + // velxio_i2c_* markers tell us WHICH I2C call survived + if (line.includes('velxio_i2c_pre')) markers.add('pre'); + if (line.includes('velxio_i2c_ctor_ok')) markers.add('ctor_ok'); + if (line.includes('velxio_i2c_scan_ok')) { + markers.add('scan_ok'); + const m = line.match(/velxio_i2c_scan_ok\s+(.+)/); + if (m) i2cScanResult = m[1].trim(); + } + if (line.includes('velxio_i2c_write_ok')) markers.add('write_ok'); + if (line.includes('velxio_i2c_write_err')) { + markers.add('write_err'); + const m = line.match(/velxio_i2c_write_err\s+(.+)/); + if (m) writeErr = m[1].trim(); + } + if (line.includes('velxio_i2c_done')) markers.add('done'); + + if (line.includes('Traceback')) warn(`TRACEBACK: ${line}`); + } + + if (markers.has('done')) { + ok('Reached velxio_i2c_done — test complete'); + ws.close(); + finish(); + } + if (serialBuf.length > 4096) serialBuf = serialBuf.slice(-512); + return; + } + + if (type === 'error') { + err(`simulation error: ${JSON.stringify(data)}`); + return; + } + }); + + ws.addEventListener('close', ev => { + wsCloseCode = ev.code; + info(`WebSocket closed (code=${ev.code})`); + finish(); + }); + ws.addEventListener('error', ev => err('WebSocket error', ev.message ?? '')); + }); +} + +// ─── Main ───────────────────────────────────────────────────────────────────── +async function main() { + console.log('\n' + '='.repeat(70)); + console.log(' Phase 1 — MicroPython I2C minimal reproduction'); + console.log('='.repeat(70) + '\n'); + info(`Backend: ${BACKEND}`); + info(`Timeout: ${TIMEOUT_S}s`); + + let exitCode = 0; + try { + const fw = await downloadFirmware(); + const image = buildFlashImage(fw); + const b64 = toBase64(image); + info(`Flash image: ${Math.round(b64.length / 1024)} KB base64`); + + 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(` i2c.scan() result: ${r.i2cScanResult ?? '(never reached)'}`); + console.log(` i2c write error: ${r.writeErr ?? '(none)'}`); + console.log(` System reboot: ${r.systemReboot}`); + console.log(` WS close code: ${r.wsCloseCode ?? '(open)'}`); + console.log(` Timed out: ${r.timedOut ?? false}`); + console.log('─'.repeat(70) + '\n'); + + // Phase 1 diagnostic — we're not asserting PASS yet, we're collecting + // evidence of WHICH call rebooted. Use the marker set to localize. + const lastMarker = ['done','write_ok','write_err','scan_ok','ctor_ok','pre'] + .find(m => r.markers.includes(m)); + + if (r.systemReboot) { + const where = lastMarker + ? `AFTER reaching marker "${lastMarker}"` + : 'BEFORE any marker (very early — code injection may not have started)'; + console.log(`Bug LOCATION: ESP32 rebooted ${where}.`); + console.log(' → If lastMarker = "scan_ok": reboot triggered by writeto()'); + console.log(' → If lastMarker = "ctor_ok": reboot triggered by scan()'); + console.log(' → If lastMarker = "pre": reboot triggered by I2C() constructor'); + exitCode = 1; + } else if (!r.markers.includes('done')) { + warn('No reboot but test did not complete — likely a different bug. See serial output above.'); + exitCode = 1; + } else { + ok(`I2C path complete. scan=${r.i2cScanResult}, writeErr=${r.writeErr ?? 'none'}`); + if (r.i2cScanResult === '[60]' && !r.writeErr) { + ok('Phase 1 PASSED — I2C hardware fully functional'); + } else { + warn(`Phase 1 PARTIAL — scan returned ${r.i2cScanResult} (expected [60]), writeErr=${r.writeErr ?? 'none'}`); + exitCode = 1; + } + } + } catch (e) { + err(`Fatal: ${e.message}`); + console.error(e); + exitCode = 1; + } + process.exit(exitCode); +} + +main(); diff --git a/test/test_micropython_i2c_ssd1306_repro/test.mjs b/test/test_micropython_i2c_ssd1306_repro/test.mjs new file mode 100644 index 00000000..d2fbdd32 --- /dev/null +++ b/test/test_micropython_i2c_ssd1306_repro/test.mjs @@ -0,0 +1,351 @@ +/** + * test_micropython_i2c_ssd1306_repro.mjs — Phase 1b reproduction test + * + * Phase 1 (test_micropython_i2c_minimal) confirmed that I2C(0,...), scan(), + * and a single-byte writeto(0x3C, b"\xA0") all work without rebooting. + * The bug must be triggered by something more specific that ssd1306.py does. + * + * This test walks the SSD1306_I2C init sequence step by step and prints a + * marker after every write, so we can see EXACTLY which call is the last + * one before the chip resets. + * + * What ssd1306.SSD1306_I2C(128, 64, i2c) does on construction: + * - For each cmd in a 27-entry init list: + * i2c.writeto(0x3C, bytes([0x80, cmd])) # 2-byte writes + * - self.fill(0) # framebuffer fill, no I2C + * - self.show() + * - 6× writeto(0x3C, bytes([0x80, addr_cmd])) # set col/page addrs + * - i2c.writevto(0x3C, [b"\x40", buffer]) # 1024-byte data dump + * + * Markers (last one printed = the suspect): + * mp_step0_ok — I2C ctor + * mp_step1_ok devs=… — scan + * mp_step2_ok — 2-byte writeto (cmd shape) + * mp_step3_iter N cmd=0xXX — each cmd of the 27-cmd init loop + * mp_step3_ok after_idx=27 — full init survived + * mp_step4_ok — show() prelude (6× addr writes) + * mp_step5_ok — writevto with small payload (8 bytes) + * mp_step6_ok — writevto with full framebuffer (1024 bytes) + * mp_done — all good, no reboot + * + * Run: + * node --experimental-websocket test/test_micropython_i2c_ssd1306_repro/test.mjs \ + * --backend=http://localhost:3080 [--timeout=120] + */ + +const BACKEND = process.env.BACKEND_URL + ?? process.argv.find(a => a.startsWith('--backend='))?.slice(10) + ?? 'http://localhost:8001'; +const WS_BASE = BACKEND.replace(/^https?:/, m => m === 'https:' ? 'wss:' : 'ws:'); +const SESSION = `test-mp-i2c-ssd1306-${Date.now()}`; +const TIMEOUT_S = parseInt( + process.argv.find(a => a.startsWith('--timeout='))?.slice(10) ?? '120' +); + +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; + +const INJECT_CODE = ` +from machine import Pin, I2C +import time + +ADDR = 0x3C +i2c = I2C(0, scl=Pin(22), sda=Pin(21)) +print("mp_step0_ok") + +devs = i2c.scan() +print("mp_step1_ok devs=" + str(devs)) + +# step 2: same shape ssd1306.write_cmd uses (2-byte writeto with 0x80 prefix) +i2c.writeto(ADDR, bytes([0x80, 0xAE])) +print("mp_step2_ok") + +# step 3: full 27-entry init sequence (verbatim from ssd1306.py for 128x64) +INIT = [ + 0xAE, # SET_DISP off + 0x20, 0x00, # SET_MEM_ADDR horizontal + 0x40, # SET_DISP_START_LINE | 0 + 0xA1, # SET_SEG_REMAP | 1 + 0xA8, 0x3F, # SET_MUX_RATIO 64-1 + 0xC8, # SET_COM_OUT_DIR | 8 + 0xD3, 0x00, # SET_DISP_OFFSET 0 + 0xDA, 0x12, # SET_COM_PIN_CFG 0x12 + 0xD5, 0x80, # SET_DISP_CLK_DIV + 0xD9, 0xF1, # SET_PRECHARGE + 0xDB, 0x30, # SET_VCOM_DESEL + 0x81, 0xFF, # SET_CONTRAST + 0xA4, # SET_ENTIRE_ON + 0xA6, # SET_NORM_INV + 0x8D, 0x14, # SET_CHARGE_PUMP + 0xAF, # SET_DISP on +] +for idx, cmd in enumerate(INIT): + i2c.writeto(ADDR, bytes([0x80, cmd])) + print("mp_step3_iter " + str(idx) + " cmd=0x" + ("%02x" % cmd)) +print("mp_step3_ok after_idx=" + str(len(INIT))) + +# step 4: 6 address commands (.show() prelude) +for cmd in (0x21, 32, 32 + 127, 0x22, 0, 7): + i2c.writeto(ADDR, bytes([0x80, cmd])) +print("mp_step4_ok") + +# step 5: writevto with small payload (8 bytes) +try: + i2c.writevto(ADDR, (b"\\x40", bytes([0]*8))) + print("mp_step5_ok") +except Exception as e: + print("mp_step5_err " + repr(e)) + +# step 6: writevto with full 1024-byte framebuffer payload +try: + i2c.writevto(ADDR, (b"\\x40", bytes([0]*1024))) + print("mp_step6_ok") +except Exception as e: + print("mp_step6_err " + repr(e)) + +print("mp_done") +`.trim(); + +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', SERIAL: '\x1b[35m', 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 from ${FIRMWARE_URL} ...`); + const ctrl = new AbortController(); + const t = setTimeout(() => ctrl.abort(), 60_000); + try { + const res = await fetch(FIRMWARE_URL, { signal: ctrl.signal }); + if (!res.ok) throw new Error(`HTTP ${res.status}`); + const bytes = new Uint8Array(await res.arrayBuffer()); + clearTimeout(t); + ok(`Downloaded ${bytes.length} bytes`); + return bytes; + } finally { clearTimeout(t); } +} + +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: [], + lastMarker: null, + step3Iters: 0, + step3LastCmd: null, + step5Status: null, + step6Status: null, + done: false, + reboot: false, + systemEvents: [], + wsCloseCode: null, + serialBuf: '', + 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); + + const finish = () => { + clearTimeout(globalTimer); + resolve(result); + }; + + 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: [{ sensor_type: 'ssd1306', pin: 200 + 0x3C, addr: 0x3C }], + wifi_enabled: false, + }, + })); + info('Sent start_esp32 with sensors=[{ssd1306@0x3C}]'); + }); + + 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' || data?.status === 'reboot') { + warn('!!! ESP32 REBOOTED — last marker before reboot: ' + (result.lastMarker || '(none)')); + result.reboot = true; + } + return; + } + + if (type === 'serial_output') { + const text = data?.data ?? ''; + serialBuf += text; + for (const ch of text) process.stdout.write(ch); + + // 4-stage REPL state machine + 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); + } + + // Parse markers line by line + let nl; + while ((nl = serialBuf.indexOf('\n')) !== -1) { + const line = serialBuf.slice(0, nl).replace(/\r$/, ''); + serialBuf = serialBuf.slice(nl + 1); + if (!line.trim()) continue; + + const m = line.match(/mp_(step\d|done)\w*(?:\s+(.+))?/); + if (m) { + const tag = 'mp_' + m[1] + (m[0].slice(3 + m[1].length).match(/^_[a-z]+/)?.[0] ?? ''); + const tail = (m[2] || '').trim(); + const full = tail ? `${tag} ${tail}` : tag; + result.markers.push(full); + result.lastMarker = full; + } + const iter = line.match(/mp_step3_iter (\d+) cmd=0x([0-9a-f]{2})/); + if (iter) { + result.step3Iters = parseInt(iter[1]) + 1; + result.step3LastCmd = '0x' + iter[2]; + } + if (line.includes('mp_step5_ok')) result.step5Status = 'ok'; + if (line.includes('mp_step5_err')) result.step5Status = line.slice(line.indexOf('mp_step5_err')); + if (line.includes('mp_step6_ok')) result.step6Status = 'ok'; + if (line.includes('mp_step6_err')) result.step6Status = line.slice(line.indexOf('mp_step6_err')); + if (line.includes('mp_done')) { + result.done = true; + setTimeout(() => { try { ws.close(); } catch {} finish(); }, 400); + } + if (line.includes('Traceback')) warn(`TRACEBACK: ${line}`); + } + if (serialBuf.length > 8192) serialBuf = serialBuf.slice(-1024); + return; + } + + if (type === 'error') { + err(`backend error: ${JSON.stringify(data)}`); + } + }); + + ws.addEventListener('close', ev => { + result.wsCloseCode = ev.code; + info(`WebSocket closed (code=${ev.code})`); + finish(); + }); + ws.addEventListener('error', ev => err('WebSocket error', ev.message ?? '')); + }); +} + +async function main() { + console.log('\n' + '='.repeat(70)); + console.log(' Phase 1b — SSD1306_I2C init sequence step-by-step reproduction'); + 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); + info(`Flash image: ${Math.round(b64.length / 1024)} KB base64`); + + 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(` Last marker: ${r.lastMarker ?? '(none)'}`); + console.log(` Step3 init iters OK: ${r.step3Iters} / 27`); + console.log(` Step3 last cmd OK: ${r.step3LastCmd ?? '(none)'}`); + console.log(` Step5 (writevto 8B): ${r.step5Status ?? '(not reached)'}`); + console.log(` Step6 (writevto 1KB): ${r.step6Status ?? '(not reached)'}`); + console.log(` System reboot: ${r.reboot}`); + console.log(` WS close code: ${r.wsCloseCode ?? '(open)'}`); + console.log(` Timed out: ${r.timedOut}`); + console.log('─'.repeat(70) + '\n'); + + if (r.done && !r.reboot) { + ok('Full SSD1306 init sequence completed without reboot.'); + process.exit(0); + } + if (r.reboot) { + err('REBOOT REPRODUCED. Suspect = last marker before reboot.'); + console.log(' → ' + (r.lastMarker || '(no markers — reboot before any marker)')); + process.exit(1); + } + warn('Inconclusive: no reboot but no mp_done either. See serial output above.'); + process.exit(3); +} + +main().catch(e => { err('Fatal:', e.message); console.error(e.stack); process.exit(2); });