From c4cbb17591f59319c40d30284ea1ca62a8acd799 Mon Sep 17 00:00:00 2001 From: David Montero Date: Fri, 12 Jun 2026 22:42:49 +0200 Subject: [PATCH] feat(cyw43): host-wake IRQ + F2 frame byte-order + SET/GET fix Unblocks the full wifi_on IOCTL sequence in the boot harness (clm_load through the 23-IOCTL bring-up, no crash): - Drive WL_HOST_WAKE (GPIO24, active-high): the driver gates poll_device on this pin until its first packet (had_successful_packet), so without it the first IOCTL response is never read. Emulator now exposes onHostWake(level) and toggles it with the inbound-frame queue. - Encode F2/SDPCM frame reads per 32-bit word (encodeFrameWords), same as register reads: the DMA-in sets channel bswap=true, so an un-encoded frame landed byte-reversed -> header_length read back as garbage and the driver dereferenced ioctl_header at an unaligned address (crash). Guarded to boot mode pass-through (no F2 traffic there; keeps unit tests). - Fix SET/GET detection: SDPCM_SET is bit 1 (0x2), not 0x1; echo the kind bit in IOCTL responses. - Add IOCTL/SDPCM debug counters + sequence log for the harness. Harness (investigation, CYW43_HARNESS=1 only): non-dropping TX FIFO so large F2 writes are not truncated, crank PIO steps/tick so the firmware drains in wall-clock, GPIO24 host-wake wiring, CPU-fault + PC-histogram + PIO-state instrumentation. Remaining: stall after mcast_list (#22) inside cyw43_cb_tcpip_init. --- ...cow-cyw43-boot-harness.investigate.test.ts | 144 +++++++++++++++++- .../src/simulation/cyw43/Cyw43Emulator.ts | 81 +++++++++- 2 files changed, 212 insertions(+), 13 deletions(-) diff --git a/frontend/src/__tests__/picow-cyw43-boot-harness.investigate.test.ts b/frontend/src/__tests__/picow-cyw43-boot-harness.investigate.test.ts index 66f84fd9..a700b3b5 100644 --- a/frontend/src/__tests__/picow-cyw43-boot-harness.investigate.test.ts +++ b/frontend/src/__tests__/picow-cyw43-boot-harness.investigate.test.ts @@ -86,7 +86,21 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig }>((resolve) => { const sim = new Simulator(); sim.rp2040.loadBootrom(bootromB1); - sim.rp2040.logger = new ConsoleLogger(LogLevel.Error); + // Custom non-throwing logger: capture CPU faults (e.g. unaligned reads) + // with the PC so we can locate corruption WITHOUT aborting the run. + void LogLevel; void ConsoleLogger; + let faultCount = 0; + const faultLog: string[] = []; + sim.rp2040.logger = { + debug() {}, info() {}, warn() {}, + error: (_comp: string, msg: string) => { + faultCount++; + if (faultLog.length < 25) { + const pc = ((sim.rp2040 as any).core?.PC ?? 0) >>> 0; + faultLog.push(`PC=0x${pc.toString(16)} ${msg}`); + } + }, + } as any; const fwBlocks = loadUF2(new Uint8Array(readFileSync(FW_PATH)), sim.rp2040.flash); let usbConnected = false; @@ -104,6 +118,9 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig const rawWords: number[] = []; const trace: string[] = []; const f2Log: string[] = []; // F2/IOCTL transfers, NOT subject to the ring + const postF2: string[] = []; // verbatim trace from the first F2 write onward + let f2Seen = false; + let restartsAtClm = -1; // restartCount at the moment clm_load goes out const funcHist = [0, 0, 0, 0]; // count of decoded gSPI functions F0..F3 const cmdCounts = new Map(); let ledOn = false; @@ -131,6 +148,7 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig if (ev.kind === 'header') { const k = key(ev.cmd); cmdCounts.set(k, (cmdCounts.get(k) ?? 0) + 1); + if (f2Seen && postF2.length < 400) postF2.push(`HDR ${formatCmd(ev.cmd)}`); } else if (ev.kind === 'payload') { // Histogram of decoded functions + capture EVERY F2 transfer. funcHist[ev.cmd.function & 3]++; @@ -140,7 +158,19 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig if (chip.debugInboundCount() > 0) statusReadsWithPkt++; } if (ev.cmd.function === 2 && f2Log.length < 60) { - f2Log.push(`${ev.cmd.write ? 'WR' : 'RD'} F2 a=0x${ev.cmd.address.toString(16)} len=${ev.payload.length || ev.readBytes}`); + const head = Array.from(ev.payload.slice(0, 32)) + .map((b) => b.toString(16).padStart(2, '0')).join(' '); + f2Log.push(`${ev.cmd.write ? 'WR' : 'RD'} F2 a=0x${ev.cmd.address.toString(16)} len=${ev.payload.length || ev.readBytes}` + + (ev.cmd.write ? `\n bytes: ${head}` : '')); + } + if (ev.cmd.function === 2 && ev.cmd.write && !f2Seen) { f2Seen = true; restartsAtClm = restartCount; } + // Once clm_load (first F2 write) goes out, capture EVERYTHING verbatim + // (no ring) so we can see exactly where the driver stalls afterward. + if (f2Seen && postF2.length < 400) { + postF2.push(`${formatCmd(ev.cmd)} rx=${ev.readBytes}` + + (ev.cmd.write && ev.payload.length > 0 && ev.payload.length < 8 + ? ` =0x${((ev.payload[0] | (ev.payload[1] << 8) | (ev.payload[2] << 16) | (ev.payload[3] << 24)) >>> 0).toString(16)}` + : '')); } // Skip the ~3500 firmware-block writes (len>=64) AND the backplane // window-address writes (0x1000a/b/c) that bracket each block — @@ -164,6 +194,11 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig .map((b) => b.toString(16).padStart(2, '0')).join(' '); trace.push(`<- (${reply.length}B) ${hex}${reply.length > 8 ? ' ...' : ''}`); } + if (f2Seen && postF2.length < 400) { + const hex = Array.from(reply.slice(0, 16)) + .map((b) => b.toString(16).padStart(2, '0')).join(' '); + postF2.push(` <- (${reply.length}B) ${hex}${reply.length > 16 ? ' ...' : ''}`); + } } } } @@ -171,17 +206,42 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig let rxPulled = 0; let restartCount = 0; + let txPulls = 0; + let smSteps = 0; for (const pio of (sim.rp2040 as any).pio) { for (const sm of pio.machines) { const tx = sm.txFIFO; if (!tx) continue; - const orig = tx.push.bind(tx); + // Make the TX FIFO NON-DROPPING by swapping its fixed 4-deep backing + // for an unbounded queue. rp2040js's FIFO.push silently drops when + // `used === length` (the DMA outruns the PIO drain on large bursts). + // Real hardware paces the DMA with DREQ so it never drops; the dropped + // words corrupt the 260-word F2 IOCTL writes (clm_load, ioctls), which + // is why no F2 payload ever frames. An unbounded queue retains every + // word so the PIO drains the complete stream — keeping the sniffer + // (hooked on push) and the driver's view identical (no phantom reads). + // Head-pointer queue: pull() is O(1) amortized (NO Array.shift, which is + // O(n) and turned the whole thing O(n^2) — the firmware download stalled). + const q: number[] = []; + let head = 0; + Object.defineProperty(tx, 'full', { get: () => false, configurable: true }); + Object.defineProperty(tx, 'empty', { get: () => head >= q.length, configurable: true }); + Object.defineProperty(tx, 'itemCount', { get: () => q.length - head, configurable: true }); + tx.peek = () => (head < q.length ? q[head] : 0); + tx.reset = () => { q.length = 0; head = 0; }; tx.push = (v: number) => { pushCount++; rawWords.push(v >>> 0); if (rawWords.length > 600) rawWords.splice(0, rawWords.length - 400); // ring feedWord(v, sm); - return orig(v); + q.push(v >>> 0); + }; + tx.pull = () => { + txPulls++; + if (head >= q.length) return 0; + const v = q[head++]; + if (head > 8192 && head * 2 > q.length) { q.splice(0, head); head = 0; } // compact + return v; }; // Reset the sniffer at each transfer boundary: cyw43_spi_transfer // calls pio_sm_restart before pushing the count words, so this keeps @@ -203,8 +263,43 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig }; } } + // Crank the PIO step-rate. rp2040js runs the PIO on its own setTimeout + // loop at only 1000 steps/tick (pio.run) while the CPU's execute() burns + // 1,000,000 instructions/tick — so a CPU tick (~hundreds of ms wall) + // starves the PIO, which only gets 1000 steps between ticks. With a + // non-dropping FIFO the PIO must bit-bang every firmware word, making the + // ~224KB download take 1000x too long. The gSPI PIO runs near the system + // clock (clkdiv ~1-2), so let it do up to 1M steps/tick, breaking early + // once all TX FIFOs are drained to avoid spinning when idle. + if (typeof pio.run === 'function') { + pio.run = () => { + for (let i = 0; i < 1_000_000 && !pio.stopped; i++) { + pio.step(); + if (i >= 2000 && (i & 1023) === 0) { + let pending = false; + for (const m of pio.machines) { + if (m.txFIFO && !m.txFIFO.empty) { pending = true; break; } + } + if (!pending) break; + } + } + if (!pio.stopped) pio.runTimer = setTimeout(() => pio.run(), 0); + }; + } } + // Drive the WL_HOST_WAKE line (GPIO24 on Pico W). The driver's + // poll_device gates ALL bus access on this pin being high until it has + // received its first packet (cyw43_ll.c had_successful_packet). Without + // it, the first IOCTL (clm_load) is sent but the driver then polls + // forever getting -1 and never reads the response. Active-high. + let hostWakeHigh = false; + chip.onHostWake((active: boolean) => { + hostWakeHigh = active; + try { (sim.rp2040 as any).gpio[24].setInputValue(active); } catch { /* noop */ } + }); + void hostWakeHigh; + // ── raw REPL injection (mirrors test_micropython_pico.mjs) ── const cdc = new USBCDC(sim.rp2040.usbCtrl); let serial = ''; @@ -253,11 +348,36 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig }; let finished = false; - const deadline = setTimeout(finish, 60_000); + // Sample the CPU PC between sim ticks to find busy-wait loops (the driver + // blocks in active(True) with no bus activity, so a PC histogram localizes + // the stuck loop — DMA wait, TXSTALL wait, or a delay). + const pcHist = new Map(); + const pcSampler = setInterval(() => { + const pc = ((sim.rp2040 as any).core?.PC ?? 0) >>> 0; + pcHist.set(pc, (pcHist.get(pc) ?? 0) + 1); + }, 20); + const deadline = setTimeout(finish, 70_000); function finish() { if (finished) return; finished = true; clearTimeout(deadline); + clearInterval(pcSampler); + // Snapshot the PIO/SM state BEFORE stopping — this is the deadlock state. + let pioState = ''; + try { + let pi = 0; + for (const pio of (sim.rp2040 as any).pio) { + pioState += `PIO${pi} stopped=${pio.stopped} fdebug=0x${(pio.fdebug >>> 0).toString(16)} txStall=0x${(pio.txStall >>> 0).toString(16)}\n`; + let si = 0; + for (const sm of pio.machines) { + const tx = sm.txFIFO; + pioState += ` SM${si} en=${sm.enabled} waiting=${sm.waiting} waitType=${sm.waitType} ` + + `pc=${sm.pc ?? '?'} txDepth=${tx ? tx.itemCount : '?'} rxDepth=${sm.rxFIFO ? sm.rxFIFO.itemCount : '?'}\n`; + si++; + } + pi++; + } + } catch (e) { pioState = `pioState err: ${String(e)}`; } try { sim.stop(); } catch { /* noop */ } const polls = [...cmdCounts.entries()].sort((a, b) => b[1] - a[1]).slice(0, 12); const report = @@ -268,9 +388,19 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig '===== TOP COMMAND COUNTS (poll loops) =====\n' + polls.map(([k, n]) => ` ${String(n).padStart(6)} ${k}`).join('\n') + '\n\n' + `===== FUNCTION HISTOGRAM F0..F3 = ${funcHist.join(',')} =====\n` + - `===== initInbound=${initInbound} statusReads=${statusReads} statusReadsWithPkt=${statusReadsWithPkt} finalInbound=${chip.debugInboundCount()} restarts=${restartCount} =====\n\n` + + `===== initInbound=${initInbound} statusReads=${statusReads} statusReadsWithPkt=${statusReadsWithPkt} finalInbound=${chip.debugInboundCount()} restarts=${restartCount} =====\n` + + `===== pushCount=${pushCount} txPulls=${txPulls} smSteps=${smSteps} =====\n` + + `===== IOCTL ${chip.debugIoctlStats()} =====\n` + + '===== IOCTL SEQUENCE =====\n' + chip.debugIoctlLog().map((s, i) => ` ${i}: ${s}`).join('\n') + '\n' + + `===== restartsAtClm=${restartsAtClm} restartsFinal=${restartCount} rxPulled=${rxPulled} =====\n` + + `===== CPU FAULTS faultCount=${faultCount} =====\n` + faultLog.join('\n') + '\n' + + '===== HOT PCs (busy-wait localization) =====\n' + + [...pcHist.entries()].sort((a, b) => b[1] - a[1]).slice(0, 12) + .map(([pc, n]) => ` ${String(n).padStart(6)} PC=0x${pc.toString(16)}`).join('\n') + '\n\n' + + '===== PIO/SM STATE AT DEADLINE (deadlock) =====\n' + pioState + '\n' + '===== F2/IOCTL TRANSFERS (total seen, non-ring) =====\n' + `count=${f2Log.length}\n` + f2Log.join('\n') + '\n\n' + + '===== POST-CLM_LOAD (verbatim from first F2 write) =====\n' + postF2.join('\n') + '\n\n' + '===== TRACE TAIL (post-firmware) =====\n' + trace.slice(-120).join('\n') + '\n\n' + '===== LAST RAW TX WORDS (hex) — the end of the run =====\n' + rawWords.slice(-70).map((w) => w.toString(16).padStart(8, '0')).join(' ') + '\n'; @@ -297,5 +427,5 @@ describe.skipIf(!process.env.CYW43_HARNESS)('Pico W cyw43 boot harness (investig console.log('\n===== reachedImport=' + result.reachedImport + ' reachedActive=' + result.reachedActive + ' ====='); expect(result.trace.length).toBeGreaterThan(0); - }, 120_000); + }, 90_000); }); diff --git a/frontend/src/simulation/cyw43/Cyw43Emulator.ts b/frontend/src/simulation/cyw43/Cyw43Emulator.ts index be3f85e0..ad550068 100644 --- a/frontend/src/simulation/cyw43/Cyw43Emulator.ts +++ b/frontend/src/simulation/cyw43/Cyw43Emulator.ts @@ -131,12 +131,32 @@ export class Cyw43Emulator { private eventMask = new Uint8Array(32); // up to 256 event types private inboundEvents: Uint8Array[] = []; + // ── Debug counters (investigation harness only) ───────────────── + private _dbgF2Writes = 0; // F2 write transfers received + private _dbgFramesDecoded = 0; // SDPCM decode succeeded + private _dbgSdpcmFail = 0; // SDPCM decode returned null + private _dbgIoctls = 0; // handleIoctl invoked + private _dbgIoctlFail = 0; // CDC decode returned null + private _dbgLastIoctl = -1; // last cdc.cmd seen + private _dbgIoctlLog: string[] = []; // human-readable IOCTL sequence + debugIoctlStats(): string { + return `f2w=${this._dbgF2Writes} sdpcmOk=${this._dbgFramesDecoded} ` + + `sdpcmFail=${this._dbgSdpcmFail} ioctls=${this._dbgIoctls} ` + + `ioctlFail=${this._dbgIoctlFail} lastCmd=${this._dbgLastIoctl}`; + } + debugIoctlLog(): string[] { return this._dbgIoctlLog; } + // ── Listeners ─────────────────────────────────────────────────── private ledListeners: Listener[] = []; private scanListeners: Listener[] = []; private connectListeners: Listener[] = []; private disconnectListeners: Listener[] = []; private packetOutListeners: Listener[] = []; + // Host-wake (WL_HOST_WAKE / GPIO24) level listeners. The chip drives this + // pin high when it has a frame for the host; the driver gates poll_device on + // it until the first packet is received (cyw43_ll.c had_successful_packet). + private hostWakeListeners: Listener[] = []; + private hostWakeAsserted = false; constructor(opts: Cyw43EmulatorOptions = {}) { this.now = opts.now ?? (() => Date.now()); @@ -166,6 +186,7 @@ export class Cyw43Emulator { } this.inboundEvents.push(sdpcm); this.f0Regs[F0.INTERRUPT >> 2] |= 0x40; + this.updateHostWake(); } // ── Listener registration ─────────────────────────────────────── @@ -174,6 +195,23 @@ export class Cyw43Emulator { onConnect = (cb: Listener) => this.add(this.connectListeners, cb); onDisconnect = (cb: Listener) => this.add(this.disconnectListeners, cb); onPacketOut = (cb: Listener) => this.add(this.packetOutListeners, cb); + /** Fires with the WL_HOST_WAKE pin level (true=high) whenever it changes. */ + onHostWake = (cb: Listener) => { + const off = this.add(this.hostWakeListeners, cb); + cb(this.hostWakeAsserted); // deliver current level on subscribe + return off; + }; + + /** + * Recompute the host-wake (GPIO24) level from the inbound-frame queue and + * notify listeners on a change. Active-high: high while a frame is pending. + */ + private updateHostWake(): void { + const want = this.inboundEvents.length > 0; + if (want === this.hostWakeAsserted) return; + this.hostWakeAsserted = want; + for (const cb of this.hostWakeListeners) cb(want); + } private add(arr: Listener[], cb: Listener): () => void { arr.push(cb); @@ -240,6 +278,27 @@ export class Cyw43Emulator { return this.bigEndian ? bswap32(value >>> 0) : swap16(value >>> 0); } + /** + * Encode an SDPCM frame for an F2 read. The frame rides the SAME byte-swapped + * DMA-in path as register reads (cyw43_spi_transfer sets channel bswap=true), + * so every 32-bit word must be run through encodeReadWord. Without this the + * frame lands byte-reversed in spid_buf: header_length reads back as garbage + * and the driver dereferences ioctl_header at an unaligned address (crash). + */ + private encodeFrameWords(frame: Uint8Array): Uint8Array { + // F2/SDPCM traffic only happens after the bus switches to 32-bit big-endian; + // in the 16-bit boot regime (and the unit tests that exercise IOCTLs there) + // the frame is consumed raw, so pass it through unchanged. + if (!this.bigEndian) return frame; + const out = new Uint8Array(frame.length); + const whole = frame.length & ~3; + for (let i = 0; i < whole; i += 4) { + writeU32LE(out, i, this.encodeReadWord(readU32LE(frame, i))); + } + for (let i = whole; i < frame.length; i++) out[i] = frame[i]; // tail (gSPI is word-aligned) + return out; + } + /** True once the driver has switched the bus to 32-bit big-endian. */ isBigEndian(): boolean { return this.bigEndian; } @@ -378,8 +437,10 @@ export class Cyw43Emulator { private handleF2(cmd: Cyw43Cmd, _payload: Uint8Array, _rxBytes: number): Uint8Array | null { if (cmd.write) { + this._dbgF2Writes++; const frame = decodeSdpcm(_payload); - if (frame) this.handleHostFrame(frame.channel, frame.payload); + if (frame) { this._dbgFramesDecoded++; this.handleHostFrame(frame.channel, frame.payload); } + else this._dbgSdpcmFail++; return null; } @@ -395,7 +456,8 @@ export class Cyw43Emulator { if (this.inboundEvents.length === 0) { this.f0Regs[F0.INTERRUPT >> 2] &= ~0x40; } - return out; + this.updateHostWake(); + return this.encodeFrameWords(out); } // ── Host → chip frame dispatch ────────────────────────────────── @@ -418,9 +480,13 @@ export class Cyw43Emulator { // ── IOCTL handler ─────────────────────────────────────────────── private handleIoctl(cdcBytes: Uint8Array): void { + this._dbgIoctls++; const cdc = decodeCdc(cdcBytes); - if (!cdc) return; - const isGet = (cdc.flags & 0x1) === 0; // bit 0 clear = GET + if (!cdc) { this._dbgIoctlFail++; return; } + this._dbgLastIoctl = cdc.cmd; + // SDPCM_SET is 0x2 (bit 1) in the CDC flags; SDPCM_GET is 0. (cyw43_ll.c) + const ioctlKind = cdc.flags & 0x2; + const isGet = ioctlKind === 0; const data = cdc.payload; // For SET_VAR/GET_VAR, name is a NUL-terminated string at start of payload. let varName = ''; @@ -429,6 +495,9 @@ export class Cyw43Emulator { varName = readCString(data, 0); varOff = varName.length + 1; } + if (this._dbgIoctlLog.length < 60) { + this._dbgIoctlLog.push(`${isGet ? 'GET' : 'SET'} cmd=${cdc.cmd}${varName ? ' ' + varName : ''} dlen=${data.length} outlen=${cdc.outlen}`); + } const reqId = (cdc.flags >>> 16) & 0xffff; let response: Uint8Array = new Uint8Array(0); const status = 0; @@ -510,8 +579,8 @@ export class Cyw43Emulator { dv.setUint32(0, cdc.cmd, true); dv.setUint16(4, response.length, true); dv.setUint16(6, 0, true); - // Mirror the request-id in the upper 16 bits, set bit 0 to mark "response" - dv.setUint32(8, ((reqId & 0xffff) << 16) | (isGet ? 0 : 1), true); + // Mirror the request-id in the upper 16 bits and echo the SET/GET kind bit. + dv.setUint32(8, ((reqId & 0xffff) << 16) | ioctlKind, true); dv.setUint32(12, status >>> 0, true); replyCdc.set(response, CDC_HEADER_LEN); const sdpcm = encodeSdpcm({