diff options
Diffstat (limited to 'examples')
| -rw-r--r-- | examples/differ.zig | 203 | ||||
| -rw-r--r-- | examples/halcheck.zig | 194 | ||||
| -rw-r--r-- | examples/http.zig | 922 | ||||
| -rw-r--r-- | examples/intrcheck.zig | 269 | ||||
| -rw-r--r-- | examples/iocheck.zig | 110 | ||||
| -rw-r--r-- | examples/minimal.zig | 42 | ||||
| -rw-r--r-- | examples/pie.zig | 224 | ||||
| -rw-r--r-- | examples/portcheck.zig | 267 | ||||
| -rw-r--r-- | examples/radio.zig | 388 | ||||
| -rw-r--r-- | examples/rf.zig | 613 | ||||
| -rw-r--r-- | examples/sdiocheck.zig | 321 |
11 files changed, 3553 insertions, 0 deletions
diff --git a/examples/differ.zig b/examples/differ.zig new file mode 100644 index 0000000..865af3e --- /dev/null +++ b/examples/differ.zig @@ -0,0 +1,203 @@ +//! Differential test: this project's Zig HAL against ESP-IDF's own LL, in one image, on the die. +//! +//! zig build diff -Doracle -Dapp=examples/differ.zig +//! +//! Both implementations are compiled into the same binary - IDF's `*_ll.h` by Zig's clang, ours by +//! Zig - so they run on the same boot, the same clocks and the same silicon. For each operation the +//! harness brings the peripheral to a known state, runs ESP-IDF's version, photographs the register +//! block, restores, runs ours, photographs again, and compares. A pass means: for this operation and +//! these arguments, our sequence leaves the hardware in the state ESP-IDF's does. +//! +//! Four rules this harness follows because adversarial review measured what happens without them: +//! +//! 1. **A snapshot can have side effects.** `UART_FIFO_REG` is at offset 0x000 of every UART block - +//! the first word a "read the whole block" loop touches - and reading it *pops the RX FIFO*. The +//! header annotates it `RO`. So each peripheral declares offsets that must not be read. +//! 2. **A block cannot be restored by writing its snapshot back.** About 10% of this chip's fields +//! perform an action when written; writing one saved word back to a UART's offset 0 transmits a +//! character, and restoring GPIO's saved `ENABLE_W1TC` would clear the enables just set. Restore +//! is either the peripheral's reset bit or a deliberate configure function - never a write-back. +//! 3. **A clock-gated block reads stale data, silently.** Not zeros: the last value latched. Two +//! snapshots of a gated peripheral can compare *equal* while describing nothing, so the bus +//! clock is checked before every comparison. +//! 4. **Equal registers do not prove equal sequences.** Ordering is invisible in the final state, +//! and ordering is where the interesting bugs are - LEDC's shadow registers commit on a +//! self-clearing bit that leaves no trace. Where a peripheral's correctness is an order rather +//! than a state, its case list says so. + +const std = @import("std"); +const soc = @import("soc"); +const hal = @import("hal"); +const regs = @import("regs"); +const mmio = @import("mmio"); +const oracle = @import("oracle"); + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK DIFF_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +/// Widest register block any suite compares. 400 words covers GPIO through its matrix +/// configuration; two snapshots at that size are 3.2 KB of L2MEM, which this image has to spare. +const max_words = 512; +var snap_a: [max_words]u32 = @splat(0); +var snap_b: [max_words]u32 = @splat(0); + +var cases_run: u32 = 0; +var failures: u32 = 0; + +fn contains(haystack: []const u32, needle: u32) bool { + for (haystack) |h| if (h == needle) return true; + return false; +} + +fn snapshot(p: oracle.types.Peripheral, out: []u32) void { + for (0..p.words) |i| { + const w: u32 = @intCast(i); + if (contains(p.no_read, w)) { + // A value hardware cannot produce, so a diff involving it is obviously a harness bug + // rather than a peripheral difference. + out[i] = 0xdead_0000 | w; + continue; + } + out[i] = mmio.Reg.atAddress(p.base + w * 4).raw(); + } +} + +fn restore(p: oracle.types.Peripheral) void { + switch (p.restore) { + .configure => |f| f(), + .reset_bit => |b| { + // Assert then deassert, with interrupts masked: these bits share a register with every + // other peripheral's reset. + const guard = hal.clkrst.maskInterrupts(); + defer guard.release(); + const r = mmio.Reg.atAddress(b.reg); + r.writeRaw(r.raw() | (@as(u32, 1) << b.bit)); + r.writeRaw(r.raw() & ~(@as(u32, 1) << b.bit)); + }, + } +} + +fn runSuite(suite: oracle.types.Suite) void { + const p = suite.descriptor; + if (p.words > max_words) { + soc.rom.print("MARK DIFF_SKIP %s wants %u words, harness holds %u\r\n", .{ p.name, p.words, @as(u32, max_words) }); + failures += 1; + return; + } + if (suite.setup) |s| s(); + + for (suite.cases) |c| { + cases_run += 1; + + // Rule 3: a gated block returns the last latched value, so two snapshots of it can agree + // and mean nothing. + if (p.clock) |clk| { + if (mmio.Reg.atAddress(clk.reg).raw() & (@as(u32, 1) << clk.bit) == 0) { + soc.rom.print("MARK DIFF SKIP %s.%s bus clock is off; a snapshot would be stale\r\n", .{ p.name, c.name }); + failures += 1; + continue; + } + } + + restore(p); + c.idf(); + snapshot(p, &snap_a); + + restore(p); + c.ours(); + snapshot(p, &snap_b); + + var diffs: u32 = 0; + for (0..p.words) |i| { + const w: u32 = @intCast(i); + if (contains(p.volatile_words, w)) continue; + if (snap_a[i] == snap_b[i]) continue; + diffs += 1; + if (diffs <= 4) { + soc.rom.print(" DIFF %s+0x%03x idf=0x%08x ours=0x%08x xor=0x%08x\r\n", .{ + p.name, w * 4, snap_a[i], snap_b[i], snap_a[i] ^ snap_b[i], + }); + } + } + if (diffs == 0) { + soc.rom.print("MARK DIFF ok %s.%s(%u) %u words identical\r\n", .{ p.name, c.name, c.arg, p.words }); + } else { + failures += 1; + soc.rom.print("MARK DIFF FAIL %s.%s(%u) %u of %u words differ\r\n", .{ p.name, c.name, c.arg, diffs, p.words }); + } + } +} + +export fn zig_main() noreturn { + // First, before anything long-running: take the RTC watchdog off the board. + // + // The bootloader arms it to cover the handover and expects the application to take it over. + // Nothing in this repo ever did, and nothing noticed, because no run had exceeded eight seconds. + // This harness passed 26 cases, then 64, and then started resetting mid-run - which looked + // exactly like "the newest suite crashes the board" and was in fact a ten-second fuse that had + // been burning since the first image. + const wdt_was_armed = hal.rwdt.armed(); + const wdt_off = hal.rwdt.disable(); + soc.rom.print("\r\nMARK DIFF_START esp-idf LL vs zig HAL, one image, on the die\r\n", .{}); + soc.rom.print("MARK DIFF_WDT armed_at_entry=%u disabled=%u (bootloader leaves the RTC watchdog running)\r\n", .{ + @as(u32, @intFromBool(wdt_was_armed)), + @as(u32, @intFromBool(wdt_off)), + }); + // If IDF's LL was compiled to call the mask ROM, the comparison would be against + // `rom_gpio_set_output_level` rather than against IDF's register sequence. src/oracle/ + // oracle_sdkconfig.h exists to keep this at 0. + soc.rom.print("MARK DIFF_CFG gpio_ll_uses_rom_api=%u expect=0\r\n", .{ + @as(u32, @intFromBool(oracle.gpio.usesRomApi())), + }); + + // GPIO's two suites run once per pin, because the bank split at 32 is where its arithmetic + // differs - and because the pad registers live in a different register file from the GPIO block, + // far enough away that one window cannot cover both. + for (oracle.gpio.pins) |p| { + oracle.gpio.pin = p; + soc.rom.print("MARK DIFF_PIN %u\r\n", .{@as(u32, p)}); + runSuite(oracle.gpio.suite); + runSuite(oracle.gpio.iomux_suite); + } + + // Every other registered peripheral. The two GPIO suites are skipped here because the loop above + // already ran them once per pin. + inline for (oracle.suites) |suite| { + const n = comptime std.mem.span(suite.descriptor.name); + if (comptime !std.mem.eql(u8, n, "gpio") and !std.mem.eql(u8, n, "iomux")) runSuite(suite); + } + + soc.rom.print("MARK DIFF_TOTAL cases=%u failures=%u\r\n", .{ cases_run, failures }); + soc.rom.print("MARK DIFF_DONE\r\n", .{}); + + // Leave the board as the rest of the project expects it: LED pin an output, blinking. + hal.gpio.configureOutput(20, .{ .readback = true }); + while (true) { + hal.gpio.setHigh(20); + soc.rom.ets_delay_us(500_000); + hal.gpio.setLow(20); + soc.rom.ets_delay_us(500_000); + } +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/halcheck.zig b/examples/halcheck.zig new file mode 100644 index 0000000..94b3a2d --- /dev/null +++ b/examples/halcheck.zig @@ -0,0 +1,194 @@ +//! Hardware check for the register layer and the first three HAL peripherals. +//! +//! Every line this prints is a claim about the silicon that the die itself answers. Nothing here is +//! a unit test of Zig code: the register numbers come from ESP-IDF's own macros, so the only thing +//! left to doubt is whether the *sequences* built on them do what the hardware needs. +//! +//! Run with: zig build -Dapp=examples/halcheck.zig run -Dseconds=8 + +const std = @import("std"); +const soc = @import("soc"); +const hal = @import("hal"); +const regs = @import("regs"); +const mmio = @import("mmio"); +const config = @import("config"); + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK HAL_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +const led = config.led_pin; + +export fn zig_main() noreturn { + soc.rom.print("\r\nMARK HAL_START hw_ver=%u registers from ESP-IDF headers\r\n", .{ + @as(u32, regs.ZIG_P4_HW_VER), + }); + + // ---------------------------------------------------------------- 1. the register layer itself + // A handful of addresses, printed so a human can check them against the technical reference + // manual without trusting anything in this repo. GPIO_OUT is 0x500E0004 and IO_MUX's pad 0 is + // 0x500E1004 on this part. + soc.rom.print("MARK HAL_ADDR gpio_out=0x%08x iomux_pad0=0x%08x systimer_conf=0x%08x\r\n", .{ + @as(u32, @intCast(regs.GPIO_OUT_REG)), + @as(u32, @intCast(regs.PERIPHS_IO_MUX_U_PAD_GPIO0)), + @as(u32, @intCast(regs.SYSTIMER_CONF_REG)), + }); + // The GPIO matrix constant that the hand-written predecessor got right and the first HAL draft + // got wrong. 256 on the P4, 128 on the S3. + soc.rom.print("MARK HAL_SIGMAP gpio_out_idx=%u expect=256\r\n", .{ + @as(u32, hal.gpio.matrix_gpio_signal), + }); + + // ---------------------------------------------------------------- 2. GPIO + // Same observable behaviour as the hand-written GPIO this replaces: drive a pin, read it back + // through the pad's own input buffer while it is driven. + hal.gpio.configureOutput(led, .{ .readback = true }); + hal.gpio.setHigh(led); + const drove_high = hal.gpio.getLevel(led); + hal.gpio.setLow(led); + const drove_low = hal.gpio.getLevel(led); + soc.rom.print("MARK HAL_GPIO pin=%u high=%u low=%u oe=%u expect=1,0,1\r\n", .{ + @as(u32, led), + @as(u32, drove_high), + @as(u32, drove_low), + @as(u32, @intFromBool(hal.gpio.isOutputEnabled(led))), + }); + + // The second bank. The split at pin 32 is the classic P4 GPIO bug - a write to `out` with a + // shift of 40 lands on pin 8 - and it is only provable above 31. + // + // Pin choice matters here and cost a debugging round. GPIO54 is on JP1 but is this board's + // ESP32-C6 reset line with an external pull-up: it drives correctly (out1 follows 1 -> 0) and + // reads back stuck high, because the pull-up wins at the pad. GPIO33 (JP1 pin 21) is genuinely + // free, and it tracks. + const bank1_pin = 33; + hal.gpio.configureOutput(bank1_pin, .{ .readback = true }); + hal.gpio.setHigh(bank1_pin); + const hi_b1 = hal.gpio.getLevel(bank1_pin); + hal.gpio.setLow(bank1_pin); + const lo_b1 = hal.gpio.getLevel(bank1_pin); + hal.gpio.outputDisable(bank1_pin); + soc.rom.print("MARK HAL_GPIO_BANK1 pin=%u high=%u low=%u expect=1,0\r\n", .{ + @as(u32, bank1_pin), @as(u32, hi_b1), @as(u32, lo_b1), + }); + + // ---------------------------------------------------------------- 3. clock gates + // TWAI0 is the one peripheral whose bus clock is gated OFF at power-on, which makes it the only + // place where enabling a clock is observable rather than merely correct. + // + // Read what this proves narrowly. Both the write and the read-back go through this project's own + // accessor, so agreement shows the two are consistent with each other - not that either touches + // the right register. That is not a hypothetical caveat: an earlier version of clkrst.zig had + // these four peripherals' gate bits in HP_SYS_CLKRST_PERI_CLK_CTRL21 instead of SOC_CLK_CTRL2, + // and this test printed exactly the expected 0,1,0 while poking a bit of an unrelated register. + // It would have passed with the chip unplugged. The real check is `zig build diff`, where the + // reference reaches the hardware through ESP-IDF's LL instead. + const twai_before = hal.clkrst.isClockEnabled(.twai0); + hal.clkrst.setClockEnabled(.twai0, true); + const twai_on = hal.clkrst.isClockEnabled(.twai0); + hal.clkrst.setClockEnabled(.twai0, false); + const twai_off = hal.clkrst.isClockEnabled(.twai0); + soc.rom.print("MARK HAL_GATE twai0 boot=%u on=%u off=%u expect=0,1,0 (self-consistency only; see diff)\r\n", .{ + @as(u32, @intFromBool(twai_before)), + @as(u32, @intFromBool(twai_on)), + @as(u32, @intFromBool(twai_off)), + }); + + // UART0 is the console this text is coming out of, so its gate must read back enabled - and + // this is a read, deliberately: writing it would cut the wire mid-sentence. + soc.rom.print("MARK HAL_GATE uart0=%u expect=1 (console is alive, so it must be)\r\n", .{ + @as(u32, @intFromBool(hal.clkrst.isClockEnabled(.uart0))), + }); + + // ---------------------------------------------------------------- 4. systimer + hal.systimer.init(); + const t0 = hal.systimer.read(.unit0) orelse { + soc.rom.print("MARK HAL_SYSTIMER dead - no valid handshake\r\n", .{}); + hang(); + }; + const c0 = soc.cycles(); + soc.rom.ets_delay_us(50_000); + const t1 = hal.systimer.read(.unit0) orelse unreachable; + const c1 = soc.cycles(); + + const ticks = t1 - t0; + const cycles = c1 - c0; + // The counter must advance, and by roughly 16 MHz * 50 ms = 800,000 ticks. + soc.rom.print("MARK HAL_SYSTIMER ticks=%u expect~800000 advancing=%u\r\n", .{ + @as(u32, @truncate(ticks)), + @as(u32, @intFromBool(t1 > t0)), + }); + // Two independent clocks measuring the same interval: systimer is a fixed 16 MHz, so the CPU + // frequency falls out of the ratio. This is the honest measurement of a number the README has + // only ever estimated. + const cpu_khz: u64 = if (ticks != 0) (cycles * (hal.systimer.hz / 1000)) / ticks else 0; + soc.rom.print("MARK HAL_CPUFREQ %u kHz, from %u cycles per %u systimer ticks\r\n", .{ + @as(u32, @truncate(cpu_khz)), + @as(u32, @truncate(cycles)), + @as(u32, @truncate(ticks)), + }); + + // The 52-bit counter read as a pair of words. If the update/valid handshake were skipped, the + // low word could wrap between the two loads and the value would jump backwards; sample it in a + // tight loop and assert monotonicity, which is the only cheap way to catch that. + var last: u64 = hal.systimer.read(.unit0) orelse unreachable; + var backwards: u32 = 0; + for (0..2000) |_| { + const now = hal.systimer.read(.unit0) orelse unreachable; + if (now < last) backwards += 1; + last = now; + } + soc.rom.print("MARK HAL_SYSTIMER_MONOTONIC 2000 reads, backwards=%u expect=0\r\n", .{backwards}); + + // ---------------------------------------------------------------- 5. the TIMG reset trap + // Resetting a timer group re-arms flash-boot watchdog protection, and the board then reboots a + // moment later with nothing on the console to explain it. resetPeripheral clears that bit as + // part of the reset. The proof is negative and needs time to pass, so print before and after and + // let the rest of this program be the delay. + soc.rom.print("MARK HAL_TIMG_RESET resetting timg0 - a reboot after this line means the flashboot fixup is missing\r\n", .{}); + hal.clkrst.resetPeripheral(.timg0); + hal.systimer.delayMicros(200_000); + soc.rom.print("MARK HAL_TIMG_SURVIVED still running 200 ms after the timg0 reset\r\n", .{}); + + soc.rom.print("MARK HAL_DONE\r\n", .{}); + + // Blink from the HAL, using the systimer for the delay rather than the ROM's. + var beat: u32 = 0; + while (true) : (beat += 1) { + hal.gpio.setHigh(led); + hal.systimer.delayMicros(250_000); + hal.gpio.setLow(led); + hal.systimer.delayMicros(250_000); + if (beat % 4 == 0) { + soc.rom.print("MARK HAL_ALIVE beat=%u t=%u us\r\n", .{ + beat, + @as(u32, @truncate(hal.systimer.micros(.unit0) orelse 0)), + }); + } + } +} + +fn hang() noreturn { + while (true) {} +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/http.zig b/examples/http.zig new file mode 100644 index 0000000..03d89c1 --- /dev/null +++ b/examples/http.zig @@ -0,0 +1,922 @@ +//! The data path, end to end: associate, take a DHCP lease, answer a ping, fetch a URL. +//! +//! examples/radio.zig proved the control path - SDIO up, RPC in both directions, a scan, an +//! association event from the C6. What it did not do is move a single Ethernet frame, and the +//! symptom was ESP-Hosted logging `task still writing Rx data to queue!` once associated: the AP's +//! traffic arriving with nobody registered to consume it. +//! +//! This file registers that consumer (src/net/link.zig) and puts src/net/ip.zig behind it. Nothing +//! from lwIP, esp_netif or the IDF network stack is linked; the IPv4, ARP, ICMP, UDP, DHCP, TCP and +//! HTTP are all this project's, in one 3.4 KB struct that allocates nothing and reads no clock. +//! +//! Run: +//! zig build -Dhosted -Dapp=examples/http.zig \ +//! -Dssid=YOUR_SSID -Dpsk-file=/path/to/psk run +//! +//! What it prints, in order, and what each line means. Every wait below is bounded and every +//! bound prints why it gave up, because a silent wait on this board is indistinguishable from a +//! dead scheduler. +//! +//! MARK HTTP_START cpu=... the image booted; the CPU clock, from two independent counters +//! MARK HTTP_WDT ... the bootloader's RTC watchdog was found armed and disarmed +//! MARK HTTP_TICK ... heartbeat during bring-up: scheduler alive, C making progress +//! MARK HTTP_RADIO_UP after N ms the C6 answered and the transport reached its active state +//! bad case: MARK HTTP_FAIL radio ... - the transport never came up. Nothing below can run. +//! MARK HTTP_WIFI_START rc=0 the first RPC round trip after bring-up +//! bad case: rc!=0, or spun>0 meaning the RPC threads never left their not-ready loop +//! MARK HTTP_LINK mac=... foot=N the station channel is registered; `mac` is the C6's radio's +//! own address and is what ARP will answer for. From this line on, +//! station frames reach src/net/ip.zig instead of being discarded. +//! bad case: MARK HTTP_FAIL link=MacUnavailable (asked before the radio was started) or +//! =ChannelRegisterFailed (transport_drv_add_channel refused; wrong if_type) +//! MARK HTTP_JOIN ssid=... psk_len=N the association request went out. The passphrase is never +//! printed; only its length, which distinguishes a missing +//! -Dpsk-file from a wrong one. +//! MARK HTTP_ASSOC after N ms by=X rx=N associated. `by=event` means WIFI_EVENT_STA_CONNECTED +//! (id 4) arrived; `by=traffic` means station frames arrived, +//! which an AP does not send to an unassociated station and which +//! is what happens when the C6 was already on this SSID. +//! bad case: MARK HTTP_FAIL assoc timeout ... - the radio never associated. Wrong passphrase, +//! wrong band, or out of range. Any RADIO_EVENT id=5 line before it is a disconnect +//! and carries the reason in its length. +//! MARK HTTP_DHCP_TX ... DISCOVER sent. This is the first frame this project has ever +//! put on a real network. +//! MARK HTTP_DHCP_WAIT ... progress, every second: DHCP state and the frame counters. If +//! `rx=0` stays zero the receive callback is not being called at +//! all; if `rx` climbs while `drop` climbs with it, frames are +//! arriving and being rejected - which is what a frame shifted by +//! a header looks like, so `csum` and `drop` are printed too. +//! MARK HTTP_IP ip=... mask=... a real lease from the real DHCP server +//! MARK HTTP_ROUTE gw=... dns=... in N ms and the route it came with +//! bad case: MARK HTTP_FAIL dhcp state=selecting - DISCOVERs went out, no OFFER came back +//! (frames leaving but not arriving), or state=requesting - an OFFER arrived and the +//! ACK did not. The state is the diagnosis, which is why it is printed rather than +//! just "timeout". +//! MARK HTTP_PING_OPEN ip=... for N ms ping the board from the workstation NOW +//! MARK HTTP_PING n=N arp_rx=... arp_tx=... one line per echo request answered. The ARP +//! counters beside it are what prove the exchange was two-way: +//! the workstation had to ARP for this address and be answered +//! before it could send the echo at all. +//! bad case: no such line for the whole window. If `HTTP_PING_IDLE` shows rx climbing, frames +//! arrive and the board is not recognising them as ICMP for its own address. +//! MARK HTTP_GET host=... port=... path=... the request begins +//! MARK HTTP_STATUS code=... len=N tcp=... the response's status line was parsed +//! MARK HTTP_BODY ... the first bytes of the body, non-printables as '.' +//! bad case: MARK HTTP_FAIL get=HostUnreachable (no ARP answer for the peer), +//! =TimedOut (SYN or data unacknowledged), =ConnectionReset (nothing listening on +//! that port), =WouldBlock (our own deadline, printed with the TCP state) +//! MARK HTTP_LIVE ... still running and still answering ICMP, once a second + +const std = @import("std"); +const hal = @import("hal"); +const soc = @import("soc"); +const net = @import("net"); +const p4 = @import("io"); +const config = @import("config"); + +/// Required by any application implementing `std.Io.VTable` on this target, and it must be in the +/// ROOT module: std reads `std.options` from `@import("root")`. +pub const std_options: std.Options = .{ .page_size_min = 4096 }; + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK HTTP_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +// =============================================================================== the target +// +// The HTTP peer. A host on this workstation's own /24 rather than the gateway's web UI, so the +// expected response bytes are known in advance and a wrong answer means this stack is wrong rather +// than that a router's firmware is unusual. +// +// Serve it with, from the directory holding the file to be fetched: +// python3 -m http.server 8080 --bind 192.168.1.181 +// A `Content-Length` is what that sends, so the body's end is framed by the header rather than by +// the peer's FIN - which exercises the more interesting of ip.zig's two termination paths. +const http_host: [4]u8 = .{ 192, 168, 1, 181 }; +const http_port: u16 = 8080; +const http_path = "/"; + +/// How long the board stays quietly pingable before it makes the HTTP request. Long enough for a +/// person to run `ping` after reading the line that says to. +const ping_window_ms: u64 = 30_000; + +// ================================================================================== budgets +// +// Every one of these is a bound on a wait that would otherwise be a hang, and each is generous +// against the thing it is waiting for rather than round. + +/// The C6 boots in well under a second; examples/radio.zig saw the transport up at 1,890 ms. +const radio_deadline_ms: u64 = 10_000; +/// A 2.4 GHz association with WPA2 is a second or two. Twenty allows for a scan and a retry. +const assoc_deadline_ms: u64 = 60_000; + +/// How many association attempts before giving up. +/// +/// Ten, because this link is genuinely marginal and the failure is not ours. Measured on this board: +/// the same SSID and passphrase associate on some attempts and are refused on others with reason=4 +/// ASSOC_EXPIRE at about -68 dBm, and one run exhausted four attempts in a row. Reason 15 would mean +/// a wrong passphrase; 4 means the AP expired the association, and the only cure is to ask again. +/// +/// Ten attempts against a 45 s deadline is roughly one every 4.5 s, which is slower than the AP's own +/// timeout and so does not pile requests on top of each other. +const assoc_attempts: u32 = 6; + +/// Pause between association attempts. See the comment at the retry itself: hammering the AP is what +/// turns a marginal link into a refused one. +const assoc_backoff_ms: u64 = 3_000; +/// DHCP's own first retransmission is at 4 s and ip.zig retries with backoff; fifteen seconds is +/// three or four DISCOVERs, which is enough to distinguish "no server" from "one lost frame". +const dhcp_deadline_ms: u64 = 15_000; +/// ARP, a SYN, a request and a response, with TCP's initial RTO at 1 s and six retries available. +const http_deadline_ms: u64 = 20_000; + +// ================================================================================ resources + +/// Twelve task slots. Sizing this too small does NOT fail loudly: `io.async` with no free slot runs +/// the body eagerly instead of returning an error, so a reader task that should loop forever runs +/// once at spawn and is never seen again. ESP-Hosted spawns seven for the transport plus RPC's. +var pool: p4.Static(12, 2048) = .{}; + +/// ESP-Hosted's heap. examples/radio.zig measured the transport and RPC at well under 32 KiB with +/// the SDIO queues at 4/4; the station channel adds one 1,536-byte aligned transmit buffer in +/// flight per queued frame, and each received frame is a `payload_len` allocation freed by +/// `link.onRxFrame` before the next is dispatched. HTTP_HEAP prints what was really used. +var heap_backing: [70 * 1024]u8 align(8) = undefined; + +// ==================================================================================== state + +var associated: bool = false; +var disconnects: u32 = 0; +var bringup_result: ?anyerror = null; +var bringup_done: bool = false; + +/// ESP-Hosted's Wi-Fi RPC, through the C shim in src/net/hosted/wifi_shim.c. The structs stay in C +/// on purpose; see that file's header. +extern fn hosted_wifi_sta_start() c_int; +extern fn hosted_wifi_connect(ssid: [*:0]const u8, psk: [*:0]const u8) c_int; + +/// NUL-terminated credential copies for the C ABI, sized to the maxima `wifi_config_t` itself uses. +/// File scope rather than local because the retry loop below re-issues the request and must pass the +/// same bytes; the passphrase is never printed and never written anywhere else. +var ssid_buf: [33]u8 = @splat(0); +var psk_buf: [65]u8 = @splat(0); + +/// `WIFI_EVENT_STA_CONNECTED`. The C6 reported this as `base=wifi id=4` on the run that proved +/// association; `id=5` beside it is `WIFI_EVENT_STA_DISCONNECTED`. +const wifi_event_sta_connected: i32 = 4; +const wifi_event_sta_disconnected: i32 = 5; + +fn bringUp(ctx: struct { io: std.Io, gpa: std.mem.Allocator }) void { + net.init(ctx.io, ctx.gpa) catch |err| { + bringup_result = err; + bringup_done = true; + return; + }; + bringup_done = true; +} + +fn onEvent(ev: net.port.Event) void { + const base_name: [*:0]const u8 = switch (ev.base) { + .wifi => "wifi", + .named => |n| n, + }; + soc.rom.print("MARK HTTP_EVENT base=%s id=%d len=%u\r\n", .{ + base_name, + ev.id, + @as(u32, @intCast(if (ev.data) |d| d.len else 0)), + }); + if (ev.base == .wifi) { + if (ev.id == wifi_event_sta_connected) associated = true; + // A disconnect after association is worth counting rather than acting on: the C6 retries on + // its own, and a stack that tore itself down on every roam would be less useful than one + // that says how many times it happened. + if (ev.id == wifi_event_sta_disconnected) { + disconnects += 1; + // The reason code is the whole diagnostic value of this event: without it a refused + // association is indistinguishable from an access point that was never there. Layout is + // `wifi_event_sta_disconnected_t` - ssid[32], ssid_len, bssid[6], reason, rssi - so 41 + // bytes with reason at offset 39. Length-checked rather than assumed, because another + // IDF version would move it. + if (ev.data) |d| { + if (d.len >= 41) { + const reason = d[39]; + const rssi: i8 = @bitCast(d[40]); + soc.rom.print("MARK HTTP_DISCONNECT reason=%u rssi=%d %s\r\n", .{ + @as(u32, reason), + @as(i32, rssi), + reasonName(reason), + }); + } else { + soc.rom.print("MARK HTTP_DISCONNECT payload=%u B, expected 41\r\n", .{ + @as(u32, @intCast(d.len)), + }); + } + } + } + } +} + +/// The disconnect reasons that actually occur during bring-up, named. From `wifi_err_reason_t` +/// (esp_wifi_types_generic.h). Anything else prints its number, which is more useful than a wrong +/// guess at a name. +fn reasonName(reason: u8) [*:0]const u8 { + return switch (reason) { + 2 => "AUTH_EXPIRE", + 4 => "ASSOC_EXPIRE", + 15 => "4WAY_HANDSHAKE_TIMEOUT - almost always a wrong passphrase", + 23 => "802_1X_AUTH_FAILED", + 200 => "BEACON_TIMEOUT", + 201 => "NO_AP_FOUND - wrong SSID, or not on a channel the C6 can see", + 202 => "AUTH_FAIL", + 203 => "ASSOC_FAIL", + 204 => "HANDSHAKE_TIMEOUT", + 205 => "CONNECTION_FAIL", + else => "see wifi_err_reason_t", + }; +} + +/// Reset entry. The bootloader hands over with an unspecified stack pointer and the FPU off, so: +/// enable the F extension (mstatus.FS = Initial), establish the stack, clear .bss, then enter Zig. +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} + +export fn zig_main() noreturn { + // The bootloader leaves the RTC watchdog armed and expects the application to take it over. + // Nothing here feeds it, and this program deliberately runs for minutes. + const wdt_was_armed = hal.rwdt.armed(); + const wdt_off = hal.rwdt.disable(); + soc.rom.print("MARK HTTP_WDT armed_at_entry=%u disabled=%u\r\n", .{ + @as(u32, @intFromBool(wdt_was_armed)), + @as(u32, @intFromBool(wdt_off)), + }); + + // Two independent clocks over one interval: the systimer is a fixed 16 MHz, so the CPU + // frequency falls out of the ratio. Everything above assumes the bootloader's 90 MHz. + const t0 = hal.systimer.read(.unit0) orelse 0; + const c0 = soc.cycles(); + soc.rom.ets_delay_us(10_000); + const t1 = hal.systimer.read(.unit0) orelse 0; + const c1 = soc.cycles(); + const cpu_khz: u64 = if (t1 > t0) ((c1 - c0) * (hal.systimer.hz / 1000)) / (t1 - t0) else 0; + soc.rom.print("\r\nMARK HTTP_START cpu=%u kHz\r\n", .{@as(u32, @truncate(cpu_khz))}); + + const runtime = pool.init(.{}); + const io = runtime.io(); + + var backing = net.heap.Heap.init(&heap_backing); + const gpa = backing.allocator(); + + net.port.setEventHandler(&onEvent); + + // Bring-up runs on its own task: `transport_drv_reconfigure` blocks in a 200 ms retry loop + // waiting for the slave, so a main task inside it could not print. With it elsewhere, the + // heartbeat below distinguishes "the transport is stuck" from "the scheduler is stuck". + var bringup = io.async(bringUp, .{.{ .io = io, .gpa = gpa }}); + soc.rom.print("MARK HTTP_SETUP dispatched\r\n", .{}); + + radioUp(runtime); + bringup.cancel(io); + + // The station channel, and the IP stack behind it. Before the association request rather than + // after, so there is never a window in which the AP's traffic arrives with nothing to consume + // it - that window is exactly what produced `task still writing Rx data to queue!`. + wifiStart(); + linkUp(); + join(runtime); + dhcp(runtime); + pingWindow(runtime); + httpGet(runtime); + internetGet(runtime); + live(runtime); +} + +// ============================================================================= 1. the radio + +fn radioUp(runtime: *p4.Runtime) void { + const started = nowMs(); + var last_report: u64 = 0; + while (!net.isUp()) { + runtime.yield(); + const elapsed = nowMs() - started; + if (elapsed - last_report >= 1000) { + last_report = elapsed; + const s = net.port.stats(); + soc.rom.print("MARK HTTP_TICK t=%u ms heap=%u B blocks=%u stubs=%u done=%u\r\n", .{ + @as(u32, @intCast(elapsed)), + @as(u32, @intCast(s.bytes_live)), + @as(u32, @intCast(s.blocks_live)), + s.stub_calls, + @as(u32, @intFromBool(bringup_done)), + }); + } + if (bringup_done) { + if (bringup_result) |err| fail("radio", @errorName(err)); + } + if (elapsed > radio_deadline_ms) { + soc.rom.print("MARK HTTP_FAIL radio timeout after %u ms (slave never answered)\r\n", .{ + @as(u32, @intCast(elapsed)), + }); + park(); + } + } + soc.rom.print("MARK HTTP_RADIO_UP after %u ms\r\n", .{@as(u32, @intCast(nowMs() - started))}); +} + +// ========================================================================== 2. the station + +fn wifiStart() void { + // `spun` counts ESP-Hosted's RPC not-ready spins across the call. Both `rpc_rx_thread` and + // `rpc_tx_thread` open their loop with `if (!is_rpc_lib_ready()) _h_sleep(1)` + // (rpc_core.c:482-485, :543-547) and those are the only `_h_sleep` callers linked here, so a + // non-zero value means the request was enqueued and never transmitted - a completely different + // failure from the coprocessor refusing it. + const before = net.port.stats().hosted_sleep_calls; + const rc = hosted_wifi_sta_start(); + const after = net.port.stats().hosted_sleep_calls; + soc.rom.print("MARK HTTP_WIFI_START rc=%d spun=%u\r\n", .{ rc, @as(u32, after - before) }); + if (rc != 0) fail("wifi_start", "rpc_wifi_start refused"); +} + +fn linkUp() void { + net.link.open() catch |err| fail("link", @errorName(err)); + const m = net.link.mac(); + soc.rom.print("MARK HTTP_LINK mac=%02x:%02x:%02x:%02x:%02x:%02x foot=%u B\r\n", .{ + @as(u32, m[0]), @as(u32, m[1]), @as(u32, m[2]), + @as(u32, m[3]), @as(u32, m[4]), @as(u32, m[5]), + @as(u32, net.link.footprint), + }); +} + +fn join(runtime: *p4.Runtime) void { + if (config.wifi_ssid.len == 0) { + soc.rom.print("MARK HTTP_FAIL join: no -Dssid given, nothing to associate with\r\n", .{}); + park(); + } + if (config.wifi_ssid.len > 32 or config.wifi_psk.len > 64) { + soc.rom.print("MARK HTTP_FAIL join: ssid or psk longer than 802.11 allows\r\n", .{}); + park(); + } + // NUL-terminated copies for the C ABI, sized to the maxima `wifi_config_t` itself uses. + @memcpy(ssid_buf[0..config.wifi_ssid.len], config.wifi_ssid); + @memcpy(psk_buf[0..config.wifi_psk.len], config.wifi_psk); + + // The SSID is printed; the passphrase is not, and only its length is - enough to tell a missing + // -Dpsk-file from a wrong one without putting the secret on a serial line. + soc.rom.print("MARK HTTP_JOIN ssid=%s psk_len=%u\r\n", .{ + @as([*:0]const u8, @ptrCast(&ssid_buf)), + @as(u32, @intCast(config.wifi_psk.len)), + }); + + // Already associated? The C6 keeps its association across a host reset, and radio.zig may have + // left one behind. Asking again is harmless and is what makes this file runnable twice. + const rc = hosted_wifi_connect(@ptrCast(&ssid_buf), @ptrCast(&psk_buf)); + soc.rom.print("MARK HTTP_CONNECT rc=%d\r\n", .{rc}); + if (rc != 0) fail("connect", "rpc_wifi_connect refused"); + + // Association is asynchronous: the request is answered at once and the outcome arrives as an + // event. Keep the scheduler running and bound the wait. + // + // Two conditions end this wait, not one. The event is the direct evidence. Received station + // traffic is the *indirect* evidence and it is just as conclusive: an AP does not forward + // broadcasts to a station that is not associated with it. The second condition exists because + // the C6 keeps its association across a host reset - examples/radio.zig may have left one + // behind - and a `connect` request that finds the radio already on this SSID need not produce + // a fresh id=4. Without it, the commonest happy case would time out with a misleading reason. + const started = nowMs(); + var why: [*:0]const u8 = "event"; + // Retry, because a single refusal is normal on a real network rather than a failure. + // + // Measured on this board: the same passphrase and SSID associate on some attempts and are + // refused on others with reason=4 ASSOC_EXPIRE at about -68 dBm. That is the AP expiring the + // association, not a credential problem - reason 15 would say wrong passphrase - and giving up + // on the first one made a working stack look broken half the time. Re-issuing the request is + // what any supplicant does. + var attempts: u32 = 1; + var seen_disconnects = disconnects; + while (!associated) { + drive(runtime); + if (net.link.ipCounters().rx_frames > 0) { + why = "traffic"; + break; + } + + // A new disconnect while still unassociated means this attempt is over; start another + // rather than waiting out a deadline that cannot now be met. + if (disconnects != seen_disconnects) { + seen_disconnects = disconnects; + if (attempts < assoc_attempts) { + attempts += 1; + // Back off before asking again, and this matters more than the attempt count. + // + // Retrying immediately made things worse, not better: ten back-to-back attempts + // produced an alternating run of reason=205 CONNECTION_FAIL at rssi=-128 and + // reason=15 4WAY_HANDSHAKE_TIMEOUT at rssi=-58 - a strong signal and a failed + // handshake, with a passphrase that had associated successfully minutes earlier. + // That pattern is an access point refusing a client that is hammering it, not a + // credential problem: reason 15 would otherwise mean a wrong passphrase, and + // psk_len proves the bytes are unchanged. + // + // Three seconds is longer than the AP's own handshake timeout, so each attempt is a + // fresh one rather than a collision with the last. + const backoff_started = nowMs(); + while (nowMs() - backoff_started < assoc_backoff_ms) drive(runtime); + soc.rom.print("MARK HTTP_RETRY attempt %u of %u after %u ms backoff\r\n", .{ + attempts, + assoc_attempts, + @as(u32, @intCast(assoc_backoff_ms)), + }); + if (hosted_wifi_connect(@ptrCast(&ssid_buf), @ptrCast(&psk_buf)) != 0) { + fail("connect", "rpc_wifi_connect refused on retry"); + } + } + } + + const elapsed = nowMs() - started; + if (elapsed > assoc_deadline_ms) { + soc.rom.print( + "MARK HTTP_FAIL assoc timeout after %u ms (attempts=%u, disconnects=%u, no id=4, no frames)\r\n", + .{ @as(u32, @intCast(elapsed)), attempts, disconnects }, + ); + park(); + } + } + soc.rom.print("MARK HTTP_ASSOC after %u ms by=%s rx=%u\r\n", .{ + @as(u32, @intCast(nowMs() - started)), + why, + net.link.ipCounters().rx_frames, + }); +} + +// ================================================================================== 3. DHCP + +fn dhcp(runtime: *p4.Runtime) void { + // `dhcpStart` stamps the acquisition's start from the stack's idea of now, and only `tick` + // sets that. One tick first, therefore, or every DHCP deadline is measured from zero. + _ = net.link.tick(nowMs()); + if (!net.link.dhcpStart()) fail("dhcp", "stack busy at dhcpStart, which cannot happen here"); + soc.rom.print("MARK HTTP_DHCP_TX discover sent\r\n", .{}); + + const started = nowMs(); + var last_report: u64 = 0; + while (net.link.address() == null) { + drive(runtime); + const elapsed = nowMs() - started; + if (elapsed - last_report >= 1000) { + last_report = elapsed; + const c = net.link.ipCounters(); + const l = net.link.stats(); + soc.rom.print( + "MARK HTTP_DHCP_WAIT t=%u state=%s rx=%u drop=%u csum=%u tx=%u dhcp_rx=%u re=%u\r\n", + .{ + @as(u32, @intCast(elapsed)), + @tagName(net.link.dhcpState()).ptr, + c.rx_frames, + c.rx_dropped, + c.checksum_bad, + c.tx_frames, + c.dhcp_rx, + l.rx_reentrant, + }, + ); + } + if (elapsed > dhcp_deadline_ms) { + const c = net.link.ipCounters(); + soc.rom.print( + "MARK HTTP_FAIL dhcp timeout after %u ms state=%s sent=%u got=%u rx=%u drop=%u\r\n", + .{ + @as(u32, @intCast(elapsed)), + @tagName(net.link.dhcpState()).ptr, + c.dhcp_tx, + c.dhcp_rx, + c.rx_frames, + c.rx_dropped, + }, + ); + park(); + } + } + + const a = net.link.address().?; + const m = net.link.netmask(); + const g = net.link.gateway(); + const d = net.link.dnsServer() orelse @as([4]u8, @splat(0)); + // Two lines rather than one seventeen-argument line. `ets_printf` is the mask ROM's, taking + // its arguments the ordinary variadic way - eight in registers and the rest on the stack - and + // there is no reason to be the first caller in this repo to find out where its limit is. + soc.rom.print("MARK HTTP_IP ip=%u.%u.%u.%u mask=%u.%u.%u.%u\r\n", .{ + @as(u32, a[0]), @as(u32, a[1]), @as(u32, a[2]), @as(u32, a[3]), + @as(u32, m[0]), @as(u32, m[1]), @as(u32, m[2]), @as(u32, m[3]), + }); + soc.rom.print("MARK HTTP_ROUTE gw=%u.%u.%u.%u dns=%u.%u.%u.%u in %u ms\r\n", .{ + @as(u32, g[0]), @as(u32, g[1]), @as(u32, g[2]), @as(u32, g[3]), + @as(u32, d[0]), @as(u32, d[1]), @as(u32, d[2]), @as(u32, d[3]), + @as(u32, @intCast(nowMs() - started)), + }); + heapReport(); +} + +// ================================================================================== 4. ICMP + +/// Yield, and tick the IP stack at most every `tick_interval_ms`. +/// +/// The rate limit is the whole point. `link.tick` holds the stack's re-entrancy guard for its +/// duration, and a frame that arrives while the guard is held is dropped - ESP-Hosted's receive task +/// and this one are different tasks, so they genuinely collide. A loop of the obvious shape, +/// +/// while (...) { runtime.yield(); _ = net.link.tick(nowMs()); } +/// +/// ticks thousands of times a second, holds the guard for most of the elapsed time, and drops much +/// of the traffic it is waiting for. Measured on the board: 40 dropped frames out of 113 received, +/// and ping answered at about 40%, even though every reply that was attempted did arrive. +/// +/// Five milliseconds is far finer than anything ip.zig needs - its timers are absolute deadlines, so +/// a late tick is late rather than lost - and it leaves the guard clear almost all the time. +fn drive(runtime: *p4.Runtime) void { + runtime.yield(); + const now = nowMs(); + if (now - last_tick_ms >= tick_interval_ms) { + last_tick_ms = now; + _ = net.link.tick(now); + } +} + +const tick_interval_ms: u64 = 5; +var last_tick_ms: u64 = 0; + +fn pingWindow(runtime: *p4.Runtime) void { + const a = net.link.address().?; + soc.rom.print( + "MARK HTTP_PING_OPEN ip=%u.%u.%u.%u for %u ms - ping it now\r\n", + .{ + @as(u32, a[0]), + @as(u32, a[1]), + @as(u32, a[2]), + @as(u32, a[3]), + @as(u32, @intCast(ping_window_ms)), + }, + ); + + const started = nowMs(); + var seen: u32 = net.link.ipCounters().icmp_echo; + var last_report: u64 = 0; + while (true) { + drive(runtime); + const c = net.link.ipCounters(); + if (c.icmp_echo != seen) { + seen = c.icmp_echo; + // One line per echo answered. `arp` beside it is what proves the exchange was two-way: + // the workstation had to ARP for this address and get an answer before it could send + // the echo at all. + soc.rom.print("MARK HTTP_PING n=%u arp_rx=%u arp_tx=%u\r\n", .{ + seen, + c.arp_rx, + c.arp_tx, + }); + } + const elapsed = nowMs() - started; + if (elapsed - last_report >= 5000) { + last_report = elapsed; + // Heap included deliberately. The board reported "mempool OOM start (RX)" at ~13 s in a + // previous run: with the pool off, ESP-Hosted allocates every received frame from our + // heap via `_h_malloc_align(1536, 64)`, and when that fails the receive path simply + // stops delivering. `live` climbing while `rx` is static means a leak; `live` pinned + // near the heap size with `rx` frozen means a heap too small for the queue depths. + // Without both numbers side by side those two are indistinguishable. + const h = net.port.stats(); + soc.rom.print( + "MARK HTTP_PING_IDLE t=%u echo=%u rx=%u drop=%u tx=%u live=%u B blocks=%u fails=%u\r\n", + .{ + @as(u32, @intCast(elapsed)), + c.icmp_echo, + c.rx_frames, + c.rx_dropped, + c.tx_frames, + @as(u32, @intCast(h.bytes_live)), + @as(u32, @intCast(h.blocks_live)), + @as(u32, @intCast(h.alloc_failures)), + }, + ); + } + if (elapsed > ping_window_ms) break; + } + soc.rom.print("MARK HTTP_PING_DONE echoes=%u\r\n", .{net.link.ipCounters().icmp_echo}); +} + +// ================================================================================== 5. HTTP + +/// The response body. Static rather than on the stack because `httpGet` borrows it for the whole +/// request - the body is written into it from inside the receive callback, on a different task - +/// and a task stack is 4 KiB. +var body: [2048]u8 = undefined; + +fn httpGet(runtime: *p4.Runtime) void { + soc.rom.print("MARK HTTP_GET host=%u.%u.%u.%u port=%u path=%s\r\n", .{ + @as(u32, http_host[0]), @as(u32, http_host[1]), + @as(u32, http_host[2]), @as(u32, http_host[3]), + @as(u32, http_port), @as([*:0]const u8, http_path), + }); + + const started = nowMs(); + var last_report: u64 = 0; + const got: usize = while (true) { + drive(runtime); + // Identical arguments every call, and `body` never moves: that is the whole of the + // WouldBlock protocol. Different arguments mid-flight would return error.Busy instead. + if (net.link.httpGet(http_host, http_port, http_path, &body)) |n| { + break n; + } else |err| switch (err) { + error.WouldBlock => {}, + else => { + soc.rom.print("MARK HTTP_FAIL get=%s tcp=%s after %u ms\r\n", .{ + @errorName(err).ptr, + @tagName(net.link.tcpState()).ptr, + @as(u32, @intCast(nowMs() - started)), + }); + park(); + }, + } + const elapsed = nowMs() - started; + if (elapsed - last_report >= 2000) { + last_report = elapsed; + const c = net.link.ipCounters(); + soc.rom.print("MARK HTTP_WAIT t=%u tcp=%s tx=%u retx=%u rx=%u rst=%u\r\n", .{ + @as(u32, @intCast(elapsed)), + @tagName(net.link.tcpState()).ptr, + c.tcp_tx, + c.tcp_retx, + c.tcp_rx, + c.tcp_rst_rx, + }); + } + if (elapsed > http_deadline_ms) { + const c = net.link.ipCounters(); + soc.rom.print( + "MARK HTTP_FAIL get timeout after %u ms tcp=%s arp_tx=%u tcp_tx=%u tcp_rx=%u\r\n", + .{ + @as(u32, @intCast(elapsed)), + @tagName(net.link.tcpState()).ptr, + c.arp_tx, + c.tcp_tx, + c.tcp_rx, + }, + ); + park(); + } + }; + + soc.rom.print("MARK HTTP_STATUS code=%u len=%u in %u ms\r\n", .{ + @as(u32, net.link.httpStatus()), + @as(u32, @intCast(got)), + @as(u32, @intCast(nowMs() - started)), + }); + printBody(body[0..got]); + heapReport(); +} + +/// The first bytes of the body, on one line, with anything that is not printable ASCII shown as +/// '.'. A response body is arbitrary bytes and this is a serial console: a stray 0x0d would split +/// the line and a 0x00 would truncate it, and either would look like a short read. +fn printBody(bytes: []const u8) void { + const preview_max = 120; + var buf: [preview_max + 1]u8 = undefined; + const n = @min(bytes.len, preview_max); + for (bytes[0..n], 0..) |b, i| buf[i] = if (b >= 0x20 and b < 0x7f) b else '.'; + buf[n] = 0; + soc.rom.print("MARK HTTP_BODY %u/%u |%s|\r\n", .{ + @as(u32, @intCast(n)), + @as(u32, @intCast(bytes.len)), + @as([*:0]const u8, @ptrCast(&buf)), + }); +} + +// ============================================================================== 6. stay live + +/// Keep running. The transport's threads must keep being scheduled, the stack keeps answering ICMP, +/// and leaving the board in a live state is what lets the next experiment start from here. +/// A real host on the real internet: resolve a name, then fetch it. +/// +/// A strictly harder test than the GET against this workstation, and every extra thing it exercises +/// is one the local test could not: +/// +/// * DNS. The name is resolved over UDP against the server DHCP handed us - on this network the +/// gateway - so the resolver, the wire format and its name-compression handling are all in play. +/// * Off-subnet routing. 0x4200.cafe is not on 192.168.1.0/24, so the stack has to ARP for the +/// GATEWAY and send to its MAC while the IP header addresses the far host. The local test never +/// leaves the subnet and so never proved that. +/// * Name-based virtual hosting. The site is behind Cloudflare, which serves it only for a request +/// carrying `Host: 0x4200.cafe`. `Host: 104.21.46.8` gets someone else's error page - which is +/// the entire reason `httpGetHost` exists. +/// * Chunked transfer encoding. Measured from a workstation the response is +/// `Transfer-Encoding: chunked` with no Content-Length, so the body arrives in framed pieces +/// whose boundaries fall wherever TCP puts them. +/// +/// The lines, and what each means: +/// +/// MARK NET_DNS name -> a.b.c.d in N ms the resolver worked end to end +/// bad: failed=Timeout no reply from the DHCP-supplied server inside the bound +/// failed=NoAddress no A record (the name does have AAAA; this stack is IPv4) +/// failed=Malformed a reply arrived and was rejected +/// MARK NET_GET host=... via gw=... the request begins, naming the next hop +/// MARK NET_STATUS code=200 len=N in M ms a real page came back +/// bad: get=HttpChunkMalformed chunked framing rejected +/// get=StreamTooLong the page is bigger than the buffer here - not a stack bug; it +/// means this buffer is small, and this says so rather than truncating +/// MARK NET_BODY n/N |...| first bytes, non-printables as '.' +const internet_name = "0x4200.cafe"; + +/// 2 KiB, which is what the target resource needs and no more. +/// +/// The site's root page is 132,932 bytes decoded - larger than this board's entire 128 KB of L2MEM, +/// so it cannot be buffered whole by anything running here and `StreamTooLong` is the correct answer +/// for asking. Fetching it would need a streaming API that hands the caller each chunk as it arrives +/// and keeps none of it, which this stack does not have. That is a real limitation and it is stated +/// rather than hidden. +/// +/// `/robots.txt` on the same host is 1,248 bytes and exercises everything the root page would about +/// the path being tested here: the name is resolved by DNS, the destination is off-subnet so the +/// frame goes to the gateway's MAC, and the response only comes back at all because the request +/// carries `Host: 0x4200.cafe`. +var net_body: [2048]u8 = undefined; + +/// The path fetched. See `net_body` for why it is not `/`. +const internet_path = "/robots.txt"; + +fn internetGet(runtime: *p4.Runtime) void { + // 1. Resolve. Same WouldBlock protocol as httpGet: identical argument every call, drive between. + const dns_started = nowMs(); + const addr: [4]u8 = while (true) { + drive(runtime); + if (net.link.resolve(internet_name)) |a| { + break a; + } else |err| switch (err) { + error.WouldBlock => {}, + else => { + soc.rom.print("MARK NET_DNS %s failed=%s after %u ms\r\n", .{ + internet_name.ptr, + @errorName(err).ptr, + @as(u32, @intCast(nowMs() - dns_started)), + }); + return; + }, + } + if (nowMs() - dns_started > 15_000) { + soc.rom.print("MARK NET_DNS %s gave up after %u ms\r\n", .{ + internet_name.ptr, + @as(u32, @intCast(nowMs() - dns_started)), + }); + return; + } + }; + soc.rom.print("MARK NET_DNS %s -> %u.%u.%u.%u in %u ms\r\n", .{ + internet_name.ptr, + @as(u32, addr[0]), + @as(u32, addr[1]), + @as(u32, addr[2]), + @as(u32, addr[3]), + @as(u32, @intCast(nowMs() - dns_started)), + }); + + // The gateway is printed because it is the thing under test here: for an off-subnet destination + // the Ethernet frame goes to the gateway's MAC while the IP header addresses the far host, and a + // stack that got that wrong would look like a dead internet rather than a routing bug. + const gw = net.link.gateway(); + soc.rom.print("MARK NET_GET host=%s%s via gw=%u.%u.%u.%u\r\n", .{ + internet_name.ptr, + internet_path.ptr, + @as(u32, gw[0]), + @as(u32, gw[1]), + @as(u32, gw[2]), + @as(u32, gw[3]), + }); + + // 2. Fetch, with the NAME in the Host header rather than the address. + const started = nowMs(); + var last_report: u64 = 0; + const got: usize = while (true) { + drive(runtime); + if (net.link.httpGetHost(addr, internet_name, 80, internet_path, &net_body)) |n| { + break n; + } else |err| switch (err) { + error.WouldBlock => {}, + else => { + soc.rom.print("MARK NET_FAIL get=%s tcp=%s after %u ms\r\n", .{ + @errorName(err).ptr, + @tagName(net.link.tcpState()).ptr, + @as(u32, @intCast(nowMs() - started)), + }); + return; + }, + } + const elapsed = nowMs() - started; + if (elapsed - last_report >= 2000) { + last_report = elapsed; + soc.rom.print("MARK NET_WAIT t=%u tcp=%s\r\n", .{ + @as(u32, @intCast(elapsed)), + @tagName(net.link.tcpState()).ptr, + }); + } + if (elapsed > 30_000) { + soc.rom.print("MARK NET_FAIL timeout tcp=%s\r\n", .{@tagName(net.link.tcpState()).ptr}); + return; + } + }; + + soc.rom.print("MARK NET_STATUS code=%u len=%u in %u ms\r\n", .{ + @as(u32, net.link.httpStatus()), + @as(u32, @intCast(got)), + @as(u32, @intCast(nowMs() - started)), + }); + // First bytes only, printable-filtered: this is a serial line and an HTML page is not a log. + var shown: [96]u8 = undefined; + const n = @min(got, shown.len - 1); + for (0..n) |i| { + const c = net_body[i]; + shown[i] = if (c >= 0x20 and c < 0x7f) c else '.'; + } + shown[n] = 0; + soc.rom.print("MARK NET_BODY %u/%u |%s|\r\n", .{ + @as(u32, @intCast(n)), + @as(u32, @intCast(got)), + @as([*:0]const u8, @ptrCast(&shown)), + }); +} + +fn live(runtime: *p4.Runtime) noreturn { + var last: u64 = 0; + var last_echo: u32 = 0; + while (true) { + drive(runtime); + const t = nowMs(); + if (t - last >= 1000) { + last = t; + const c = net.link.ipCounters(); + const l = net.link.stats(); + soc.rom.print( + "MARK HTTP_LIVE t=%u echo=%u(+%u) rx=%u drop=%u tx=%u txfail=%u re=%u skip=%u\r\n", + .{ + @as(u32, @intCast(t / 1000)), + c.icmp_echo, + c.icmp_echo - last_echo, + c.rx_frames, + c.rx_dropped, + l.tx_frames, + l.tx_failed, + l.rx_reentrant, + l.tick_skipped, + }, + ); + last_echo = c.icmp_echo; + } + } +} + +// =================================================================================== shared + +fn heapReport() void { + const s = net.port.stats(); + soc.rom.print("MARK HTTP_HEAP live=%u B reserved=%u B peak=%u B blocks=%u fails=%u\r\n", .{ + @as(u32, @intCast(s.bytes_live)), + @as(u32, @intCast(s.bytes_reserved)), + @as(u32, @intCast(s.peak_reserved)), + @as(u32, @intCast(s.blocks_live)), + @as(u32, @intCast(s.alloc_failures)), + }); +} + +fn fail(comptime what: []const u8, why: [*:0]const u8) noreturn { + soc.rom.print("MARK HTTP_FAIL " ++ what ++ "=%s\r\n", .{why}); + park(); +} + +fn nowMs() u64 { + // The systimer is a fixed 16 MHz and the only trustworthy timebase here: the CPU runs at the + // bootloader's 90 MHz and nothing in this image reconfigures the PLL. A failed snapshot read + // yields 0, which makes an elapsed calculation conservative rather than wrong. + const ticks = hal.systimer.read(.unit0) orelse return 0; + return ticks / 16_000; +} + +/// `while (true) {}` rather than a reset, so the last message stays on screen instead of scrolling +/// past in a reboot loop. Note that this stops the scheduler too: nothing here is recoverable. +fn park() noreturn { + soc.rom.print("MARK HTTP_DONE parked\r\n", .{}); + while (true) {} +} diff --git a/examples/intrcheck.zig b/examples/intrcheck.zig new file mode 100644 index 0000000..278ee8e --- /dev/null +++ b/examples/intrcheck.zig @@ -0,0 +1,269 @@ +//! Does an interrupt actually get taken? The one question the differential harness cannot answer. +//! +//! zig build -Dapp=examples/intrcheck.zig run -Dseconds=10 +//! +//! The register differential proves that `hal.intr`'s writes land in the same registers ESP-IDF's do. +//! It cannot prove that the CLIC then delivers anything, because delivery leaves no trace in any +//! register it photographs: mtvec and MTVT are CSRs, the vector table is memory, and whether the +//! core vectored to the right handler is a fact about control flow. +//! +//! So this is the behavioural half, and it is deliberately arranged so each failure mode prints +//! something different rather than all of them looking like a silent hang: +//! +//! * counter 0 and pending 1 - the CLIC latched it and the core never took it: mtvec, MTVT or MIE. +//! * counter 0 and pending 0 - never latched: the matrix write missed, or the timer never fired +//! (which the raw status distinguishes). +//! * counter > 1 - the handler returned without clearing the source, and a level +//! interrupt re-enters forever. On this chip the CLIC has no +//! acknowledge for a level source, so clearing at the peripheral is +//! the only way out, and forgetting it looks exactly like a crash. +//! * spurious > 0 - an interrupt arrived on a line nobody claimed: a routing write +//! went somewhere unintended. +//! +//! The second phase is the sharper test, and it is the claim the whole CLIC port is least able to +//! support any other way: raise the threshold *above* the line's priority, confirm the interrupt +//! latches but is not delivered, then lower it and confirm the pending interrupt arrives. That is +//! what shows the memory-mapped threshold register at 0x2080_0008 is the one the arbiter reads - +//! rather than the `mintthresh` CSR, which on this die accepts writes and does nothing. +//! +//! TIMG1's interrupt-enable and interrupt-clear registers are reached here through `regs` directly, +//! because `hal.timg` deliberately does not model interrupts. That is the register layer doing its +//! job: a peripheral the HAL has not covered yet is still fully addressable. + +const std = @import("std"); +const soc = @import("soc"); +const hal = @import("hal"); +const regs = @import("regs"); +const mmio = @import("mmio"); + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK INTR_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +/// TIMG1's timer-0 alarm interrupt. Group index 1. +const timg1_int_ena = mmio.Reg.atAddress(@intCast(regs.TIMG_INT_ENA_TIMERS_REG(1))); +const timg1_int_raw = mmio.Reg.atAddress(@intCast(regs.TIMG_INT_RAW_TIMERS_REG(1))); +const timg1_int_clr = mmio.Reg.atAddress(@intCast(regs.TIMG_INT_CLR_TIMERS_REG(1))); +const t0_int_ena = mmio.Field.of(regs.TIMG_T0_INT_ENA_S, regs.TIMG_T0_INT_ENA_V); +const t0_int_raw = mmio.Field.of(regs.TIMG_T0_INT_RAW_S, regs.TIMG_T0_INT_RAW_V); +const t0_int_clr = mmio.Field.of(regs.TIMG_T0_INT_CLR_S, regs.TIMG_T0_INT_CLR_V); + +/// The CLIC line under test. 5 is arbitrary and free; the differential suite uses 5 and 24. +const line: u5 = 5; + +var fired: u32 = 0; + +fn onAlarm(l: u5) void { + fired += 1; + // Two things, and both are needed to return exactly once. + // + // Clear at the *peripheral*: a level-triggered source stays asserted until the peripheral + // deasserts it, and this chip's CLIC offers no acknowledge for one, so a handler that returns + // without clearing re-enters immediately and forever with the console silent. + // + // Then disable the alarm. Clearing the status alone is not enough: with auto-reload off the + // counter keeps running past the alarm value, the comparator stays satisfied, and the interrupt + // is re-asserted as fast as it is cleared. That is the same silent re-entry by a different + // route, and it is what this test hit first. + // Mask globally first, before anything else. Any handler that can be re-entered before it has + // deasserted its source is one console-silent hang away from being undiagnosable, and this test + // exists to distinguish failure modes rather than to demonstrate a tidy handler. + hal.intr.globalDisable(); + timg1_int_clr.write(.{t0_int_clr.is(1)}); + hal.timg.setAlarmEnabled(.timg1, .t0, false); + _ = l; +} + +fn armTimer(alarm_ticks: u64) void { + hal.clkrst.setClockEnabled(.timg1, true); + hal.clkrst.resetPeripheral(.timg1); + // 40 MHz APB with a divider of 400 gives 100 kHz, so the alarm value is in units of 10 us. + hal.timg.setDivider(.timg1, .t0, 400); + hal.timg.setAutoReload(.timg1, .t0, false); + hal.timg.setAlarmValue(.timg1, .t0, alarm_ticks); + hal.timg.load(.timg1, .t0); + timg1_int_ena.modify(.{t0_int_ena.is(1)}); + hal.timg.setAlarmEnabled(.timg1, .t0, true); + hal.timg.setCounterEnabled(.timg1, .t0, true); +} + +fn disarmTimer() void { + hal.timg.setCounterEnabled(.timg1, .t0, false); + hal.timg.setAlarmEnabled(.timg1, .t0, false); + timg1_int_ena.modify(.{t0_int_ena.is(0)}); + timg1_int_clr.write(.{t0_int_clr.is(1)}); +} + +export fn zig_main() noreturn { + // Without this the board resets about ten seconds in, mid-test. + _ = hal.rwdt.disable(); + + soc.rom.print("\r\nMARK INTR_START clic behavioural test\r\n", .{}); + soc.rom.print("MARK INTR_CFG mtvt_csr=0x%x mintstatus_csr=0x%x nlbits=%u ext_offset=%u\r\n", .{ + @as(u32, hal.intr.mtvt_csr), + @as(u32, hal.intr.mintstatus_csr), + @as(u32, hal.intr.NLBITS), + @as(u32, hal.intr.ext_offset), + }); + + // The bootloader hands over with mstatus.MIE set - `init()` masks it, and this records what it + // found, because that fact is what makes the ordering below matter at all. + const mie_at_boot = hal.intr.globalEnabled(); + + // A parked core is silent, and every mistake in a trap handler parks the core. This hook is the + // difference between a diagnosis and a reflash. + hal.intr.on_fault = struct { + fn f(x: hal.intr.Fault) void { + soc.rom.print("MARK INTR_FAULT mcause=0x%08x mepc=0x%08x mtval=0x%08x taken=%u last_id=%u fired=%u\r\n", .{ + x.mcause, x.mepc, x.mtval, hal.intr.taken, @as(u32, hal.intr.last_clic_id), fired, + }); + } + }.f; + + hal.intr.init(); + // What the ROM left behind, captured before init() cleared it. A non-zero enabled_lines is the + // whole explanation for the first version of this test hanging: the ROM hands over with lines + // armed and MIE set, so the first globalEnable() delivers someone else's interrupt to a handler + // that does not exist, and a level source then re-enters forever. + soc.rom.print("MARK INTR_BOOT mie=%u rom_enabled_lines=0x%08x rom_routed_sources=%u mtvec=0x%08x mtvt=0x%08x entry=0x%08x table=0x%08x\r\n", .{ + @as(u32, @intFromBool(hal.intr.boot_state.mie)), + hal.intr.boot_state.enabled_lines, + hal.intr.boot_state.routed_sources, + hal.intr.readMtvec(), + hal.intr.readMtvt(), + hal.intr.trapEntryAddress(), + hal.intr.vectorTableAddress(), + }); + _ = mie_at_boot; + + // Quiesce the source before its line is enabled. TIMG1's raw interrupt status survives a + // reflash, and a level-triggered source that is already asserted fires the instant IE goes up - + // which, before init() masked MIE, was an immediate re-entrant trap. + timg1_int_clr.writeRaw(0xffff_ffff); + + // What the hardware will actually fetch. With SHV=1 the CLIC loads the handler address from + // MTVT[id] and jumps there, so this slot - id 21 for line 5 - is the address the core will run. + const tbl = hal.intr.vectorTableAddress(); + soc.rom.print("MARK INTR_TABLE table=0x%08x slot21=0x%08x slot0=0x%08x expect_entry=0x%08x\r\n", .{ + tbl, + mmio.Reg.atAddress(tbl + 4 * 21).raw(), + mmio.Reg.atAddress(tbl).raw(), + hal.intr.trapEntryAddress(), + }); + + hal.intr.setThreshold(0); + hal.intr.attach(.tg1_t0, line, .{ .handler = onAlarm, .trigger = .level, .priority = 1 }); + soc.rom.print("MARK INTR_ROUTE tg1_t0(49) -> line %u, routed_line=%u threshold=%u\r\n", .{ + @as(u32, line), + @as(u32, hal.intr.routedLine(.tg1_t0) orelse 99), + @as(u32, hal.intr.getThreshold()), + }); + + // ------------------------------------------- phase 0: does the source reach the CLIC at all? + // No MIE, so nothing can be taken and nothing can hang: this asks only whether the matrix and + // the CLIC latch a real peripheral event. If pending stays 0 here, everything after it is moot. + timg1_int_clr.writeRaw(0xffff_ffff); + armTimer(2_000); // 20 ms + soc.rom.ets_delay_us(100_000); + const p0_raw = timg1_int_raw.get(t0_int_raw); + const p0_pending = hal.intr.isPending(line); + disarmTimer(); + soc.rom.print("MARK INTR_PHASE0 timer_raw=%u expect=1 clic_pending=%u expect=1 (no MIE, cannot hang)\r\n", .{ + p0_raw, @as(u32, @intFromBool(p0_pending)), + }); + + // ------------------------------------------------------------------ phase 1: take exactly one + fired = 0; + hal.intr.spurious = 0; + armTimer(5_000); // 50 ms + hal.intr.globalEnable(); + soc.rom.ets_delay_us(200_000); + hal.intr.globalDisable(); + + const took = fired; + const spur = hal.intr.spurious; + const raw_after = timg1_int_raw.get(t0_int_raw); + const pend_after = hal.intr.isPending(line); + disarmTimer(); + + // `taken` and `last_clic_id` split "latched but not delivered" in two: taken=0 means the trap + // was never entered (mtvec, MTVT or SHV), taken>0 with fired=0 means it was entered and the + // handler lookup missed. + soc.rom.print("MARK INTR_PHASE1 fired=%u expect=1 taken=%u spurious=%u expect=0 last_clic_id=%u expect=21 timer_raw=%u pending=%u\r\n", .{ + took, hal.intr.taken, spur, @as(u32, hal.intr.last_clic_id), raw_after, @as(u32, @intFromBool(pend_after)), + }); + if (took == 1 and spur == 0) { + soc.rom.print("MARK INTR_PHASE1 PASS an interrupt was taken and vectored to its handler\r\n", .{}); + } else if (took == 0 and pend_after) { + soc.rom.print("MARK INTR_PHASE1 FAIL latched but not taken - mtvec, MTVT or MIE\r\n", .{}); + } else if (took == 0 and raw_after == 0) { + soc.rom.print("MARK INTR_PHASE1 FAIL the timer never fired; this measured nothing\r\n", .{}); + } else if (took == 0) { + soc.rom.print("MARK INTR_PHASE1 FAIL timer fired but never latched - the matrix write missed\r\n", .{}); + } else { + soc.rom.print("MARK INTR_PHASE1 FAIL re-entered %u times - the handler is not clearing the source\r\n", .{took}); + } + + // ------------------------------------------- phase 2: is the memory-mapped threshold the real one + // Priority 1 against a threshold of 7 must not be delivered. If the arbiter were reading the + // mintthresh CSR instead - which this die does not implement, and which accepts writes silently - + // the threshold would read back correctly and the interrupt would arrive anyway. + fired = 0; + hal.intr.spurious = 0; + hal.intr.setThreshold(7); + armTimer(5_000); + hal.intr.globalEnable(); + soc.rom.ets_delay_us(200_000); + + const blocked = fired; + const pending_while_blocked = hal.intr.isPending(line); + + // Now drop the threshold with MIE still on: the latched interrupt must be delivered. + hal.intr.setThreshold(0); + soc.rom.ets_delay_us(50_000); + hal.intr.globalDisable(); + const after_drop = fired; + disarmTimer(); + + soc.rom.print("MARK INTR_PHASE2 blocked=%u expect=0 pending_while_blocked=%u expect=1 after_drop=%u expect=1\r\n", .{ + blocked, @as(u32, @intFromBool(pending_while_blocked)), after_drop, + }); + if (blocked == 0 and pending_while_blocked and after_drop >= 1) { + soc.rom.print("MARK INTR_PHASE2 PASS the memory-mapped threshold at 0x20800008 is the one the arbiter reads\r\n", .{}); + } else if (blocked > 0) { + soc.rom.print("MARK INTR_PHASE2 FAIL delivered despite threshold 7 - the write is not reaching the arbiter\r\n", .{}); + } else { + soc.rom.print("MARK INTR_PHASE2 FAIL blocked but never delivered after the drop\r\n", .{}); + } + + soc.rom.print("MARK INTR_DONE\r\n", .{}); + + hal.gpio.configureOutput(20, .{ .readback = true }); + while (true) { + hal.gpio.setHigh(20); + soc.rom.ets_delay_us(500_000); + hal.gpio.setLow(20); + soc.rom.ets_delay_us(500_000); + } +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/iocheck.zig b/examples/iocheck.zig new file mode 100644 index 0000000..959e7f4 --- /dev/null +++ b/examples/iocheck.zig @@ -0,0 +1,110 @@ +//! Does `std.Io.sleep` wake up on this chip? +//! +//! Written to answer one question during radio bring-up. ESP-Hosted's transport stops immediately +//! after a successful SDIO card init, at a `_h_msleep(100)` - and a cooperative scheduler whose +//! sleep never returns is indistinguishable, from the outside, from a driver that hung. The 21 host +//! tests in src/io/p4.zig cover the scheduler against a virtual clock; what they cannot cover is +//! whether a real deadline against the real systimer ever comes due. +//! +//! Four claims, each answered by the die: +//! +//! MARK IO_NOW the timebase advances at all, and at 16 MHz +//! MARK IO_SLEEP a sleep from the main task returns, and after roughly the right time +//! MARK IO_TASK a spawned task runs, sleeps, and finishes +//! MARK IO_ORDER three tasks with different deadlines wake in deadline order +//! +//! Run: zig build -Dapp=examples/iocheck.zig run -Dseconds=15 + +const std = @import("std"); +const soc = @import("soc"); +const hal = @import("hal"); +const p4 = @import("io"); + +pub const std_options: std.Options = .{ .page_size_min = 4096 }; + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK IO_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +var pool: p4.Static(4, 4096) = .{}; + +/// Wake order, appended by the three tasks in `IO_ORDER`. +var order: [3]u8 = .{ 0, 0, 0 }; +var order_len: usize = 0; + +fn sleeper(ctx: struct { io: std.Io, ms: i64, tag: u8 }) void { + ctx.io.sleep(.fromMilliseconds(ctx.ms), .awake) catch {}; + order[order_len] = ctx.tag; + order_len += 1; +} + +export fn zig_main() noreturn { + // The bootloader leaves this armed and nothing here feeds it. + _ = hal.rwdt.disable(); + + const runtime = pool.init(.{}); + const io = runtime.io(); + + // 1. Does the timebase move? Everything below is meaningless if not. + const t0 = hal.systimer.read(.unit0) orelse 0; + soc.rom.ets_delay_us(10_000); + const t1 = hal.systimer.read(.unit0) orelse 0; + soc.rom.print("MARK IO_NOW advanced=%u ticks expect~160000\r\n", .{@as(u32, @truncate(t1 - t0))}); + + // 2. The question that matters: does a sleep from the calling task return? Measured against the + // systimer rather than trusted, because a sleep that returns instantly would also look like + // success from a print alone. + const before = hal.systimer.read(.unit0) orelse 0; + io.sleep(.fromMilliseconds(100), .awake) catch |err| { + soc.rom.print("MARK IO_SLEEP failed=%s\r\n", .{@errorName(err).ptr}); + park(); + }; + const after = hal.systimer.read(.unit0) orelse 0; + const slept_ms = (after - before) / 16_000; + soc.rom.print("MARK IO_SLEEP returned after %u ms, asked 100\r\n", .{@as(u32, @truncate(slept_ms))}); + + // 3. A spawned task that sleeps: this is the shape ESP-Hosted's threads have. + var fut = io.async(sleeper, .{.{ .io = io, .ms = 20, .tag = 'A' }}); + fut.await(io); + soc.rom.print("MARK IO_TASK ran=%u\r\n", .{@as(u32, @intCast(order_len))}); + + // 4. Three deadlines, out of submission order, to prove the scheduler picks the earliest. + order_len = 0; + var f1 = io.async(sleeper, .{.{ .io = io, .ms = 60, .tag = '3' }}); + var f2 = io.async(sleeper, .{.{ .io = io, .ms = 20, .tag = '1' }}); + var f3 = io.async(sleeper, .{.{ .io = io, .ms = 40, .tag = '2' }}); + f1.await(io); + f2.await(io); + f3.await(io); + soc.rom.print("MARK IO_ORDER %c%c%c expect 123\r\n", .{ + @as(u32, order[0]), @as(u32, order[1]), @as(u32, order[2]), + }); + + soc.rom.print("MARK IO_DONE\r\n", .{}); + park(); +} + +fn park() noreturn { + while (true) {} +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/minimal.zig b/examples/minimal.zig new file mode 100644 index 0000000..a70f0ef --- /dev/null +++ b/examples/minimal.zig @@ -0,0 +1,42 @@ +//! The floor: the smallest thing that can boot on this chip and prove it is alive. +//! No printing, no descriptor text - just a pin that toggles. Build it with +//! zig build -Dapp=examples/minimal.zig size + +const std = @import("std"); +const config = @import("config"); +const soc = @import("soc"); + +/// Even the floor needs a panic handler: the default one formats and would pull in half of std. +pub const panic = std.debug.FullPanic(struct { + fn call(_: []const u8, _: ?usize) noreturn { + while (true) {} + } +}.call); +const led: u6 = @intCast(config.led_pin); + +export fn zig_main() noreturn { + soc.gpio.configureOutput(led); + while (true) { + soc.gpio.setHigh(led); + soc.rom.ets_delay_us(100_000); + soc.gpio.setLow(led); + soc.rom.ets_delay_us(100_000); + } +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/pie.zig b/examples/pie.zig new file mode 100644 index 0000000..9c51cc3 --- /dev/null +++ b/examples/pie.zig @@ -0,0 +1,224 @@ +//! Using the ESP32-P4's vendor ISA extensions (xespv2p1 / xesploop1p0, "PIE") from stock Zig. +//! +//! Two separate gaps hide behind "LLVM does not support the vendor extensions": +//! +//! 1. The optimiser will never *choose* an `esp.*` instruction, because LLVM has no cost model or +//! intrinsics for the PIE unit. That is a performance ceiling: you get no autovectorisation. +//! 2. The assembler cannot *encode* the mnemonics. Inline assembly does **not** help - it goes +//! through the same integrated assembler: +//! +//! asm volatile ("esp.vld.128.ip q0, a0, 16") +//! -> error: <inline asm>:1:2: unrecognized instruction mnemonic +//! +//! That is the real blocker, and it is what stops Zig from assembling ESP-IDF's own FreeRTOS +//! context switch (portasm.S, 34 instructions under `#if SOC_CPU_HAS_PIE`). +//! +//! Gap 2 closes without a compiler fork: emit the words with `.insn` and pin the registers the +//! fixed encoding names. `tools/encode.sh` generates the words with Espressif's GAS as a +//! build-time oracle; every constant below carries the mnemonic it came from. Two of them +//! (vld/vst q0) were also read straight out of an ESP-IDF build of this board with Espressif's +//! objdump, and agree byte for byte. +//! +//! Gap 1 does not close this way - hand-written kernels only. But that is what DSP code does +//! anyway: esp-dsp is hand-written assembly even under Espressif's own fork. + +const std = @import("std"); +const soc = @import("soc"); + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK PIE_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +/// CSR 0x7F2 is `CSR_PIE_STATE_REG`; ESP-IDF writes 1 to enable the unit +/// (riscv/include/riscv/rv_utils.h:341, riscv/include/riscv/csr_pie.h:19). +inline fn enablePie() void { + asm volatile ("csrw 0x7f2, 1"); +} + +/// 16 bytes through the PIE register file: one load, one store, neither spellable by the assembler. +/// Both instructions post-increment their base register, so a0 is an in-out operand. +fn pieCopy16(dst: *align(16) volatile [16]u8, src: *align(16) const volatile [16]u8) void { + var p: usize = @intFromPtr(src); + asm volatile (".insn 4, 0x0201223b" // esp.vld.128.ip q0, a0, 16 + : [p] "={a0}" (p), + : [in] "{a0}" (p), + : .{ .memory = true }); + var q: usize = @intFromPtr(dst); + asm volatile (".insn 4, 0x8201223b" // esp.vst.128.ip q0, a0, 16 + : [q] "={a0}" (q), + : [in] "{a0}" (q), + : .{ .memory = true }); +} + +/// The reason the extension exists: 16 signed 8-bit multiply-accumulates in one instruction. +/// +/// `a` and `b` are 16 bytes each; QACC accumulates 16 lanes which are then spilled as 64 bytes. +/// The four `st.qacc` instructions dump the accumulator in quarters, chaining through a0. +/// +/// q0/q1 stay live across the two asm blocks. That is only sound because nothing else in this +/// image emits a PIE instruction - LLVM cannot see the q registers, so it cannot preserve them. +fn pieMacS8( + out: *align(16) volatile [64]u8, + a: *align(16) const volatile [16]i8, + b: *align(16) const volatile [16]i8, +) void { + var p: usize = @intFromPtr(a); + asm volatile ( + \\ .insn 4, 0x0201223b # esp.vld.128.ip q0, a0, 16 + : [p] "={a0}" (p), + : [in] "{a0}" (p), + : .{ .memory = true }); + p = @intFromPtr(b); + asm volatile ( + \\ .insn 4, 0x0201263b # esp.vld.128.ip q1, a0, 16 + : [p] "={a0}" (p), + : [in] "{a0}" (p), + : .{ .memory = true }); + + var q: usize = @intFromPtr(out); + asm volatile ( + \\ .insn 4, 0x0000025b # esp.zero.qacc + \\ .insn 4, 0x06c5005f # esp.vmulas.s8.qacc q0, q1 + \\ .insn 4, 0xa001423b # esp.st.qacc.l.l.128.ip a0, 16 + \\ .insn 4, 0x8001423b # esp.st.qacc.l.h.128.ip a0, 16 + \\ .insn 4, 0xe001423b # esp.st.qacc.h.l.128.ip a0, 16 + \\ .insn 4, 0xc001423b # esp.st.qacc.h.h.128.ip a0, 16 + : [q] "={a0}" (q), + : [in] "{a0}" (q), + : .{ .memory = true }); +} + +var source: [16]u8 align(16) = .{ 0x42, 0x00, 0xca, 0xfe, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12 }; +var dest: [16]u8 align(16) = @splat(0); + +var vec_a: [16]i8 align(16) = @splat(1); +var vec_b: [16]i8 align(16) = .{ 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16 }; +var qacc: [64]u8 align(16) = @splat(0); + +var big_a: [256]i8 align(16) = blk: { + var v: [256]i8 = undefined; + for (&v, 0..) |*e, i| e.* = @intCast((i % 7) + 1); + break :blk v; +}; +var big_b: [256]i8 align(16) = blk: { + var v: [256]i8 = undefined; + for (&v, 0..) |*e, i| e.* = @intCast((i % 5) + 1); + break :blk v; +}; + +/// Gap 1, measured: a 256-element signed dot product, the way the compiler emits it versus the way +/// the PIE unit does it. LLVM cannot autovectorise into `esp.*`, so the scalar loop is what any +/// stock-toolchain build gets - with Espressif's fork too, since their LLVM has no autovectoriser +/// for this unit either. The vector version is sixteen MACs per instruction with the accumulator +/// spilled once at the end. +fn dotScalar(a: *const volatile [256]i8, b: *const volatile [256]i8) i32 { + var acc: i32 = 0; + for (0..256) |i| acc += @as(i32, a[i]) * @as(i32, b[i]); + return acc; +} + +fn dotPie(out: *align(16) volatile [64]u8, a: *align(16) const volatile [256]i8, b: *align(16) const volatile [256]i8) i32 { + asm volatile (".insn 4, 0x0000025b" ::: .{ .memory = true }); // esp.zero.qacc + var pa: usize = @intFromPtr(a); + var pb: usize = @intFromPtr(b); + for (0..16) |_| { + asm volatile (".insn 4, 0x0201223b" // esp.vld.128.ip q0, a0, 16 + : [p] "={a0}" (pa), + : [in] "{a0}" (pa), + : .{ .memory = true }); + asm volatile ( + \\ .insn 4, 0x0201263b # esp.vld.128.ip q1, a0, 16 + \\ .insn 4, 0x06c5005f # esp.vmulas.s8.qacc q0, q1 + : [p] "={a0}" (pb), + : [in] "{a0}" (pb), + : .{ .memory = true }); + } + var q: usize = @intFromPtr(out); + asm volatile ( + \\ .insn 4, 0xa001423b # esp.st.qacc.l.l.128.ip a0, 16 + \\ .insn 4, 0x8001423b # esp.st.qacc.l.h.128.ip a0, 16 + \\ .insn 4, 0xe001423b # esp.st.qacc.h.l.128.ip a0, 16 + \\ .insn 4, 0xc001423b # esp.st.qacc.h.h.128.ip a0, 16 + : [q] "={a0}" (q), + : [in] "{a0}" (q), + : .{ .memory = true }); + // Sixteen lane accumulators, horizontally summed by the scalar core. + var acc: i32 = 0; + for (0..16) |i| acc += @as(i32, @bitCast(@as(u32, out[i*4]) | @as(u32, out[i*4+1]) << 8 | @as(u32, out[i*4+2]) << 16 | @as(u32, out[i*4+3]) << 24)); + return acc; +} + +export fn zig_main() noreturn { + soc.rom.print("\r\nMARK PIE_START csr 0x7f2 <- 1\r\n", .{}); + enablePie(); + soc.rom.print("MARK PIE_ENABLED survived the CSR write\r\n", .{}); + + // 1. vector load/store. + pieCopy16(&dest, &source); + var copy_ok = true; + for (source, dest) |x, y| { + if (x != y) copy_ok = false; + } + soc.rom.print("MARK PIE_COPY dest=%02x%02x%02x%02x match=%u\r\n", .{ + @as(u32, dest[0]), @as(u32, dest[1]), @as(u32, dest[2]), @as(u32, dest[3]), + @as(u32, @intFromBool(copy_ok)), + }); + + // 2. sixteen 8-bit MACs in one instruction. a is all ones and b is 1..16, so the sixteen + // accumulator lanes must hold exactly 1..16 - whatever order the QACC dump puts them in. + pieMacS8(&qacc, &vec_a, &vec_b); + var seen: u32 = 0; + var lanes: u32 = 0; + for (0..16) |i| { + const v = std.mem.readInt(u32, qacc[i * 4 ..][0..4], .little); + if (v >= 1 and v <= 16) { + seen |= @as(u32, 1) << @intCast(v - 1); + lanes += 1; + } + } + soc.rom.print("MARK PIE_MAC lanes=%u distinct=%08x expect=0000ffff sum_ok=%u\r\n", .{ + lanes, seen, @as(u32, @intFromBool(seen == 0xffff)), + }); + + // 3. gap 1, in cycles: the same 256-element dot product both ways. Both results must agree, + // or the vector path is not computing what the compiler's loop computes. + const t0 = soc.cycles(); + const scalar = dotScalar(&big_a, &big_b); + const t1 = soc.cycles(); + const vector = dotPie(&qacc, &big_a, &big_b); + const t2 = soc.cycles(); + soc.rom.print("MARK PIE_DOT scalar=%d in %u cyc, vector=%d in %u cyc, agree=%u\r\n", .{ + scalar, @as(u32, @truncate(t1 - t0)), + vector, @as(u32, @truncate(t2 - t1)), + @as(u32, @intFromBool(scalar == vector)), + }); + soc.rom.print("MARK PIE_DONE vendor vector ISA executed from a zig-built image\r\n", .{}); + + soc.gpio.configureOutput(20); + while (true) { + soc.gpio.setHigh(20); + soc.rom.ets_delay_us(250_000); + soc.gpio.setLow(20); + soc.rom.ets_delay_us(250_000); + } +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/portcheck.zig b/examples/portcheck.zig new file mode 100644 index 0000000..ac0894e --- /dev/null +++ b/examples/portcheck.zig @@ -0,0 +1,267 @@ +//! Hardware self-test for the ESP-Hosted port table, with no ESP-Hosted C linked in. +//! +//! Run with: zig build -Dapp=src/portcheck.zig run -Dseconds=8 +//! +//! Every line is a claim this file can actually make from the die. What it does *not* do is bring +//! the radio up: that needs the ESP-Hosted C linked beside it, which is the parent's build step. +//! What it proves is that the seam works - that the table's layout is what C measured, that the +//! heap survives the allocation pattern ESP-Hosted subjects it to, that the OS objects behave under +//! the real `std.Io` on this chip rather than under `Threaded` on the host, and that the reset pin +//! moves the way the radio needs. + +const std = @import("std"); +const hal = @import("hal"); + +const net = @import("net"); +const port = net.port; +const hheap = net.heap; +const os = net.os; +const p4 = @import("io"); + +extern fn ets_printf(fmt: [*:0]const u8, ...) c_int; + +fn print(comptime fmt: [*:0]const u8, args: anytype) void { + _ = @call(.auto, ets_printf, .{fmt} ++ args); +} + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + print("MARK PORT_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +/// Required in **every** app root that implements `std.Io.VTable` on this target, and it has to be +/// here rather than in the runtime: std reads `std_options` from `@import("root")` only +/// (`/usr/lib/zig/std/std.zig:112`), so the same declaration inside src/io/p4.zig is ignored. +/// +/// The reason it is needed at all: defining `fileMemoryMapCreate` forces `Io.File.MemoryMap` to be +/// laid out, its `memory` field is `[]align(std.heap.page_size_min) u8` +/// (`/usr/lib/zig/std/Io/File/MemoryMap.zig:18`), and `page_size_min` has no default for +/// freestanding (`/usr/lib/zig/std/heap.zig:48`). It is the *return type* that does it, so no stub +/// body can avoid it. 4096 is arbitrary and honest: nothing in this image pages, and that one +/// field's alignment is the only thing that reads it. `page_size_max` is not reached. +pub const std_options: std.Options = .{ + .page_size_min = 4096, +}; + +/// The heap ESP-Hosted allocates from. 48 KiB is a starting point, not a measurement: the honest +/// number comes from `port.stats().peak_reserved` after a run with the C linked in, and the +/// dominant term is the transport queues - `CONFIG_ESP_HOSTED_SDIO_TX_Q_SIZE` and `..._RX_Q_SIZE` +/// are both 20 in the working IDF build, and 40 in-flight buffers at 1536 bytes is 60 KB on its +/// own. Those depths will have to come down for this memory budget; see the report. +var heap_buffer: [48 * 1024]u8 align(hheap.Heap.granule) = undefined; + +/// Nine task slots: ESP-Hosted's seven, the port's timer service, and this context. +/// 4 KiB each = 36 KiB. `port.requested_stack_bytes` is 5 KiB, which is FreeRTOS's number for tasks +/// that call `printf`; these do not, and the real number wants a painted-stack watermark. +var runtime_storage: p4.Static(9, 4 * 1024) = .{}; + +var events_seen: u32 = 0; + +fn onEvent(e: port.Event) void { + events_seen += 1; + switch (e.base) { + .wifi => print("MARK PORT_EVENT wifi id=%d\r\n", .{e.id}), + .named => |n| print("MARK PORT_EVENT %s id=%d\r\n", .{ n, e.id }), + } +} + +export fn zig_main() noreturn { + hal.intr.init(); + hal.systimer.init(); + print("\r\nMARK PORT_START\r\n", .{}); + + // -------------------------------------------------------------- 1. the ABI the C side measured + // Three numbers, and if any of them is wrong the table is a set of calls to the wrong + // functions. C's own offsetof, with the force-include in place, gives 284 / 148 / 280. + print("MARK PORT_ABI sizeof=%u config_gpio=%u event_post=%u fields=%u expect=284,148,280,71\r\n", .{ + @as(u32, @sizeOf(port.HostedOsiFuncs)), + @as(u32, @offsetOf(port.HostedOsiFuncs, "config_gpio")), + @as(u32, @offsetOf(port.HostedOsiFuncs, "event_post")), + @as(u32, std.meta.fields(port.HostedOsiFuncs).len), + }); + // g_h must point at the table before anything runs; C reads `g_h.funcs->...` directly. + print("MARK PORT_GH funcs_is_table=%u stubs=%u real=%u\r\n", .{ + @as(u32, @intFromBool(port.g_h.funcs == &port.g_hosted_osi_funcs)), + @as(u32, port.stubbed.len), + @as(u32, std.meta.fields(port.HostedOsiFuncs).len - port.stubbed.len), + }); + + // -------------------------------------------------------------- 2. install + var heap = hheap.Heap.init(&heap_buffer); + const rt = runtime_storage.init(.{}); + const io = rt.io(); + port.install(io, heap.allocator()); + port.setEventHandler(onEvent); + print("MARK PORT_INSTALL heap=%u tasks=%u stack=%u\r\n", .{ + @as(u32, heap_buffer.len), + @as(u32, 9), + @as(u32, 4 * 1024), + }); + + // -------------------------------------------------------------- 3. the timebase + // _h_get_time_ms off hal.systimer's 16 MHz. Two reads a known delay apart: the difference is + // the claim, and it is checked against the counter that produced it. + const t0 = port.g_h.funcs.get_time_ms(); + hal.systimer.delayMicros(50_000); + const t1 = port.g_h.funcs.get_time_ms(); + print("MARK PORT_TIME t0=%u t1=%u delta_ms=%u expect~50\r\n", .{ + @as(u32, @intCast(t0)), @as(u32, @intCast(t1)), @as(u32, @intCast(t1 - t0)), + }); + + // -------------------------------------------------------------- 4. memory, through the table + // The exact pattern an arena cannot serve: allocate, free out of order, reallocate. This is + // mempool.c's churn, done through the C entry points rather than through Zig. + const f = port.g_h.funcs; + var held: [12]?*anyopaque = @splat(null); + for (&held) |*h| h.* = f.malloc_align(1536, 64); + var aligned_ok: u32 = 0; + for (held) |h| { + if (h) |p| if (@intFromPtr(p) % 64 == 0) { + aligned_ok += 1; + }; + } + const after_alloc = port.stats(); + const order = [_]usize{ 7, 0, 11, 3, 9, 1, 5, 10, 2, 8, 4, 6 }; + for (order) |i| f.free_align(held[i]); + const after_free = port.stats(); + for (&held) |*h| h.* = f.malloc_align(1536, 64); + const after_realloc = port.stats(); + for (order) |i| f.free_align(held[i]); + + print("MARK PORT_HEAP aligned=%u/12 live_after_alloc=%u live_after_free=%u peak=%u fail=%u\r\n", .{ + aligned_ok, + @as(u32, @intCast(after_alloc.blocks_live)), + @as(u32, @intCast(after_free.blocks_live)), + @as(u32, @intCast(after_realloc.peak_reserved)), + @as(u32, @intCast(after_realloc.alloc_failures)), + }); + // The whole point: the second round must not need more memory than the first. + print("MARK PORT_HEAP_REUSE round1=%u round2=%u expect_equal\r\n", .{ + @as(u32, @intCast(after_alloc.bytes_reserved)), + @as(u32, @intCast(after_realloc.bytes_reserved)), + }); + const s = heap.stats(); + print("MARK PORT_HEAP_FREELIST total=%u free=%u largest=%u blocks=%u expect free==total,blocks==1\r\n", .{ + s.total, s.free, s.largest_free, s.free_blocks, + }); + heap.check(); + + // -------------------------------------------------------------- 5. the C-visible sync objects + // Created and driven through the table, so the handles and the return codes are the C ones. + const mtx = f.create_mutex().?; + const lock_ok = f.lock_mutex(mtx, -1); + const relock_busy = f.lock_mutex(mtx, 0); + const unlock_ok = f.unlock_mutex(mtx); + print("MARK PORT_MUTEX lock=%d try_while_held=%d unlock=%d expect=0,-1,0\r\n", .{ lock_ok, relock_busy, unlock_ok }); + _ = f.destroy_mutex(mtx); + + // A FreeRTOS semaphore arrives with one permit already given; sdio_drv.c:1504 depends on it. + const sem = f.create_semaphore(4).?; + const initial_take = f.get_semaphore(sem, 0); + const empty_take = f.get_semaphore(sem, 0); + _ = f.post_semaphore(sem); + const after_post = f.get_semaphore(sem, 0); + print("MARK PORT_SEM initial=%d empty=%d after_post=%d expect=0,-5,0\r\n", .{ initial_take, empty_take, after_post }); + _ = f.destroy_semaphore(sem); + + // A queue of 24-byte records, which is sizeof(interface_buffer_handle_t) on rv32. + const q = f.create_queue(4, 24).?; + var rec: [24]u8 = @splat(0xA5); + var out: [24]u8 = @splat(0); + const empty_deq = f.dequeue_item(q, &out, 0); + var sent: c_int = 0; + for (0..4) |_| sent += f.queue_item(q, &rec, -1); + const full_send = f.queue_item(q, &rec, 0); + const waiting = f.queue_msg_waiting(q); + const deq = f.dequeue_item(q, &out, -1); + print("MARK PORT_QUEUE empty=%d sent=%d full=%d waiting=%d deq=%d roundtrip=%u expect=-1,0,-1,4,0,1\r\n", .{ + empty_deq, sent, full_send, waiting, deq, @as(u32, @intFromBool(out[0] == 0xA5 and out[23] == 0xA5)), + }); + _ = f.destroy_queue(q); + + // -------------------------------------------------------------- 6. timers, through the table + const timer = f.timer_start("portcheck_oneshot", 30, 0, timerFired, null); + print("MARK PORT_TIMER_ARMED handle=%u\r\n", .{@as(u32, @intFromBool(timer != null))}); + // The timer service task only runs when this context blocks. Sleeping is what starts it. + _ = f.msleep(120); + print("MARK PORT_TIMER fired=%u expect=1\r\n", .{timer_fires}); + // Stopping an expired one-shot reports failure, as esp_timer_stop does. + if (timer) |t| print("MARK PORT_TIMER_STOP %d expect=-1\r\n", .{f.timer_stop(t)}); + + // -------------------------------------------------------------- 7. events + _ = f.event_post("PORTCHECK_EVENT", 7, null, 0, 0); + _ = f.event_wifi_post(4, null, 0, 0); + print("MARK PORT_EVENTS seen=%u expect=2\r\n", .{events_seen}); + + // -------------------------------------------------------------- 8. the reset pin + // GPIO54 has an external pull-up, so released means high. ESP-Hosted's sequence + // (sdio_drv.c:1651-1657) is active, inactive, active, and with this board's configuration + // active is HIGH - so it ends released. Driven here through the table's own GPIO entries, with + // readback, because getting this backwards holds the radio in reset for ever. + const pin: u32 = port.config.reset_pin; + _ = f.config_gpio(null, pin, 1 | 2); // H_GPIO_MODE_INPUT_OUTPUT: drive and read back + _ = f.write_gpio(null, pin, 1); + const high1 = f.read_gpio(null, pin); + _ = f.msleep(10); + _ = f.write_gpio(null, pin, 0); + const low = f.read_gpio(null, pin); + _ = f.msleep(10); + _ = f.write_gpio(null, pin, 1); + const high2 = f.read_gpio(null, pin); + print("MARK PORT_RESET pin=%u high=%d low=%d released=%d expect=1,0,1\r\n", .{ pin, high1, low, high2 }); + + // The pull entries, on the same pad: enable a pull-down, then disable it, and check the + // internal pull does not end up fighting the external one. + _ = f.config_gpio(null, pin, 1); // input only, so the pull is what drives the pad + _ = f.pull_gpio(null, pin, 0, 1); // H_GPIO_PULL_DOWN, enable + hal.systimer.delayMicros(200); + const pulled_down = f.read_gpio(null, pin); + _ = f.pull_gpio(null, pin, 0, 0); // disable it again + hal.systimer.delayMicros(200); + const released = f.read_gpio(null, pin); + print("MARK PORT_PULL down=%d released=%d expect=0,1\r\n", .{ pulled_down, released }); + // Leave the radio out of reset, whatever the test did to the pad. + _ = f.config_gpio(null, pin, 1 | 2); + _ = f.write_gpio(null, pin, 1); + + // -------------------------------------------------------------- 9. what was never implemented + const final = port.stats(); + print("MARK PORT_STUBS_HIT %u\r\n", .{final.stub_calls}); + print("MARK PORT_DONE live=%u reserved=%u peak=%u blocks=%u fail=%u\r\n", .{ + @as(u32, @intCast(final.bytes_live)), + @as(u32, @intCast(final.bytes_reserved)), + @as(u32, @intCast(final.peak_reserved)), + @as(u32, @intCast(final.blocks_live)), + @as(u32, @intCast(final.alloc_failures)), + }); + while (true) {} +} + +var timer_fires: u32 = 0; + +fn timerFired(_: ?*anyopaque) callconv(.c) void { + timer_fires += 1; +} + +/// Reset entry, verbatim from `src/main.zig:79-95`: enable the F extension, establish a stack in +/// L2MEM, clear .bss, jump to `zig_main`. Every app in this repo carries its own copy because the +/// linker script's entry symbol is per-image. +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/radio.zig b/examples/radio.zig new file mode 100644 index 0000000..7a2704a --- /dev/null +++ b/examples/radio.zig @@ -0,0 +1,388 @@ +//! First light for the radio: does the ESP32-C6 answer over SDIO, driven entirely from Zig? +//! +//! This is the milestone the whole stack exists to reach, and it is deliberately the smallest thing +//! that can prove it. The P4 has no radio. The C6 beside it does, and ESP-Hosted's transport - 13k +//! lines of C that already works - is what talks to it. Everything *underneath* that C is this +//! project's: the SDIO host driver (src/hal/sdmmc.zig), the runtime it blocks on +//! (src/io/p4.zig, std.Io), the allocator it allocates from (src/net/heap.zig), and the function +//! table it reaches all of them through (src/net/port.zig). +//! +//! So a successful run is not "the C works". It is: our SDIO driver clocked a real CMD52/CMD53 +//! exchange, our scheduler suspended and resumed ESP-Hosted's threads, our allocator served its +//! buffers, and a separate chip agreed to talk. +//! +//! What it prints, and what each line proves: +//! +//! MARK RADIO_START the image booted and the runtime installed +//! MARK RADIO_SETUP rc=0 setup_transport accepted; ESP-Hosted's threads now exist +//! MARK RADIO_TICK ... the scheduler is running and the transport is progressing +//! MARK RADIO_UP the C6 answered and the transport reached its active state +//! MARK RADIO_CAPS ... the capability byte the C6 reported (0x0d on this board) +//! MARK RADIO_HEAP ... what the C actually allocated, against what was reserved +//! MARK RADIO_STUBS n ... how many loud stubs were reached: a non-zero count names work left, +//! and `sleeps=` the running total of ESP-Hosted's RPC not-ready spins +//! MARK WIFI_START rc= spun= the first RPC. `spun` counts not-ready spins during the call, so a +//! non-zero value means the request was never transmitted at all +//! MARK RADIO_FAIL <why> the transport did not come up, with the reason +//! +//! Run: zig build -Dhosted -Dapp=examples/radio.zig run + +const std = @import("std"); +const hal = @import("hal"); +const soc = @import("soc"); +const net = @import("net"); +const p4 = @import("io"); +const config = @import("config"); + +/// Required by any application that implements `std.Io.VTable` on this target. Five vtable entries +/// name `Io.File.MemoryMap`, whose `memory` field is `[]align(std.heap.page_size_min) u8`, and +/// riscv32-freestanding has no default page size. It must be in the ROOT module, because std reads +/// `std.options` from `@import("root")` - putting it in the runtime does nothing. +pub const std_options: std.Options = .{ .page_size_min = 4096 }; + +/// A panic must reach the serial line: this board has no other output, and the whole point of the +/// MARK lines is that a failure is legible. `while (true) {}` rather than a reset, so the last +/// message stays on screen instead of scrolling past in a reboot loop. +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK RADIO_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +/// ESP-Hosted spawns seven threads for the transport and more for RPC. Twelve slots. +/// +/// Sizing this too small does NOT fail loudly, which is why the number is generous: `io.async` with +/// no free slot runs the body *eagerly* rather than returning an error, so a reader task that should +/// loop forever instead runs once at spawn time and is never seen again. The symptom is a request +/// that goes out and a response that never arrives - which is exactly what an eight-slot pool +/// produced here, with seven slots already taken by the time RPC started. +/// +/// 4 KiB each is a measured starting point rather than a guess - `runtime.dump()` at the end reports +/// each task's real high-water mark, so the next revision of this number is an observation. Total +/// 32 KiB of stacks out of ~128 KiB of L2MEM, which has to also hold the heap below. +var pool: p4.Static(12, 4096) = .{}; + +/// ESP-Hosted's heap. With the SDIO queues cut to 4/4 (see src/net/hosted/sdkconfig.h), the +/// in-flight buffers are ~12 KiB; the rest is the transport's own bookkeeping and the RPC scratch. +/// `RADIO_HEAP` prints what was really used, which is how this number gets corrected. +var heap_backing: [32 * 1024]u8 align(8) = undefined; + +/// Set from the event callback. `volatile` is not needed - the scheduler is cooperative and this is +/// written and read on the same hart with no preemption - but the transport does set it from one of +/// its own threads, so it is read only at yield points. +var last_event: ?net.port.Event = null; + +/// Set by the bring-up task so the heartbeat can report the outcome. +var bringup_result: ?anyerror = null; +var bringup_done: bool = false; + +fn bringUp(ctx: struct { io: std.Io, gpa: std.mem.Allocator }) void { + net.init(ctx.io, ctx.gpa) catch |err| { + bringup_result = err; + bringup_done = true; + return; + }; + bringup_done = true; +} + +fn onEvent(ev: net.port.Event) void { + last_event = ev; + // `base` says which event family this is - Wi-Fi, or one of ESP-Hosted's own named bases - and + // `id` is the family's own enum. Both are printed raw rather than decoded: this file's job is to + // prove the transport came up, and inventing names for ids we have not seen yet would be + // guessing at exactly the moment the board is telling us something. + const base_name: [*:0]const u8 = switch (ev.base) { + .wifi => "wifi", + .named => |n| n, + }; + soc.rom.print("MARK RADIO_EVENT base=%s id=%d len=%u\r\n", .{ + base_name, + ev.id, + @as(u32, @intCast(if (ev.data) |d| d.len else 0)), + }); +} + +/// Reset entry. The bootloader hands over with an unspecified stack pointer and the FPU off, so: +/// enable the F extension (mstatus.FS = Initial), establish the stack, clear .bss, then enter Zig. +/// Every application in this repo carries its own copy - there is no runtime to hide it in, and the +/// linker script's symbols are what it depends on. +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} + +export fn zig_main() noreturn { + // The bootloader leaves the RTC watchdog armed and expects the application to take it over. + // Nothing in this image feeds it, so without this the board resets at roughly ten seconds - + // which is longer than any demo in this repo has ever run, and is exactly why it went unnoticed + // until something here waited on a real handshake. The reset reason on the first run of this + // file was CHIP_LP_WDT_RESET, from the park() loop below. + const wdt_was_armed = hal.rwdt.armed(); + const wdt_off = hal.rwdt.disable(); + soc.rom.print("MARK RADIO_WDT armed_at_entry=%u disabled=%u\r\n", .{ + @as(u32, @intFromBool(wdt_was_armed)), + @as(u32, @intFromBool(wdt_off)), + }); + + // Two independent clocks over one interval: the systimer is a fixed 16 MHz, so the CPU + // frequency falls out of the ratio. Worth printing because everything above assumes the + // bootloader's 90 MHz - nothing in this image reconfigures the PLL - and a surprise here would + // explain a wrong SDIO clock divider before it wasted an afternoon. + const t0 = hal.systimer.read(.unit0) orelse 0; + const c0 = soc.cycles(); + soc.rom.ets_delay_us(10_000); + const t1 = hal.systimer.read(.unit0) orelse 0; + const c1 = soc.cycles(); + const cpu_khz: u64 = if (t1 > t0) ((c1 - c0) * (hal.systimer.hz / 1000)) / (t1 - t0) else 0; + soc.rom.print("\r\nMARK RADIO_START cpu=%u kHz\r\n", .{@as(u32, @truncate(cpu_khz))}); + + // 1. The runtime. Everything above blocks on this. + const runtime = pool.init(.{}); + const io = runtime.io(); + + // 2. The allocator ESP-Hosted's C allocates from. A fixed buffer is right here: the whole point + // is a bounded, known footprint, and `heap.zig`'s CHeap adds the length header that C's + // `free` needs. + // A real allocator over the static buffer, rather than the buffer allocator itself. + // + // `std.heap.FixedBufferAllocator` is a bump allocator and reclaims only the most recent + // allocation - that is its design, not a shortcoming, and it is the right tool when allocations + // are freed in reverse order or never. It is the wrong tool here: ESP-Hosted allocates one + // MAX_TRANSPORT_BUFFER_SIZE buffer per frame in each direction and frees each when that frame is + // done, in no particular order. Using the buffer allocator directly for that was my mistake, and + // the board named it precisely - 210 bytes live, 6 blocks live, and allocation failures climbing + // past 33 while the receive counter sat frozen at 29. Nothing leaked; the arena had simply been + // walked through 1536 bytes at a time with no way to give any of it back. + // + // So a general-purpose allocator goes on top, and the static buffer stays what it is: the + // memory. `net.heap.Heap` is a coalescing free list over exactly that, reached through the + // ordinary `std.mem.Allocator` vtable, so everything above it - including the C, through + // `_h_malloc` - is unaware of the difference. + var backing = net.heap.Heap.init(&heap_backing); + const gpa = backing.allocator(); + + net.port.setEventHandler(&onEvent); + + // 3. Bring the transport up. This installs the port table and hands control to the C, which + // resets the C6, initialises the SDIO card through our driver, and starts its threads. + // Bring-up runs on its OWN task, not this one, and that is a deliberate diagnostic choice. + // + // ESP-Hosted's `transport_drv_reconfigure` blocks: it waits for the slave to become ready in a + // 200 ms retry loop. Calling it from the main task means the main task is inside the C for the + // whole handshake and cannot print anything, so a stall in there is indistinguishable from a + // stalled scheduler. With it on a separate task, the heartbeat below keeps running and says + // which of the two is happening. + var bringup = io.async(bringUp, .{.{ .io = io, .gpa = gpa }}); + soc.rom.print("MARK RADIO_SETUP dispatched\r\n", .{}); + + // 4. Run the scheduler and watch for the transport to come up. The handshake happens on + // ESP-Hosted's threads, so this task's only job is to yield and report. + // + // Ten seconds is generous: the C6 boots in well under one. A bounded wait matters more than + // the exact number, because the failure this catches - the slave never answering - otherwise + // looks like a hang, and a hang tells you nothing about where it stopped. + const deadline_ms: u64 = 10_000; + const started = nowMs(); + var last_report: u64 = 0; + while (!net.isUp()) { + runtime.yield(); + const elapsed = nowMs() - started; + if (elapsed - last_report >= 1000) { + last_report = elapsed; + const s = net.port.stats(); + // heap and blocks moving means the C is doing work; both frozen while the tick advances + // means the transport is blocked but the scheduler is not. + soc.rom.print("MARK RADIO_TICK t=%u ms heap=%u B blocks=%u stubs=%u bringup_done=%u\r\n", .{ + @as(u32, @intCast(elapsed)), + @as(u32, @intCast(s.bytes_live)), + @as(u32, @intCast(s.blocks_live)), + s.stub_calls, + @as(u32, @intFromBool(bringup_done)), + }); + // The card-interrupt delivery chain, register by register, on every beat. RADIO_TICK + // says whether the scheduler is alive; these five lines say whether the C6 is asking + // for service, whether the controller latched it, and whether the CLIC could deliver + // it - which is not inferable from anything else printed here. + hal.sdmmc.interruptDiagnostics(); + } + if (bringup_done) { + if (bringup_result) |err| { + soc.rom.print("MARK RADIO_FAIL bringup=%s\r\n", .{@errorName(err).ptr}); + report(runtime); + park(); + } + // Bring-up returned success but the transport is not up: that is the interesting case, + // and it is worth saying so rather than sitting in the loop silently. + if (elapsed > 2000 and last_report == elapsed) { + soc.rom.print("MARK RADIO_NOTE bringup returned ok, transport still down\r\n", .{}); + } + } + if (elapsed > deadline_ms) { + soc.rom.print("MARK RADIO_FAIL timeout after %u ms\r\n", .{@as(u32, @intCast(elapsed))}); + report(runtime); + park(); + } + } + bringup.cancel(io); + + soc.rom.print("MARK RADIO_UP after %u ms\r\n", .{@as(u32, @intCast(nowMs() - started))}); + report(runtime); + + // The transport is up, so the RPC layer has vocabulary. A scan is the cheapest end-to-end proof + // that the whole path works - it needs no credentials, and it can only succeed if the request + // was serialised, sent over our SDIO driver, executed by the C6's radio, and the reply parsed. + scan(); + + // Keep yielding: the transport's threads must keep running, and leaving the board in a live + // state is what lets the next experiment build on this one. + while (true) runtime.yield(); +} + +/// ESP-Hosted's Wi-Fi RPC, through the C shim in src/net/hosted/wifi_shim.c. The structs stay in C +/// on purpose; see that file's header. +extern fn hosted_wifi_sta_start() c_int; +extern fn hosted_wifi_get_mac(out: *[6]u8) c_int; +extern fn hosted_wifi_scan(found: *u16) c_int; +extern fn hosted_wifi_connect(ssid: [*:0]const u8, psk: [*:0]const u8) c_int; +extern fn hosted_wifi_scan_record( + index: u16, + ssid_out: [*]u8, + rssi_out: *i8, + channel_out: *u8, + authmode_out: *u8, +) c_int; + +fn scan() void { + // ESP-Hosted's rpc_rx_thread and rpc_tx_thread both begin their loop with + // `if (!is_rpc_lib_ready()) _h_sleep(1)` (rpc_core.c:482-485, :543-547), and those two lines are + // the only `_h_sleep` callers in the file set build.zig compiles. So the delta across a + // synchronous request says, with no ambiguity, which of the two failures happened: + // + // spun=0 the RPC threads ran; the request went out and the answer (or its absence) is real + // spun~=2 per second stuck the RPC lib never reached READY; nothing was ever transmitted + // + // Without this the two are indistinguishable: `rpc_send_req` only enqueues (rpc_core.c:1019), + // so it returns success either way and the only other symptom is "Timeout waiting for Resp". + const spins_before = net.port.stats().hosted_sleep_calls; + const rc_start = hosted_wifi_sta_start(); + const spins_after = net.port.stats().hosted_sleep_calls; + soc.rom.print("MARK WIFI_START rc=%d spun=%u\r\n", .{ + rc_start, + @as(u32, spins_after - spins_before), + }); + if (rc_start != 0) return; + + var mac: [6]u8 = undefined; + if (hosted_wifi_get_mac(&mac) == 0) { + soc.rom.print("MARK WIFI_MAC %02x:%02x:%02x:%02x:%02x:%02x\r\n", .{ + @as(u32, mac[0]), @as(u32, mac[1]), @as(u32, mac[2]), + @as(u32, mac[3]), @as(u32, mac[4]), @as(u32, mac[5]), + }); + } + + var found: u16 = 0; + const rc_scan = hosted_wifi_scan(&found); + soc.rom.print("MARK WIFI_SCAN rc=%d found=%u\r\n", .{ rc_scan, @as(u32, found) }); + if (rc_scan != 0) return; + + // Print the first few, enough to see this network among them without flooding the UART. + var i: u16 = 0; + const limit = @min(found, 12); + while (i < limit) : (i += 1) { + var ssid: [33]u8 = undefined; + var rssi: i8 = 0; + var chan: u8 = 0; + var auth: u8 = 0; + if (hosted_wifi_scan_record(i, &ssid, &rssi, &chan, &auth) != 0) break; + soc.rom.print("MARK WIFI_AP %2u ch=%2u rssi=%d auth=%u %s\r\n", .{ + @as(u32, i), @as(u32, chan), @as(i32, rssi), @as(u32, auth), + @as([*:0]const u8, @ptrCast(&ssid)), + }); + } + + joinIfConfigured(); +} + +/// Join the network named by `-Dssid`, if one was given. +/// +/// Credentials come from build options (see build.zig): the SSID and passphrase are never in this +/// source. With no `-Dssid` this does nothing and says so, so the scan above remains a complete, +/// credential-free demonstration on its own. +fn joinIfConfigured() void { + if (config.wifi_ssid.len == 0) { + soc.rom.print("MARK WIFI_JOIN skipped: no -Dssid given\r\n", .{}); + return; + } + + // NUL-terminated copies for the C ABI. Sized to the 802.11 maxima that wifi_config_t itself + // uses: 32 for an SSID, 64 for a passphrase. + var ssid: [33]u8 = @splat(0); + var psk: [65]u8 = @splat(0); + if (config.wifi_ssid.len > 32 or config.wifi_psk.len > 64) { + soc.rom.print("MARK WIFI_JOIN refused: ssid or psk too long\r\n", .{}); + return; + } + @memcpy(ssid[0..config.wifi_ssid.len], config.wifi_ssid); + @memcpy(psk[0..config.wifi_psk.len], config.wifi_psk); + + // The SSID is printed; the passphrase is not, and only its length is, which is enough to tell a + // missing -Dpsk from a wrong one without putting the secret on a serial line. + soc.rom.print("MARK WIFI_JOIN ssid=%s psk_len=%u\r\n", .{ + @as([*:0]const u8, @ptrCast(&ssid)), + @as(u32, @intCast(config.wifi_psk.len)), + }); + + const rc = hosted_wifi_connect(@ptrCast(&ssid), @ptrCast(&psk)); + soc.rom.print("MARK WIFI_CONNECT rc=%d\r\n", .{rc}); + if (rc != 0) return; + + // Association is asynchronous: the C6 answers the request immediately and reports the outcome + // as an event. `onEvent` prints those, so the job here is to keep the scheduler running and put + // a bound on the wait. + soc.rom.print("MARK WIFI_WAIT for association events\r\n", .{}); +} + +fn report(runtime: *p4.Runtime) void { + const s = net.port.stats(); + soc.rom.print("MARK RADIO_HEAP live=%u B reserved=%u B peak=%u B blocks=%u fails=%u\r\n", .{ + @as(u32, @intCast(s.bytes_live)), + @as(u32, @intCast(s.bytes_reserved)), + @as(u32, @intCast(s.peak_reserved)), + @as(u32, @intCast(s.blocks_live)), + @as(u32, @intCast(s.alloc_failures)), + }); + // A non-zero stub count is not a failure - it names the next layer to write. Printing it is + // what turns "it hung somewhere" into "it wanted rpc_start". `sleeps` is the same idea one + // layer up: it is the running total of ESP-Hosted's RPC not-ready spins, so the value here is + // the baseline that `MARK WIFI_START spun=` is measured against. + soc.rom.print("MARK RADIO_STUBS %u sleeps=%u\r\n", .{ s.stub_calls, s.hosted_sleep_calls }); + // Per-task stack high-water marks, so the 4 KiB above becomes a measurement. + runtime.dump(); +} + +fn nowMs() u64 { + // The systimer is a fixed 16 MHz and the only trustworthy timebase here: the CPU runs at the + // bootloader's 90 MHz and nothing in this image reconfigures the PLL. A failed snapshot read + // yields 0, which makes the elapsed calculation conservative rather than wrong. + const ticks = hal.systimer.read(.unit0) orelse return 0; + return ticks / 16_000; +} + +fn park() noreturn { + soc.rom.print("MARK RADIO_DONE parked\r\n", .{}); + while (true) {} +} diff --git a/examples/rf.zig b/examples/rf.zig new file mode 100644 index 0000000..93babbd --- /dev/null +++ b/examples/rf.zig @@ -0,0 +1,613 @@ +//! The RF experiment from `04-report` section 5, re-emitted from this toolchain. +//! +//! zig build -Dapp=examples/rf.zig flash +//! cd ../02-esp32p4-m3-radio && tools/rfprobe.py chop --tag zig-tone-chop --cmd-on T --cmd-off o +//! cd ../02-esp32p4-m3-radio && tools/rfprobe.py iq --tag zig-tone-burst --cmd-on t --keep-iq +//! cd ../02-esp32p4-m3-radio && tools/decode_tone.py captures/zig-tone-burst.iq +//! +//! The original firmware was ESP-IDF: FreeRTOS tasks, `ledc_timer_config`, `esp_timer_get_time`, +//! `printf`. This is the same physical experiment driven by this project's own HAL, so the SDR and +//! the unmodified analysis tools become an external oracle on the HAL: if `hal.ledc`'s divider +//! arithmetic, `hal.gpio`'s matrix routing or `hal.systimer`'s timebase are wrong, the captured +//! carrier lands on a different frequency, the pulse widths drift, or the decoded word is not +//! 0x4200. +//! +//! What is reproducible here and what is not, stated up front: +//! +//! * **Reproducible: the 25 MHz keyed carrier.** It is the P4's own pin, driven by LEDC. That is +//! the whole of section 5, including the only real SDR spectrum in the report. +//! * **Not reproducible: Wi-Fi, BLE, 802.15.4.** The P4 has no radio. Those went out over an +//! ESP32-C6 across SDIO under `esp_hosted` + `esp_wifi_remote` - a 19,000-line host stack plus a +//! prebuilt coprocessor binary, none of which exists here and none of which is low-level +//! hardware. Section 4 of the report is out of this toolchain's scope by construction, and +//! claiming otherwise would be the dishonest part. +//! +//! The frequency is the sharp end. LEDC at 1-bit duty resolution off the 80 MHz PLL-derived clock +//! cannot synthesise a round 25 MHz: the Q10.8 divider closest to it is 410 (= 1.6015625), giving +//! 80e6 * 256 / (410 * 2) = 24,975,609 Hz. The report measured 24.977455 MHz by phase slope, +73.9 +//! ppm from that. So the number this firmware should produce is 24.9756 MHz, not 25.0 MHz, and it is +//! predicted by the divider arithmetic rather than by the requested frequency. + +const std = @import("std"); +const soc = @import("soc"); +const hal = @import("hal"); +const regs = @import("regs"); +const mmio = @import("mmio"); + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK RF_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +/// GPIO20, JP1 pin 17: the LED pin when blinking, the carrier pin when keyed. Same pad the report +/// used, which matters because the antenna coupling is whatever the header wire happens to be. +const tone_pin: u8 = 20; +const tone_channel: u32 = 0; +const tone_timer: u32 = 0; + +/// The word, MSB first, and the frame that carries it: 500 ms preamble, 200 ms gap, then 16 cells of +/// 100 ms carrier-if-set followed by 100 ms silence. 3.9 s total. Identical to the C firmware's +/// `tone_burst`, because `decode_tone.py` uses PREAMBLE_MS and GAP_MS as known constants. +const key_word: u16 = 0x4200; +const preamble_ms: u32 = 500; +const gap_ms: u32 = 200; +const cell_ms: u32 = 100; + +var carrier_running = false; + +/// The console. UART0 is where the CH340 is wired and where the ROM's printf goes, so the transmit +/// side is already working; this is only ever used to *read* commands. +/// +/// Reading is the one thing that is safe to do to this peripheral here. Its FIFO register at offset +/// 0 pops on read - which is exactly what a console reader wants, and is the same property that +/// makes a register-block snapshot of a UART unsound. Nothing in this file reconfigures UART0: a +/// reset or a baud change on the console would cut the wire this experiment reports over. +const console = hal.uart.Uart.init(0); + +/// ESP-IDF's own LEDC LL, compiled into this image by `-Doracle`. Present so the two +/// implementations can be compared with *one* instrument on *one* board in *one* boot: the register +/// differential already proves they write the same words, so the only question left is behavioural, +/// and a claim about behaviour needs both sides measured the same way. +extern fn oracle_ledc_configure_timer(timer: c_uint, src_hz: c_uint, freq_hz: c_int, resolution: c_uint) void; +extern fn oracle_ledc_configure_channel(channel: c_uint, timer: c_uint, duty: c_uint, hpoint: c_uint, idle_level: c_uint, output_enabled: c_int) void; +extern fn oracle_ledc_set_pin(pin: c_uint, channel: c_uint) void; + +/// Count rising edges on the carrier pad, bounded. The instrument for the A/B below. +fn countEdges(reads: u32) u32 { + var seen: u32 = 0; + var prev: u1 = hal.gpio.getLevel(tone_pin); + var g: u32 = 0; + while (g < reads) : (g += 1) { + const v = hal.gpio.getLevel(tone_pin); + if (v == 1 and prev == 0) seen += 1; + prev = v; + } + return seen; +} + +fn micros() u64 { + return hal.systimer.micros(.unit0) orelse 0; +} + +fn mark(comptime event: [*:0]const u8, comptime detail: [*:0]const u8) void { + soc.rom.print("MARK %s %s t=%uus\r\n", .{ event, detail, @as(u32, @truncate(micros())) }); +} + +fn delayMs(ms: u32) void { + hal.systimer.delayMicros(ms * 1000); +} + +// ------------------------------------------------------------------------------- the emitter + +/// Bring LEDC up on the 80 MHz source and stage the carrier, without starting it. +fn toneInit() void { + hal.clkrst.init(.ledc); + hal.ledc.init(.pll_div); + + // 1-bit duty resolution: the counter has two states, so a duty of 1 is a 50 % square wave and + // the output frequency is the timer frequency. Asking for 25 MHz gets divider 410 and therefore + // 24.9756 MHz - the arithmetic is IDF's, reproduced exactly, including its rounding. + hal.ledc.configureTimer(tone_timer, .{ + .resolution = 1, + .freq_hz = 25_000_000, + .src_hz = hal.ledc.pll_div_hz, + }) catch { + mark("TONE_FAIL", "divider out of range for 25MHz at 1-bit resolution"); + return; + }; + + hal.ledc.configureChannel(tone_channel, .{ + .timer = tone_timer, + .duty = 1, // half of 2^1: a square wave + .hpoint = 0, + .idle_level = 0, + }); + hal.ledc.attachPin(tone_channel, tone_pin); + hal.ledc.stop(tone_channel, 0); + carrier_running = false; +} + +fn toneOn() void { + hal.ledc.start(tone_channel); + carrier_running = true; +} + +fn toneOff() void { + hal.ledc.stop(tone_channel, 0); + carrier_running = false; +} + +/// The keyed frame. Timed with the systimer rather than a task delay, so the cell widths depend on +/// a 16 MHz counter instead of on a scheduler tick - the report measured 100.062 ms and 100.000 ms +/// against 100 ms commanded, and that is the number to beat. +fn toneBurst() void { + mark("TONE_START", "gpio20 24975609Hz pattern=0x4200"); + + toneOn(); + delayMs(preamble_ms); + toneOff(); + delayMs(gap_ms); + + var bit: i32 = 15; + while (bit >= 0) : (bit -= 1) { + if (key_word & (@as(u16, 1) << @intCast(bit)) != 0) toneOn(); + delayMs(cell_ms); + toneOff(); + delayMs(cell_ms); + } + + mark("TONE_END", "gpio20 24975609Hz pattern=0x4200"); + // Hand the pad back as a readable output, the way the C firmware did, so the blink witness still + // works afterwards. + hal.gpio.configureOutput(tone_pin, .{ .readback = true }); +} + +/// Ten samples at 125 ms, the C firmware's proof that the pad is really toggling rather than sitting +/// at a level. A 1 Hz blink sampled at 125 ms must show runs of four. +fn blinkWitness() void { + soc.rom.print("MARK BLINK_WITNESS gpio20 levels:", .{}); + var i: u32 = 0; + while (i < 10) : (i += 1) { + soc.rom.print(" %u", .{@as(u32, hal.gpio.getLevel(tone_pin))}); + delayMs(125); + } + soc.rom.print(" t=%uus\r\n", .{@as(u32, @truncate(micros()))}); +} + +/// On-chip corroboration that the pad is really switching, before believing anything an SDR says. +/// +/// The report did this with the ADC (GPIO20 is also ADC1 channel 4) and read the min and max of a +/// 64-sample burst rather than the mean, because the ADC cannot track 25 MHz and its sampling phase +/// is uncorrelated with the pad. This HAL has no ADC, so it uses the pad's own input register +/// instead: at ~90 MHz the core can issue a load every few cycles, so a run of reads across a +/// 25 MHz square wave must catch both levels. Catching only one level means the pin is sitting +/// still, which is the failure an SDR null cannot distinguish from bad coupling. +fn padSample() void { + var ones: u32 = 0; + var zeros: u32 = 0; + var edges: u32 = 0; + var prev: u1 = hal.gpio.getLevel(tone_pin); + var i: u32 = 0; + // The sampling phase has to be *uncorrelated* with the signal, and a tight read loop is not. + // + // A first version read the pad 4096 times back to back and reported "constant high" for every + // carrier at or above 20 MHz - including 40 MHz, which is exactly APB/2, and 20 MHz, exactly + // APB/4. Both the read cadence and the LEDC output descend from the same clock, so a loop with a + // fixed period samples one phase of the waveform forever and reports a level that is not there. + // The ESP-IDF firmware avoided this by accident of its instrument: it used the ADC, whose + // conversion time is unrelated to the pad, and the report is explicit that its min/max - never + // its mean - is what carries the information. + // + // The software equivalent is to walk the phase deliberately: a delay that grows by one cycle + // every iteration cannot stay locked to any fixed period. + var jitter: u32 = 0; + while (i < 4096) : (i += 1) { + jitter = (jitter + 1) & 63; + var d: u32 = 0; + while (d < jitter) : (d += 1) asm volatile ("nop"); + const v = hal.gpio.getLevel(tone_pin); + if (v == 1) ones += 1 else zeros += 1; + if (v != prev) edges += 1; + prev = v; + } + soc.rom.print("MARK PAD_SAMPLE carrier=%u ones=%u zeros=%u edges=%u of 4096 t=%uus\r\n", .{ + @as(u32, @intFromBool(carrier_running)), ones, zeros, edges, @as(u32, @truncate(micros())), + }); +} + +/// The registers that decide whether this pin oscillates, printed rather than inferred. +fn dumpRegs() void { + const ledc_base: u32 = @intCast(regs.LEDC_CH0_CONF0_REG); + soc.rom.print("MARK REGDUMP ch0_conf0=0x%08x ch0_hpoint=0x%08x ch0_duty=0x%08x ch0_conf1=0x%08x\r\n", .{ + mmio.Reg.atAddress(ledc_base).raw(), + mmio.Reg.atAddress(@intCast(regs.LEDC_CH0_HPOINT_REG)).raw(), + mmio.Reg.atAddress(@intCast(regs.LEDC_CH0_DUTY_REG)).raw(), + mmio.Reg.atAddress(@intCast(regs.LEDC_CH0_CONF1_REG)).raw(), + }); + soc.rom.print("MARK REGDUMP timer0_conf=0x%08x timer0_value=0x%08x ledc_conf=0x%08x\r\n", .{ + mmio.Reg.atAddress(@intCast(regs.LEDC_TIMER0_CONF_REG)).raw(), + mmio.Reg.atAddress(@intCast(regs.LEDC_TIMER0_VALUE_REG)).raw(), + mmio.Reg.atAddress(@intCast(regs.LEDC_CONF_REG)).raw(), + }); + soc.rom.print("MARK REGDUMP pad20=0x%08x matrix_out20=0x%08x gpio_out=0x%08x gpio_enable=0x%08x\r\n", .{ + mmio.Reg.atAddress(@as(u32, @intCast(regs.PERIPHS_IO_MUX_U_PAD_GPIO0)) + 4 * 20).raw(), + mmio.Reg.atAddress(@as(u32, @intCast(regs.GPIO_FUNC0_OUT_SEL_CFG_REG)) + 4 * 20).raw(), + mmio.Reg.atAddress(@intCast(regs.GPIO_OUT_REG)).raw(), + mmio.Reg.atAddress(@intCast(regs.GPIO_ENABLE_REG)).raw(), + }); + // The active shadow, and the counter sampled twice: `duty` is what was staged, `duty_r` is what + // the hardware is using, and a counter that does not move between two reads has no clock. + const v1 = mmio.Reg.atAddress(@intCast(regs.LEDC_TIMER0_VALUE_REG)).raw(); + const v2 = mmio.Reg.atAddress(@intCast(regs.LEDC_TIMER0_VALUE_REG)).raw(); + soc.rom.print("MARK REGDUMP duty_r=0x%08x cnt1=0x%08x cnt2=0x%08x moved=%u\r\n", .{ + mmio.Reg.atAddress(@intCast(regs.LEDC_CH0_DUTY_R_REG)).raw(), + v1, v2, @as(u32, @intFromBool(v1 != v2)), + }); + soc.rom.print("MARK REGDUMP ledc_sig_idx=%u clkrst_ctrl22=0x%08x t=%uus\r\n", .{ + @as(u32, @intCast(regs.LEDC_LS_SIG_OUT_PAD_OUT0_IDX)), + mmio.Reg.atAddress(@intCast(regs.HP_SYS_CLKRST_PERI_CLK_CTRL22_REG)).raw(), + @as(u32, @truncate(micros())), + }); +} + +fn status() void { + const div = hal.ledc.getClockDivider(tone_timer); + soc.rom.print( + "MARK STATUS carrier=%u divider=%u(Q10.8) freq=%uHz src=80000000Hz pin=%u cpu_mhz_x1000=%u t=%uus\r\n", + .{ + @as(u32, @intFromBool(carrier_running)), + div, + hal.ledc.frequencyOf(hal.ledc.pll_div_hz, div, 1), + @as(u32, tone_pin), + cpuKhz(), + @as(u32, @truncate(micros())), + }, + ); +} + +/// The CPU clock, measured against the systimer's fixed 16 MHz rather than assumed. Printed in the +/// status line because every timing number in this experiment depends on the systimer, and this is +/// the cheapest continuous check that its timebase is what it claims. +fn cpuKhz() u32 { + const t0 = hal.systimer.read(.unit0) orelse return 0; + const c0 = soc.cycles(); + soc.rom.ets_delay_us(20_000); + const t1 = hal.systimer.read(.unit0) orelse return 0; + const c1 = soc.cycles(); + const ticks = t1 - t0; + if (ticks == 0) return 0; + return @intCast(((c1 - c0) * (hal.systimer.hz / 1000)) / ticks); +} + +export fn zig_main() noreturn { + // Without this the board resets about ten seconds in, which for a 3.9 s frame captured inside a + // 10 s SDR dwell is the difference between a capture and a reboot. + _ = hal.rwdt.disable(); + + hal.systimer.init(); + hal.gpio.configureOutput(tone_pin, .{ .readback = true }); + toneInit(); + + soc.rom.print("\r\nMARK RF_READY zig toolchain, no esp-idf, no freertos\r\n", .{}); + status(); + soc.rom.print( + \\commands: T carrier on o carrier off t keyed burst (0x4200) + \\ ? status g blink witness p pad sampler i idle + \\ + , .{}); + + // The command loop doubles as the 1 Hz blink when nothing is being transmitted, so the pad is + // never left floating and `g` has something to witness. + var last_toggle = micros(); + var level: u1 = 0; + while (true) { + if (console.rxCount() > 0) { + var buf: [1]u8 = undefined; + if (console.read(&buf) == 1) { + switch (buf[0]) { + 'T' => { + toneOn(); + mark("TONE_CONTINUOUS_ON", "gpio20 24975609Hz square"); + }, + 'o' => { + toneOff(); + mark("TONE_OFF", "gpio20 released to blink"); + hal.gpio.configureOutput(tone_pin, .{ .readback = true }); + }, + 't' => toneBurst(), + '?' => status(), + 'g' => blinkWitness(), + 'p' => padSample(), + 'd' => dumpRegs(), + // Experiment: hand the pad's output enable back to GPIO_ENABLE (oen_sel = 1) + // instead of to the routed peripheral. LEDC's signal carries no output-enable + // line, so with oen_sel = 0 there may be nothing asserting OE at all. + // Bisection: a slow LEDC output that the pad sampler can obviously see. If this + // toggles, LEDC and the routing work and the 25 MHz case is about the divider or + // a frequency ceiling; if it does not, the output path itself is broken. + 's' => { + hal.ledc.configureTimer(tone_timer, .{ + .resolution = 8, + .freq_hz = 1000, + .src_hz = hal.ledc.pll_div_hz, + }) catch { + soc.rom.print("MARK SLOW_FAIL divider out of range\r\n", .{}); + continue; + }; + hal.ledc.configureChannel(tone_channel, .{ + .timer = tone_timer, + .duty = 128, // half of 2^8 + .hpoint = 0, + .idle_level = 0, + }); + hal.ledc.attachPin(tone_channel, tone_pin); + hal.ledc.start(tone_channel); + carrier_running = true; + const div = hal.ledc.getClockDivider(tone_timer); + soc.rom.print("MARK SLOW_ON 1kHz 8-bit divider=%u freq=%uHz\r\n", .{ + div, hal.ledc.frequencyOf(hal.ledc.pll_div_hz, div, 8), + }); + }, + // Where does it stop? Sweep resolution/frequency pairs and count edges on the + // pad. This turns "25 MHz does not work" into a measured ceiling. + 'S' => { + const cases = [_]struct { res: u5, hz: u32 }{ + .{ .res = 8, .hz = 1_000 }, + .{ .res = 8, .hz = 100_000 }, + .{ .res = 4, .hz = 1_000_000 }, + .{ .res = 2, .hz = 5_000_000 }, + .{ .res = 2, .hz = 12_500_000 }, + .{ .res = 1, .hz = 1_000_000 }, + .{ .res = 1, .hz = 10_000_000 }, + .{ .res = 1, .hz = 20_000_000 }, + .{ .res = 1, .hz = 25_000_000 }, + .{ .res = 1, .hz = 40_000_000 }, + }; + inline for (cases) |c| { + const want_div = hal.ledc.divisor(hal.ledc.pll_div_hz, c.hz, c.res); + if (!hal.ledc.divisorValid(want_div)) { + soc.rom.print("MARK SWEEP res=%u want=%uHz div=%u REJECTED\r\n", .{ + @as(u32, c.res), c.hz, want_div, + }); + } else { + hal.ledc.setClockDivider(tone_timer, want_div); + hal.ledc.setDutyResolution(tone_timer, c.res); + hal.ledc.commitTimer(tone_timer); + hal.ledc.resumeTimer(tone_timer); + hal.ledc.resetTimer(tone_timer); + hal.ledc.configureChannel(tone_channel, .{ + .timer = tone_timer, + .duty = @as(u32, 1) << (c.res - 1), + .hpoint = 0, + .idle_level = 0, + }); + hal.ledc.attachPin(tone_channel, tone_pin); + hal.ledc.start(tone_channel); + var ones: u32 = 0; + var edges: u32 = 0; + var prev: u1 = hal.gpio.getLevel(tone_pin); + var k: u32 = 0; + while (k < 2048) : (k += 1) { + const v = hal.gpio.getLevel(tone_pin); + if (v == 1) ones += 1; + if (v != prev) edges += 1; + prev = v; + } + soc.rom.print("MARK SWEEP res=%u want=%uHz div=%u got=%uHz ones=%u edges=%u\r\n", .{ + @as(u32, c.res), c.hz, want_div, + hal.ledc.frequencyOf(hal.ledc.pll_div_hz, want_div, c.res), + ones, edges, + }); + } + } + hal.ledc.stop(tone_channel, 0); + carrier_running = false; + }, + // The LEDC registers are bit-identical to ESP-IDF's for this configuration + // (proven by the differential harness, 96 words), so if the pad still does not + // move the difference is in a clock mux outside the block. There are two: + // HP_SYS_CLKRST.peri_clk_ctrl22.reg_ledc_clk_src_sel, and LEDC_CONF.APB_CLK_SEL + // inside the block whose documented meaning is 0=APB_CLK, 1=RC_FAST, 2=XTAL, + // 3=invalid. Try every combination and sample the pad. + // Measure the LEDC output period against the systimer's fixed 16 MHz, at a + // frequency slow enough to time edges reliably. That yields the *actual* source + // clock, which is the number every divider here assumes and none has verified: + // this image runs at whatever the bootloader left (90 MHz CPU), not at the + // 360 MHz the ESP-IDF firmware configures, so its APB need not be 80 MHz. + // The A/B that settles it: ESP-IDF's LL and this HAL, same image, same pad, same + // edge counter, at the resolutions that matter. + 'A' => { + const cases = [_]struct { hz: u32, res: u5 }{ + .{ .hz = 5_000_000, .res = 2 }, + .{ .hz = 10_000_000, .res = 1 }, + .{ .hz = 25_000_000, .res = 1 }, + }; + inline for (cases) |c| { + // ESP-IDF's side. + oracle_ledc_configure_timer(tone_timer, hal.ledc.pll_div_hz, @intCast(c.hz), c.res); + oracle_ledc_configure_channel(tone_channel, tone_timer, @as(u32, 1) << (c.res - 1), 0, 0, 1); + oracle_ledc_set_pin(tone_pin, tone_channel); + const idf_edges = countEdges(300_000); + // Ours. + hal.ledc.configureTimer(tone_timer, .{ + .resolution = c.res, .freq_hz = c.hz, .src_hz = hal.ledc.pll_div_hz, + }) catch {}; + hal.ledc.configureChannel(tone_channel, .{ + .timer = tone_timer, .duty = @as(u32, 1) << (c.res - 1), + .hpoint = 0, .idle_level = 0, + }); + hal.ledc.attachPin(tone_channel, tone_pin); + hal.ledc.start(tone_channel); + const our_edges = countEdges(300_000); + soc.rom.print("MARK AB res=%u hz=%u idf_edges=%u our_edges=%u (300k reads each)\r\n", .{ + @as(u32, c.res), c.hz, idf_edges, our_edges, + }); + } + hal.ledc.stop(tone_channel, 0); + carrier_running = false; + }, + 'F' => { + // Same measurement across rates, with a generous guard: the question is only + // whether ANY edge appears, so a read loop that cannot keep up with the rate + // still answers it. + const rates = [_]struct { hz: u32, res: u5 }{ + .{ .hz = 10_000, .res = 8 }, .{ .hz = 1_000_000, .res = 4 }, + .{ .hz = 5_000_000, .res = 2 }, .{ .hz = 10_000_000, .res = 1 }, + .{ .hz = 15_000_000, .res = 1 }, .{ .hz = 20_000_000, .res = 1 }, + .{ .hz = 25_000_000, .res = 1 }, + }; + inline for (rates) |r| { + const d = hal.ledc.divisor(hal.ledc.pll_div_hz, r.hz, r.res); + hal.ledc.setClockDivider(tone_timer, d); + hal.ledc.setDutyResolution(tone_timer, r.res); + hal.ledc.commitTimer(tone_timer); + hal.ledc.resumeTimer(tone_timer); + hal.ledc.resetTimer(tone_timer); + hal.ledc.configureChannel(tone_channel, .{ + .timer = tone_timer, + .duty = @as(u32, 1) << (r.res - 1), + .hpoint = 0, + .idle_level = 0, + }); + hal.ledc.attachPin(tone_channel, tone_pin); + hal.ledc.start(tone_channel); + var seen: u32 = 0; + var prev: u1 = hal.gpio.getLevel(tone_pin); + var g: u32 = 0; + while (seen < 200 and g < 2_000_000) : (g += 1) { + const v = hal.gpio.getLevel(tone_pin); + if (v == 1 and prev == 0) seen += 1; + prev = v; + } + soc.rom.print("MARK EDGES want=%uHz res=%u div=%u rising_edges=%u in %u reads\r\n", .{ + r.hz, @as(u32, r.res), d, seen, g, + }); + } + hal.ledc.stop(tone_channel, 0); + carrier_running = false; + }, + 'f' => { + const want: u32 = 10_000; + const res: u5 = 8; + const div = hal.ledc.divisor(hal.ledc.pll_div_hz, want, res); + hal.ledc.setClockDivider(tone_timer, div); + hal.ledc.setDutyResolution(tone_timer, res); + hal.ledc.commitTimer(tone_timer); + hal.ledc.resumeTimer(tone_timer); + hal.ledc.resetTimer(tone_timer); + hal.ledc.configureChannel(tone_channel, .{ + .timer = tone_timer, .duty = 128, .hpoint = 0, .idle_level = 0, + }); + hal.ledc.attachPin(tone_channel, tone_pin); + hal.ledc.start(tone_channel); + // Time 100 rising edges. + var seen: u32 = 0; + var prev: u1 = hal.gpio.getLevel(tone_pin); + const t_start = hal.systimer.read(.unit0) orelse 0; + var guard: u32 = 0; + while (seen < 100 and guard < 20_000_000) : (guard += 1) { + const v = hal.gpio.getLevel(tone_pin); + if (v == 1 and prev == 0) seen += 1; + prev = v; + } + const t_end = hal.systimer.read(.unit0) orelse 0; + const us = (t_end - t_start) / (hal.systimer.hz / 1_000_000); + // measured_hz = edges / seconds; source = measured * div * 2^res / 256 + const measured_hz: u64 = if (us != 0) (@as(u64, seen) * 1_000_000) / us else 0; + const src_est: u64 = (measured_hz * div * (@as(u64, 1) << res)) / 256; + soc.rom.print("MARK FREQ want=%uHz div=%u edges=%u in %uus -> measured=%uHz implied_src=%uHz\r\n", .{ + want, div, seen, @as(u32, @truncate(us)), + @as(u32, @truncate(measured_hz)), @as(u32, @truncate(src_est)), + }); + }, + 'M' => { + const ctrl22 = mmio.Reg.at(regs.HP_SYS_CLKRST_PERI_CLK_CTRL22_REG); + const src_sel = mmio.Field.of(regs.HP_SYS_CLKRST_REG_LEDC_CLK_SRC_SEL_S, regs.HP_SYS_CLKRST_REG_LEDC_CLK_SRC_SEL_V); + const fclk_en = mmio.Field.of(regs.HP_SYS_CLKRST_REG_LEDC_CLK_EN_S, regs.HP_SYS_CLKRST_REG_LEDC_CLK_EN_V); + const conf = mmio.Reg.at(regs.LEDC_CONF_REG); + const apb_sel = mmio.Field.of(regs.LEDC_APB_CLK_SEL_S, regs.LEDC_APB_CLK_SEL_V); + var ssel: u32 = 0; + while (ssel < 3) : (ssel += 1) { + var asel: u32 = 0; + while (asel < 3) : (asel += 1) { + ctrl22.modify(.{ src_sel.is(ssel), fclk_en.is(1) }); + conf.modify(.{apb_sel.is(asel)}); + hal.ledc.configureTimer(tone_timer, .{ + .resolution = 1, + .freq_hz = 25_000_000, + .src_hz = hal.ledc.pll_div_hz, + }) catch {}; + hal.ledc.configureChannel(tone_channel, .{ + .timer = tone_timer, + .duty = 1, + .hpoint = 0, + .idle_level = 0, + }); + hal.ledc.attachPin(tone_channel, tone_pin); + hal.ledc.start(tone_channel); + var ones: u32 = 0; + var edges: u32 = 0; + var prev: u1 = hal.gpio.getLevel(tone_pin); + var k: u32 = 0; + var jit: u32 = 0; + while (k < 1024) : (k += 1) { + jit = (jit + 1) & 31; + var d: u32 = 0; + while (d < jit) : (d += 1) asm volatile ("nop"); + const v = hal.gpio.getLevel(tone_pin); + if (v == 1) ones += 1; + if (v != prev) edges += 1; + prev = v; + } + soc.rom.print("MARK MUX src_sel=%u apb_sel=%u ones=%u edges=%u of 1024\r\n", .{ + ssel, asel, ones, edges, + }); + } + } + }, + 'E' => { + const sel = mmio.Reg.atAddress(@as(u32, @intCast(regs.GPIO_FUNC0_OUT_SEL_CFG_REG)) + 4 * @as(u32, tone_pin)); + sel.modify(.{mmio.Field.of(regs.GPIO_FUNC0_OEN_SEL_S, regs.GPIO_FUNC0_OEN_SEL_V).is(1)}); + hal.gpio.outputEnable(tone_pin); + soc.rom.print("MARK OEN_SEL set to 1 (GPIO_ENABLE drives OE), matrix_out20=0x%08x\r\n", .{sel.raw()}); + }, + 'i' => { + toneOff(); + hal.gpio.configureOutput(tone_pin, .{ .readback = true }); + mark("IDLE", "-"); + }, + else => {}, + } + } + } + + if (!carrier_running) { + const now = micros(); + if (now - last_toggle >= 500_000) { + last_toggle = now; + level = ~level; + hal.gpio.setLevel(tone_pin, level); + } + } + } +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} diff --git a/examples/sdiocheck.zig b/examples/sdiocheck.zig new file mode 100644 index 0000000..d9fde11 --- /dev/null +++ b/examples/sdiocheck.zig @@ -0,0 +1,321 @@ +//! Does CMD53 return the same bytes as CMD52? +//! +//! Written to settle one question during radio bring-up. The transport gets all the way to "Open +//! data path at slave" and then never sees the slave's NEW_PACKET bit, which it learns by reading the +//! slave's interrupt register through `sdio_read_regs` - a multi-byte read, so CMD53. CMD52 is +//! already proven on this board: the CCCR write-and-read-back during card init cannot succeed +//! without it. CMD53 is not, and it is the one that uses the IDMAC and therefore the one exposed to +//! every DMA and cache mistake. +//! +//! The test is a differential against the bus itself. Read the same slave register window twice - +//! once with a single CMD53, once byte at a time with CMD52 - and compare. Both go to the same +//! addresses on the same card in the same boot, so a disagreement is our CMD53 and nothing else. +//! +//! Registers are the ones the transport actually reads, from +//! host/drivers/transport/sdio/sdio_reg.h, masked with ESP_ADDRESS_MASK (0x3FF) exactly as +//! `hosted_sdio_read_reg` does at port_esp_hosted_host_sdio.c:500: +//! +//! 0x050 ESP_SLAVE_INT_RAW_REG bit 23 is RX_NEW_PACKET, the bit the read task waits for +//! 0x058 ESP_SLAVE_INT_ST_REG +//! 0x060 ESP_SLAVE_PACKET_LEN_REG the slave's cumulative TX length counter +//! 0x044 ESP_SLAVE_TOKEN_RDATA the slave's receive-buffer credit +//! 0x06C ESP_SLAVE_SCRATCH_REG_0 written by the coprocessor firmware +//! +//! What the output means: +//! +//! MARK SDIO_CMP ... SAME CMD53 agrees with CMD52 - the data path is good and the missing +//! NEW_PACKET is the slave's silence, not our bus +//! MARK SDIO_CMP ... DIFFER CMD53 is broken; the bytes printed say how (all-zero is a DMA that +//! never landed, stale is a cache view, shifted is an address or +//! length error) +//! MARK SDIO_LEN ... the slave's packet-length counter, read twice a second apart. If it +//! moves, the C6 is queueing data for us and the fault is on the host +//! side of the interrupt. If it never moves, the C6 has nothing to say. +//! +//! Run: zig build -Dapp=examples/sdiocheck.zig run -Dseconds=15 + +const std = @import("std"); +const soc = @import("soc"); +const hal = @import("hal"); + +pub const panic = std.debug.FullPanic(struct { + fn call(msg: []const u8, _: ?usize) noreturn { + soc.rom.print("MARK SDIO_PANIC %s\r\n", .{msg.ptr}); + while (true) {} + } +}.call); + +/// FN1: every slave register lives in function 1 (port_esp_hosted_host_sdio.c:505). +const func: u3 = 1; + +/// The windows to compare. Length 4 for the 32-bit registers, and one longer run to catch a length +/// or block-boundary error that a 4-byte read would not. +const windows = [_]struct { name: [*:0]const u8, addr: u17, len: usize }{ + .{ .name = "INT_RAW 0x050", .addr = 0x050, .len = 4 }, + .{ .name = "INT_ST 0x058", .addr = 0x058, .len = 4 }, + .{ .name = "PKT_LEN 0x060", .addr = 0x060, .len = 4 }, + .{ .name = "TOKEN 0x044", .addr = 0x044, .len = 4 }, + .{ .name = "SCRATCH 0x06C", .addr = 0x06C, .len = 4 }, + .{ .name = "RUN 0x050", .addr = 0x050, .len = 16 }, +}; + +export fn zig_main() noreturn { + _ = hal.rwdt.disable(); + soc.rom.print("\r\nMARK SDIO_START\r\n", .{}); + + // The C6 must be out of reset and booted before it will answer anything. Active low with an + // external pull-up: drive low to hold, release to run. Driving it high would fight the pull-up. + hal.gpio.configureOutput(54, .{}); + hal.gpio.setLow(54); + soc.rom.ets_delay_us(20_000); + hal.gpio.outputDisable(54); // release; the pull-up takes it high + soc.rom.print("MARK SDIO_RESET released gpio54, waiting for the C6 to boot\r\n", .{}); + soc.rom.ets_delay_us(1_500_000); + + hal.sdmmc.init(.{ .slot = 1, .width = .four, .khz = 40_000 }) catch |err| { + soc.rom.print("MARK SDIO_FAIL init=%s\r\n", .{@errorName(err).ptr}); + park(); + }; + hal.sdmmc.cardInit() catch |err| { + soc.rom.print("MARK SDIO_FAIL cardInit=%s\r\n", .{@errorName(err).ptr}); + park(); + }; + soc.rom.print("MARK SDIO_CARD up\r\n", .{}); + + // FN1 must be enabled and ready before its registers answer, exactly as card init does for the + // transport. Without this the reads below are against a disabled function and return zeros - + // which would look identical to a broken CMD53, so it is done explicitly rather than assumed. + enableFn1() catch |err| { + soc.rom.print("MARK SDIO_FAIL fn1=%s\r\n", .{@errorName(err).ptr}); + park(); + }; + + var buf53: [32]u8 = undefined; + var buf52: [32]u8 = undefined; + var differ: u32 = 0; + + for (windows) |w| { + // CMD53 first, then CMD52, then CMD53 again. The third read is what tells a genuine + // disagreement apart from a register that simply changed between the two reads - these are + // live status registers, and a differing INT_RAW could be honest. + hal.sdmmc.cmd53Read(func, w.addr, buf53[0..w.len], true) catch |err| { + soc.rom.print("MARK SDIO_CMP %s cmd53=%s\r\n", .{ w.name, @errorName(err).ptr }); + differ += 1; + continue; + }; + for (0..w.len) |i| { + buf52[i] = hal.sdmmc.cmd52Read(func, @intCast(w.addr + i)) catch { + soc.rom.print("MARK SDIO_CMP %s cmd52 failed at +%u\r\n", .{ w.name, @as(u32, @intCast(i)) }); + differ += 1; + break; + }; + } + const same = std.mem.eql(u8, buf53[0..w.len], buf52[0..w.len]); + if (!same) differ += 1; + soc.rom.print("MARK SDIO_CMP %s len=%u cmd53=%s cmd52=%s %s\r\n", .{ + w.name, + @as(u32, @intCast(w.len)), + hex(&buf53, w.len, &hexbuf_a), + hex(&buf52, w.len, &hexbuf_b), + @as([*:0]const u8, if (same) "SAME" else "DIFFER"), + }); + } + soc.rom.print("MARK SDIO_CMP_TOTAL windows=%u differing=%u\r\n", .{ + @as(u32, windows.len), differ, + }); + + // Is the slave producing anything at all? PACKET_LEN is a cumulative counter of bytes the slave + // has made available. Sampled twice a second apart: movement means the C6 is queueing data and + // the fault is on our side of the interrupt; no movement means it has nothing to send. + var a: [4]u8 = undefined; + var b: [4]u8 = undefined; + hal.sdmmc.cmd53Read(func, 0x060, &a, true) catch {}; + soc.rom.ets_delay_us(1_000_000); + hal.sdmmc.cmd53Read(func, 0x060, &b, true) catch {}; + const len_a = std.mem.readInt(u32, &a, .little) & 0xFFFFF; + const len_b = std.mem.readInt(u32, &b, .little) & 0xFFFFF; + soc.rom.print("MARK SDIO_LEN first=%u second=%u moved=%u\r\n", .{ + len_a, len_b, @as(u32, @intFromBool(len_a != len_b)), + }); + + // And the interrupt register, decoded, because bit 23 is the whole question. + var ir: [4]u8 = undefined; + hal.sdmmc.cmd53Read(func, 0x050, &ir, true) catch {}; + const raw = std.mem.readInt(u32, &ir, .little); + soc.rom.print("MARK SDIO_INTRAW 0x%08x new_packet=%u\r\n", .{ + raw, @as(u32, @intFromBool(raw & (1 << 23) != 0)), + }); + + // Every scratch register, because this is where the coprocessor firmware announces itself. All + // zeroes would say the C6 is answering as a card but not running ESP-Hosted's slave app. + var scratch: [8]u32 = undefined; + const scratch_addr = [_]u17{ 0x06C, 0x070, 0x074, 0x078, 0x07C, 0x080, 0x088, 0x08C }; + for (scratch_addr, 0..) |a2, i| { + var w: [4]u8 = undefined; + hal.sdmmc.cmd53Read(func, a2, &w, true) catch {}; + scratch[i] = std.mem.readInt(u32, &w, .little); + } + soc.rom.print("MARK SDIO_SCRATCH %08x %08x %08x %08x %08x %08x %08x %08x\r\n", .{ + scratch[0], scratch[1], scratch[2], scratch[3], + scratch[4], scratch[5], scratch[6], scratch[7], + }); + + // The poke the transport makes after card init: ESP_OPEN_DATA_PATH is enum value 0, so + // sdio_generate_slave_intr writes BIT(0 + ESP_SDIO_CONF_OFFSET) = 0x01 to + // HOST_TO_SLAVE_INTR = ESP_SLAVE_SCRATCH_REG_7, masked to offset 0x08C + // (sdio_drv.c:404-415, sdio_reg.h:49,77,99). + // + // This is the decisive test. If the slave answers a poke with a packet, our host's read loop is + // at fault. If it stays silent, the coprocessor is not responding to the protocol and no amount + // of host-side work will help. + soc.rom.print("MARK SDIO_POKE writing 0x01 to 0x08c (ESP_OPEN_DATA_PATH)\r\n", .{}); + hal.sdmmc.cmd52Write(func, 0x08C, 0x01) catch |err| { + soc.rom.print("MARK SDIO_POKE write failed=%s\r\n", .{@errorName(err).ptr}); + }; + + var beat: u32 = 0; + while (beat < 20) : (beat += 1) { + soc.rom.ets_delay_us(100_000); + var w1: [4]u8 = undefined; + var w2: [4]u8 = undefined; + hal.sdmmc.cmd53Read(func, 0x050, &w1, true) catch {}; + hal.sdmmc.cmd53Read(func, 0x060, &w2, true) catch {}; + const iraw = std.mem.readInt(u32, &w1, .little); + const plen = std.mem.readInt(u32, &w2, .little) & 0xFFFFF; + if (iraw & (1 << 23) != 0 or plen != 0) { + soc.rom.print("MARK SDIO_ANSWER beat=%u int_raw=0x%08x new_packet=1 pkt_len=%u\r\n", .{ + beat, iraw, plen, + }); + break; + } + if (beat % 5 == 0) { + soc.rom.print("MARK SDIO_WAIT beat=%u int_raw=0x%08x pkt_len=%u\r\n", .{ beat, iraw, plen }); + } + } + if (beat >= 20) soc.rom.print("MARK SDIO_SILENT no packet 2 s after the poke\r\n", .{}); + + // CMD53 WRITES, which nothing has yet verified. + // + // The reads above are proven identical to CMD52. Writes are the other half and they are the + // half the transport depends on: every RPC request leaves through a CMD53 write, and a request + // that arrives corrupted at the slave produces exactly what the board shows - the request goes + // out, the coprocessor makes nothing of it, and no response ever comes back. + // + // Writes are also where the cache hazard points the other way. On a read, DMA fills memory and + // the CPU must not see a stale cached line. On a write, the CPU fills a buffer - which lands in + // the L1 D-cache - and DMA reads from memory, so without a write-back the controller sends + // whatever was in memory before. Reads working tells us nothing about writes. + // + // Scratch register 1 (offset 0x070) is the target: writable from the host, and not the one that + // triggers slave interrupts (that is register 7 at 0x08C, poked above). + const scratch1: u17 = 0x070; + const patterns = [_][4]u8{ + .{ 0xde, 0xad, 0xbe, 0xef }, + .{ 0x00, 0x00, 0x00, 0x00 }, + .{ 0xff, 0xff, 0xff, 0xff }, + .{ 0x42, 0x00, 0x42, 0x00 }, + }; + var write_bad: u32 = 0; + for (patterns) |pat| { + var out = pat; // a mutable copy, so the driver may not rely on the source being static + hal.sdmmc.cmd53Write(func, scratch1, &out, true) catch |err| { + soc.rom.print("MARK SDIO_W53 pattern=%s write failed=%s\r\n", .{ + hex(&pat, 4, &hexbuf_a), @errorName(err).ptr, + }); + write_bad += 1; + continue; + }; + // Read back with CMD52, the path already proven, so a mismatch can only be the write. + var back: [4]u8 = undefined; + for (0..4) |i| { + back[i] = hal.sdmmc.cmd52Read(func, @intCast(scratch1 + i)) catch 0xAA; + } + const ok = std.mem.eql(u8, &pat, &back); + if (!ok) write_bad += 1; + soc.rom.print("MARK SDIO_W53 wrote=%s read=%s %s\r\n", .{ + hex(&pat, 4, &hexbuf_a), + hex(&back, 4, &hexbuf_b), + @as([*:0]const u8, if (ok) "SAME" else "DIFFER"), + }); + } + + // And the same patterns through CMD52 writes, as the control: if these also fail the register is + // not writable and the CMD53 result above means nothing. + var ctrl_bad: u32 = 0; + for (patterns) |pat| { + for (0..4) |i| { + hal.sdmmc.cmd52Write(func, @intCast(scratch1 + i), pat[i]) catch {}; + } + var back: [4]u8 = undefined; + for (0..4) |i| { + back[i] = hal.sdmmc.cmd52Read(func, @intCast(scratch1 + i)) catch 0xAA; + } + if (!std.mem.eql(u8, &pat, &back)) ctrl_bad += 1; + } + soc.rom.print("MARK SDIO_W_TOTAL cmd53_bad=%u cmd52_bad=%u of %u\r\n", .{ + write_bad, ctrl_bad, @as(u32, patterns.len), + }); + + soc.rom.print("MARK SDIO_DONE\r\n", .{}); + park(); +} + +/// Enable function 1 and wait for it to report ready, then set its block size. The CCCR offsets are +/// the standard SDIO ones; the sequence mirrors what src/net/port.zig's card init does, kept local so +/// this example does not depend on the radio stack being built. +fn enableFn1() !void { + const cccr_fn_enable = 0x02; + const cccr_fn_ready = 0x03; + const fn1: u8 = 1 << 1; + + const ioe = try hal.sdmmc.cmd52Read(0, cccr_fn_enable); + try hal.sdmmc.cmd52Write(0, cccr_fn_enable, ioe | fn1); + + var tries: u32 = 0; + while (tries < 1000) : (tries += 1) { + const ready = try hal.sdmmc.cmd52Read(0, cccr_fn_ready); + if (ready & fn1 != 0) { + soc.rom.print("MARK SDIO_FN1 ready after %u polls\r\n", .{tries}); + return; + } + soc.rom.ets_delay_us(1000); + } + return error.Timeout; +} + +var hexbuf_a: [80]u8 = undefined; +var hexbuf_b: [80]u8 = undefined; + +/// Bytes as lowercase hex into a caller-provided buffer, NUL-terminated for the ROM printer. +fn hex(bytes: []const u8, len: usize, out: *[80]u8) [*:0]const u8 { + const digits = "0123456789abcdef"; + var i: usize = 0; + while (i < len and i * 2 + 2 < out.len) : (i += 1) { + out[i * 2] = digits[bytes[i] >> 4]; + out[i * 2 + 1] = digits[bytes[i] & 0xF]; + } + out[i * 2] = 0; + return @ptrCast(out); +} + +fn park() noreturn { + while (true) {} +} + +export fn _start() linksection(".text.entry") callconv(.naked) noreturn { + asm volatile ( + \\ li t0, 1 << 13 + \\ csrs mstatus, t0 + \\ la sp, __stack_top + \\ mv fp, sp + \\ la t0, __bss_start + \\ la t1, __bss_end + \\ bgeu t0, t1, 2f + \\1: + \\ sw zero, 0(t0) + \\ addi t0, t0, 4 + \\ bltu t0, t1, 1b + \\2: + \\ j zig_main + ); +} |