Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
103 changes: 103 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -357,6 +357,109 @@ AP: rems RSSI -59
AP: rems RSSI -79
```

### soak

Long-running memory and scheduler soak test, driven by repeated scanning.
Exercises the radio for hours and reports whether the shared arena drifts, which
is how a leak in either the WiFi blob or the BT controller presents.

Needs no AP and no network, and scan is the allocation-heaviest single operation
the blob has, so this is the soak to run first:

```
$ tinygo flash -target xiao-esp32c3 -monitor ./examples/soak
soak: scan mode
soak 00:00:30 warmup 1/4 arena 30176/49144 B out 29
soak 00:01:00 warmup 2/4 arena 30384/49144 B out 31
soak 00:01:30 warmup 3/4 arena 30024/49144 B out 28
soak 00:02:00 warmup 4/4 arena 30024/49144 B out 28
soak 00:02:30 BASELINE arena 30024/49144 B out 28 passes/s 1197 hwisr/s 2
soak 00:03:00 arena 30024/49144 B out 28 drift +0 B / +0 per hr +0 B / +0 work 13/0
...
soak 00:05:30 arena 30384/49144 B out 31 drift +360 B / +3 per hr +7200 B / +60 work 23/0
peak arena 30384 B (+360) out 31 (+3)
soak 00:06:00 arena 30592/49144 B out 33 drift +568 B / +5 per hr +9737 B / +85 work 25/0
peak arena 30592 B (+568) out 33 (+5)
soak 00:06:30 arena 30024/49144 B out 28 drift +0 B / +0 per hr +0 B / +0 work 28/0
peak arena 30592 B (+568) out 33 (+5)
```

Interpreting it:

- The first four samples are discarded, then a baseline is latched. Bring-up
allocates once, and counting that as growth would report a leak on every run.
- `drift` is arena bytes and outstanding allocations (`AllocCount - FreeCount`)
relative to that baseline, and `per hr` is the same figures extrapolated.
- **Expect a sawtooth, not a flat line.** A scan in flight holds a few hundred
bytes, so a sample reads anywhere from +0 to +672 depending on where the 30s
tick lands. The pass condition is that the troughs return to the *same* floor —
above, exactly 30024 B and 28 outstanding every time across 19 minutes. A leak
raises the floor; a busy allocator only moves the teeth. Ignore `per hr` on an
elevated sample, since it is extrapolating a tooth.
- Watch both drift figures: the outstanding count catches a leak of many small
blocks that barely moves `ArenaUsed`, and `ArenaUsed` catches a leak that
reuses a block but grows it.
- The `peak` line is a sampled maximum, not a true high-water mark — the largest
value seen at a 30s boundary. It understates the real peak, and can creep for a
while purely because a later sample landed nearer the top of a tooth.
- A `QUIET COUNTERS MOVED` line appears only when a counter that should stay at
zero moves — cap hits, ring drops, queue-full, oversize frames, a leaked
critical section. Any of those is a finding on its own, whatever the arena did.
It never appeared in the run above.

Leave it running for at least an hour; overnight is better, since a slow leak in
a 48 KB arena can take a long time to become visible.

### soak-traffic

The same soak driven by real network traffic instead of scans: connects to an AP
and fetches a URL on a loop, so frames go through the TX and RX paths. Run
`./examples/soak` first — this one adds an AP and a server to whatever it is
you are trying to measure.

Point it at a LAN host rather than a public endpoint, which is what a multi-hour
run wants:

```
$ tinygo flash -target xiao-esp32c3 \
-ldflags="-X main.ssid=yourssid -X main.password=YourPasswordHere -X main.url=http://192.168.1.10/" \
-monitor ./examples/soak-traffic
soak: traffic mode, ssid yourssid url http://192.168.1.10/
soak 00:02:30 BASELINE arena 30808/49144 B out 34 passes/s 1211 hwisr/s 24
soak 00:03:00 arena 30808/49144 B out 34 drift +0 B / +0 per hr +0 B / +0 work 18/0
tx att 170 nomem 0 retry 0 busy 0 done 172 rx cb 795 drop 208 (26%) ingress-err 364
...
soak 00:19:30 arena 30808/49144 B out 34 drift +0 B / +0 per hr +0 B / +0 work 116/0
tx att 1127 nomem 0 retry 0 busy 0 done 1129 rx cb 4796 drop 1361 (28%) ingress-err 1959
```

Output is read the same way as `soak`, with two additions:

- An extra `tx` line, because this is the mode where the TX path does anything.
`retry` counts NO_MEM rejections the driver retried rather than dropped.
- The trailing `work` pair is completed fetches and failures. Check the failure
count before trusting flat drift — an idle radio leaks nothing, so a soak that
quietly stopped passing traffic looks identical to a clean one.

Fetch failures are counted rather than fatal, so one DNS hiccup does not end a
run.

Three things from the measured run above are worth knowing before you read your
own:

- **The arena does not move at all here**, not even the sawtooth `soak` shows.
The HTTP path allocates on the Go heap and in the blob's own TX buffers, not
the shared arena, so this mode tests the TX/RX counters more than it tests the
arena. Run both.
- **`drop` is not zero and is not expected to be.** Roughly a quarter of inbound
frames were dropped on a full RX ring, steadily, on an ordinary LAN. Every
fetch still succeeded — TCP retransmits what the ring loses — so read it as a
capacity signal rather than a fault. It is reported as a share here instead of
in the quiet-counter list precisely because it fires constantly.
- **`nomem 0, retry 0` means the retry path never ran.** A clean run at this
traffic level is not evidence that NO_MEM handling works, only that it was not
needed.

### starting

Starts the ESP32 radio.
Expand Down
12 changes: 9 additions & 3 deletions ble.go
Original file line number Diff line number Diff line change
Expand Up @@ -32,13 +32,13 @@ type VHCITransport struct{}

// Buffered returns the number of bytes available to read from the controller.
func (t VHCITransport) Buffered() int {
return int(C.espradio_vhci_buffered())
return vhciBuffered()
}

// ReadByte reads a single byte from the HCI controller.
func (t VHCITransport) ReadByte() (byte, error) {
for {
b := int(C.espradio_vhci_read_byte())
b := vhciReadByte()
if b >= 0 {
return byte(b), nil
}
Expand All @@ -52,7 +52,7 @@ func (t VHCITransport) Read(buf []byte) (int, error) {
return 0, nil
}
for {
n := int(C.espradio_vhci_read((*C.uint8_t)(unsafe.Pointer(&buf[0])), C.int(len(buf))))
n := vhciRead(buf)
if n > 0 {
return n, nil
}
Expand Down Expand Up @@ -129,10 +129,16 @@ func setupBTInterrupts() {
intr8.Enable()
}

// Both dispatchers run blob code in real interrupt context, so they mark it:
// anything they reach that would otherwise spin-and-yield must spin instead.
func btISR5Handler(interrupt.Interrupt) {
C.espradio_enter_hw_isr()
C.espradio_bt_isr_dispatch_5()
C.espradio_exit_hw_isr()
}

func btISR8Handler(interrupt.Interrupt) {
C.espradio_enter_hw_isr()
C.espradio_bt_isr_dispatch_8()
C.espradio_exit_hw_isr()
}
31 changes: 24 additions & 7 deletions bt_ble.c
Original file line number Diff line number Diff line change
Expand Up @@ -104,11 +104,19 @@ static void bt_wake_task_throttled(void) {
bt_isr_wake_task();
}

/* ISR context depth for the two BT dispatchers. Read by bt_is_in_isr() further
* down, which the blob calls to decide between its normal and from-ISR APIs.
* Nothing assigned this before, so that decision was made on the WiFi poll's flag
* and was false during every actual BT interrupt. */
static volatile int s_bt_in_isr;

/* Called from Go ISR handler for CPU interrupt assigned to RWBT+BT_BB */
void espradio_bt_isr_dispatch_5(void) {
s_bt_in_isr++;
if (s_bt_isr_fn_5) {
s_bt_isr_fn_5(s_bt_isr_arg_5);
}
s_bt_in_isr--;
bt_isr_wake_task();
/* Re-raise priority — TinyGo's trap handler restores to defaultThreshold (5)
* which equals CPU_INT_THRESH, preventing future interrupts. */
Expand All @@ -126,6 +134,7 @@ static volatile uint32_t s_isr_trace_head;

/* Called from Go ISR handler for CPU interrupt assigned to RWBLE */
void espradio_bt_isr_dispatch_8(void) {
s_bt_in_isr++;
uint32_t n = s_bt_isr8_count++;
if (n < BT_ISR_TRACE_N) {
/* Raw BLE core interrupt status, sampled before the blob ISR acks it. */
Expand All @@ -136,6 +145,7 @@ void espradio_bt_isr_dispatch_8(void) {
if (s_bt_isr_fn_8) {
s_bt_isr_fn_8(s_bt_isr_arg_8);
}
s_bt_in_isr--;
bt_isr_wake_task();
/* Re-raise priority — same reason as above */
BT_CPU_INT_PRI_REG_8 = 7u;
Expand Down Expand Up @@ -443,7 +453,8 @@ uint32_t espradio_bt_intc_pending(void) {
* VHCI Ring Buffer (controller → host)
* ═══════════════════════════════════════════════════════════════════════════ */

/* The ring itself lives in vhci_ring.c so the unit-test target can reach it. */
/* The ring itself is implemented in Go (vhci_ring.go), which is what lets the
* unit-test target reach it without the BTDM blob. */
extern int espradio_vhci_ring_push(const uint8_t *data, int len);

static volatile int s_vhci_send_available = 1;
Expand Down Expand Up @@ -475,7 +486,7 @@ static void vhci_host_send_available_cb(void) {
s_vhci_send_available = 1;
}

/* espradio_vhci_buffered / _read_byte / _read live in vhci_ring.c */
/* The consumer side (buffered / read_byte / read) is Go-only: see vhci_ring.go. */

/* ROM VHCI API */
extern bool API_vhci_host_check_send_available(void);
Expand Down Expand Up @@ -564,9 +575,8 @@ extern int32_t espradio_queue_send_from_isr(void *queue, void *item, void *hptw)
extern int32_t espradio_queue_recv(void *queue, void *item, uint32_t block_time_tick);
extern int32_t espradio_queue_recv_from_isr(void *queue, void *item, void *hptw);

/* ─── ISR context tracking ─── */
static volatile int s_bt_in_isr;

/* ─── ISR context tracking ───
* s_bt_in_isr is maintained by the two BT dispatchers near the top of this file. */
static int bt_is_in_isr(void) {
return s_bt_in_isr > 0 || espradio_is_from_isr();
}
Expand Down Expand Up @@ -692,12 +702,19 @@ static int bt_semphr_give_from_isr(void *semphr, void *hptw) {
}

/* ─── Memory ─── */
/* Route through the osi.c wrappers rather than straight to the arena, so BLE
* allocations are counted by espradio_alloc_stats(). The BT controller and the
* WiFi blob share one arena, so BLE bypassing the counters made the reported
* alloc/free totals describe only half the users of the pool. */
extern void *espradio_malloc(size_t size);
extern void espradio_free(void *p);

static void *bt_malloc(uint32_t size) {
return espradio_arena_alloc((size_t)size);
return espradio_malloc((size_t)size);
}

static void bt_free(void *ptr) {
espradio_arena_free(ptr);
espradio_free(ptr);
}

static int bt_read_efuse_mac(void *mac) {
Expand Down
35 changes: 34 additions & 1 deletion esp32/isr.c
Original file line number Diff line number Diff line change
Expand Up @@ -109,12 +109,45 @@ void espradio_wifi_isr_post_mask(void) {
espradio_ints_off(1u << ESPRADIO_WIFI_CPU_INT);
}

/* Rate limit on re-enabling the WiFi CPU interrupt -- see the long note in
* esp32s3/isr.c. Same closed loop here, measured at 27,183 interrupts and one
* scheduler pass each per second on an idle radio, and safe to limit for the same
* reason: this handler only masks and wakes the scheduler, and schedOnce() calls
* espradio_call_wifi_isr() itself on every pass, so the MAC is serviced whether or
* not the interrupt fired.
*
* Zero disables the limit, for A/B on hardware. */
static volatile uint32_t s_unmask_interval_us = 1000;
static uint64_t s_last_unmask_us;
static volatile uint32_t s_unmask_suppressed;

void espradio_set_unmask_interval_us(uint32_t us) { s_unmask_interval_us = us; }
uint32_t espradio_unmask_interval_us(void) { return s_unmask_interval_us; }
uint32_t espradio_unmask_suppressed(void) { return s_unmask_suppressed; }

void espradio_wifi_unmask(void) {
/* Restore any TinyGo-owned INTENABLE bits that blob code may have cleared
* (e.g. via ROM ets_isr_mask), then ensure the WiFi CPU interrupt is on. */
uint32_t interval = s_unmask_interval_us;
int allow_wifi = 1;
if (interval) {
uint64_t now = espradio_time_us_now();
if (now - s_last_unmask_us < (uint64_t)interval) {
allow_wifi = 0;
s_unmask_suppressed++;
} else {
s_last_unmask_us = now;
}
}

uint32_t val;
__asm__ volatile ("rsr %0, intenable" : "=r"(val));
val |= s_intenable_snapshot | (1u << ESPRADIO_WIFI_CPU_INT);
/* Exclude the WiFi bit from the snapshot restore: the snapshot predates
* schedOnce masking it, so OR-ing it back would defeat the rate limit. */
val |= s_intenable_snapshot & ~(1u << ESPRADIO_WIFI_CPU_INT);
if (allow_wifi) {
val |= (1u << ESPRADIO_WIFI_CPU_INT);
}
__asm__ volatile ("wsr %0, intenable; rsync" :: "r"(val));

/* Re-route GPIO source → TinyGo's CPU interrupt in case blob ROM code
Expand Down
12 changes: 12 additions & 0 deletions esp32c3/isr.c
Original file line number Diff line number Diff line change
Expand Up @@ -105,6 +105,18 @@ void espradio_snapshot_intenable(void) {
s_intenable_snapshot = ESPRADIO_INTC_ENABLE_REG;
}

/* No unmask rate limit needed here, but the accessors must exist because the
* shared Go side reports them for every target.
*
* The C3 does not have the interrupt storm the Xtensa targets do: its handler runs
* the blob ISR inline in interrupt context, which acks the MAC before returning, so
* the line is not still asserted when the pass unmasks it. Measured, this target
* takes single-digit hardware interrupts per second where the S3 takes 45,000.
* Rate-limiting the unmask here would only add latency for nothing. */
void espradio_set_unmask_interval_us(uint32_t us) { (void)us; }
uint32_t espradio_unmask_interval_us(void) { return 0; }
uint32_t espradio_unmask_suppressed(void) { return 0; }

/* No-op on RISC-V: PS.INTLEVEL does not exist. */
void espradio_lower_intlevel(void) {
}
Expand Down
49 changes: 48 additions & 1 deletion esp32s3/isr.c
Original file line number Diff line number Diff line change
Expand Up @@ -146,12 +146,59 @@ void espradio_wifi_isr_post_mask(void) {
espradio_ints_off(1u << ESPRADIO_WIFI_CPU_INT);
}

/* Rate limit on re-enabling the WiFi CPU interrupt.
*
* Several WiFi peripheral sources share this one level-triggered line and the blob
* registers exactly one ISR handler, so a source it does not own -- WIFI_BB --
* asserts and is never acked. Unmasking at the end of every pass therefore
* re-fires the interrupt immediately, and the result is a closed loop: measured on
* scan with no traffic, 45,190 interrupts and one scheduler pass each per second.
*
* Un-routing that source is not an option. Leaving it dangling, or pointing it at
* ESP-IDF's ETS_INVALID_INUM (6), both crash inside TinyGo's handleInterrupt --
* TinyGo dispatches CPU interrupts 6 through 30, so 6 is a live line here rather
* than the nowhere it is under IDF.
*
* What makes rate-limiting cheap is that this handler does not service anything: it
* masks the line and wakes the scheduler, and schedOnce() then calls
* espradio_call_wifi_isr() itself on every pass. So the hardware interrupt only
* ever brings a pass forward; the MAC is serviced whether or not it fired. Holding
* the line masked for a while costs at most a little latency, and the ticker
* guarantees a pass every 5 ms regardless.
*
* Zero disables the limit, restoring unmask-every-pass, for A/B on hardware. */
static volatile uint32_t s_unmask_interval_us = 1000;
static uint64_t s_last_unmask_us;
static volatile uint32_t s_unmask_suppressed;

void espradio_set_unmask_interval_us(uint32_t us) { s_unmask_interval_us = us; }
uint32_t espradio_unmask_interval_us(void) { return s_unmask_interval_us; }
uint32_t espradio_unmask_suppressed(void) { return s_unmask_suppressed; }

void espradio_wifi_unmask(void) {
/* Restore any TinyGo-owned INTENABLE bits that blob code may have cleared
* (e.g. via ROM ets_isr_mask), then ensure the WiFi CPU interrupt is on. */
uint32_t interval = s_unmask_interval_us;
int allow_wifi = 1;
if (interval) {
uint64_t now = espradio_time_us_now();
if (now - s_last_unmask_us < (uint64_t)interval) {
allow_wifi = 0;
s_unmask_suppressed++;
} else {
s_last_unmask_us = now;
}
}

uint32_t val;
__asm__ volatile ("rsr %0, intenable" : "=r"(val));
val |= s_intenable_snapshot | (1u << ESPRADIO_WIFI_CPU_INT);
/* The snapshot was taken before schedOnce masked the WiFi bit, so it still
* has that bit set -- it has to be excluded here or the rate limit would be
* undone by the very restore it sits next to. */
val |= s_intenable_snapshot & ~(1u << ESPRADIO_WIFI_CPU_INT);
if (allow_wifi) {
val |= (1u << ESPRADIO_WIFI_CPU_INT);
}
__asm__ volatile ("wsr %0, intenable; rsync" :: "r"(val));

/* Re-route GPIO source → TinyGo's CPU interrupt in case blob ROM code
Expand Down
Loading
Loading