test(esp32): add MicroPython I2C reproduction tests for IWDT bug
Two Node.js tests that hit the simulation backend WebSocket directly
and inject minimal MicroPython programs via raw-paste REPL:
- test_micropython_i2c_minimal: smallest possible repro. I2C(0)+scan+
single-byte writeto. Used to prove the bug is NOT in the basic I2C
layer — this test passes both before and after the fix.
- test_micropython_i2c_ssd1306_repro: walks the full SSD1306 init
sequence (25-cmd init loop + 6x addr writes + writevto 8B + writevto
1024B). Used to prove the bug is NOT in the cmd sequence or the
writevto path — this test also passes both before and after.
These two tests refuted the original "missing TRANS_DONE IRQ"
hypothesis and pointed the investigation toward the file-load vs
raw-REPL difference, which led to identifying the per-byte _emit
bottleneck in esp32_worker.py.
Run with:
node --experimental-websocket test/test_micropython_i2c_minimal/test.mjs \
--backend=http://localhost:3080 --timeout=120
Requires the velxio container (or local backend with QEMU libs) on
the given backend URL.
This commit is contained in:
David Montero
parent
d6442180b0
commit
c147e7a4aa
|
|
@ -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/<session>`.
|
||||||
|
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.
|
||||||
|
|
@ -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();
|
||||||
|
|
@ -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); });
|
||||||
Loading…
Reference in New Issue