939 lines
34 KiB
Markdown
939 lines
34 KiB
Markdown
# ESP32 / ESP32-C3 WiFi Emulation — Investigation, Root Causes & Fixes
|
||
|
||
> **Scope**: This document covers the full debugging journey and all fixes applied to make
|
||
> WiFi association work in the lcgamboa QEMU ESP32/C3 emulation layer used by Velxio.
|
||
> Target audience: future maintainers who need to understand *why* the code is the way it is.
|
||
|
||
---
|
||
|
||
## Table of Contents
|
||
|
||
1. [Background — what is this emulation layer?](#1-background)
|
||
2. [The symptom — WiFi never connects](#2-the-symptom)
|
||
3. [Architecture overview — frame delivery pipeline](#3-architecture-overview)
|
||
4. [Bug #1 — `wifi_pkt_rx_ctrl_t.channel = 0`](#4-bug-1--channel-field-is-zero)
|
||
5. [Bug #2 — Wrong AP lookup in handle_frame](#5-bug-2--wrong-ap-lookup-in-handle_frame)
|
||
6. [Bug #3 — DMA ring resets to 0 (the main blocker)](#6-bug-3--dma-ring-resets-to-0)
|
||
7. [Fix #1 — Channel resolution strategy](#7-fix-1--channel-resolution-strategy)
|
||
8. [Fix #2 — BSSID-first AP lookup](#8-fix-2--bssid-first-ap-lookup)
|
||
9. [Fix #3 — DMA ring reset on item.next == 0](#9-fix-3--dma-ring-reset-on-itemnext--0)
|
||
10. [Applying the same fixes to ESP32-C3](#10-applying-fixes-to-esp32-c3)
|
||
11. [How we debugged — the fprintf strategy](#11-how-we-debugged)
|
||
12. [Key data structures](#12-key-data-structures)
|
||
13. [Complete WiFi association flow (after fixes)](#13-complete-wifi-association-flow)
|
||
14. [File map — what lives where](#14-file-map)
|
||
15. [Build & deploy pipeline (Velxio)](#15-build--deploy-pipeline)
|
||
16. [Regression test](#16-regression-test)
|
||
|
||
---
|
||
|
||
## 1. Background
|
||
|
||
The Velxio platform runs ESP32 firmware inside QEMU (based on the lcgamboa fork of QEMU with
|
||
ESP32 board support). The ESP32 board model is implemented in `hw/misc/` and includes a custom
|
||
WiFi hardware model (`esp32_wifi.c`, `esp32_wifi_ap.c`, `esp32_wlan_packet.c`, etc.).
|
||
|
||
The WiFi model simulates an 802.11 access point. When firmware calls `WiFi.begin(ssid, password)`,
|
||
the firmware's WiFi MAC sends probe requests via the outgoing DMA channel. The QEMU model
|
||
intercepts these, responds with probe responses, auth responses, and association responses
|
||
generated by the simulated AP, and delivers those responses back to the firmware via the incoming
|
||
DMA channel.
|
||
|
||
The firmware used is ESP-IDF compiled for `esp32` (Xtensa LX7) or `esp32c3` (RISC-V).
|
||
The Velxio compilation pipeline normalises all user SSIDs to `"Espressif"` on channel 5 so the
|
||
QEMU AP can always respond correctly regardless of what the user wrote in their sketch.
|
||
|
||
The shared library (`libqemu-xtensa.so` for ESP32, `libqemu-riscv32.so` for ESP32-C3) is built
|
||
by GitHub Actions and downloaded into the container at runtime.
|
||
|
||
---
|
||
|
||
## 2. The Symptom
|
||
|
||
When running an ESP32 HTTP Server sketch (or any sketch that calls `WiFi.begin()`), the serial
|
||
output showed the firmware stuck printing dots indefinitely:
|
||
|
||
```
|
||
Connecting to WiFi.............................(never stops)
|
||
```
|
||
|
||
For ESP32-C3, the association attempt went slightly further but also failed:
|
||
|
||
```
|
||
I (1115) wifi:state: init -> auth (b0)
|
||
I (1610) wifi:state: auth -> assoc (0)
|
||
...I (2610) wifi:state: assoc -> init (2700)
|
||
```
|
||
|
||
The state machine reached `assoc` but then timed out exactly 1 second later and fell back
|
||
to `init`, repeating indefinitely.
|
||
|
||
---
|
||
|
||
## 3. Architecture Overview
|
||
|
||
### Frame delivery pipeline (ESP32 → AP)
|
||
|
||
```
|
||
Firmware (ESP32 RAM)
|
||
│ writes descriptor address to A_WIFI_DMA_OUTLINK register
|
||
▼
|
||
esp32_wifi_write() in esp32_wifi.c
|
||
│ reads DMA descriptor → reads frame from firmware RAM
|
||
▼
|
||
Esp32_WLAN_handle_frame() in esp32_wifi_ap.c
|
||
│ dispatches by frame subtype: probe req, auth req, assoc req, data
|
||
▼
|
||
Esp32_WLAN_init_*_frame() in esp32_wlan_packet.c
|
||
│ builds the response frame (probe resp, auth resp, assoc resp)
|
||
▼
|
||
Esp32_sendFrame() in esp32_wifi.c
|
||
│ prepends wifi_pkt_rx_ctrl_t header (channel, rssi, etc.)
|
||
│ writes frame to firmware RAM via DMA descriptor
|
||
│ fires interrupt → firmware processes the frame
|
||
▼
|
||
Firmware receives frame, advances WiFi state machine
|
||
```
|
||
|
||
### Beacon timer (AP → ESP32)
|
||
|
||
```
|
||
QEMUTimer (50 ms interval)
|
||
│
|
||
▼
|
||
Esp32_WLAN_beacon_timer() in esp32_wifi_ap.c
|
||
│ builds beacon frame for each AP in rotation
|
||
▼
|
||
Esp32_sendFrame() ← same path as responses
|
||
```
|
||
|
||
### Key registers (ESP32 variant)
|
||
|
||
| Register | Offset | Purpose |
|
||
|---|---|---|
|
||
| `A_WIFI_DMA_INLINK` | `0x88` | Firmware writes head of RX DMA descriptor ring |
|
||
| `A_WIFI_DMA_OUTLINK` | `0x8C` | Firmware writes TX DMA descriptor pointer to transmit a frame |
|
||
| `A_WIFI_DMA_INT_CLR` | `0xCC` | Firmware clears interrupt bits |
|
||
| `A_WIFI_DMA_INT_STATUS` | `0xC8` | QEMU exposes pending interrupt bits |
|
||
| `A_WIFI_STATUS` | `0xC0` | Always returns 1 (hardware ready) |
|
||
|
||
---
|
||
|
||
## 4. Bug #1 — Channel Field Is Zero
|
||
|
||
### What went wrong
|
||
|
||
`Esp32_sendFrame()` fills a `wifi_pkt_rx_ctrl_t` header before each frame. This header is
|
||
prepended to the raw 802.11 frame and contains metadata the firmware uses to decide whether
|
||
to process or discard the frame:
|
||
|
||
```c
|
||
*pkt = (wifi_pkt_rx_ctrl_t){
|
||
.rssi = signal_strength + ...,
|
||
.rate = 11,
|
||
.channel = esp32_wifi_channel, // <-- BUG: may be 0
|
||
...
|
||
};
|
||
```
|
||
|
||
`esp32_wifi_channel` is a global that gets updated by `esp32_ana.c` when the firmware writes
|
||
certain PHY registers. The formula is:
|
||
|
||
```c
|
||
// in esp32_ana.c, register address 0xC4:
|
||
if ((v % 10) == 4)
|
||
esp32_wifi_channel = (v / 10) - 1;
|
||
```
|
||
|
||
On a VPS or under heavy load, the PHY register write sequence can lag or be out of order,
|
||
leaving `esp32_wifi_channel == 0` for many frames.
|
||
|
||
**ESP-IDF firmware behaviour**: if `wifi_pkt_rx_ctrl_t.channel == 0`, the firmware silently
|
||
discards the frame. This means *every single frame* (beacons, probe responses, auth responses,
|
||
association responses) was being discarded by the firmware, because they all had `channel = 0`.
|
||
|
||
### Why it's masked for beacons
|
||
|
||
Beacon frames carry a **DS Parameter Set Information Element** (tag `0x03`) that encodes the
|
||
channel number inside the frame body. The firmware can optionally parse this directly. So even
|
||
if `pkt.channel == 0`, the firmware may still process beacons — but it will not process probe
|
||
responses, auth responses, or association responses that have `channel == 0` in the header.
|
||
|
||
---
|
||
|
||
## 5. Bug #2 — Wrong AP Lookup in handle_frame
|
||
|
||
### What went wrong
|
||
|
||
`Esp32_WLAN_handle_frame()` (in `esp32_wifi_ap.c`) handles frames sent *from* the firmware to
|
||
the simulated AP. For probe requests, auth requests, and association requests, it needs to
|
||
find the `access_point_info*` for the AP being targeted so it can build the correct response.
|
||
|
||
The original code used `s->ap_macaddr` as the lookup key. `s->ap_macaddr` is updated every
|
||
50 ms by the beacon timer, which rotates through all 4 configured APs:
|
||
|
||
```
|
||
t=0 ap_macaddr = Velxio-GUEST (ch 6, MAC 42:13:37:55:aa:01)
|
||
t=50 ap_macaddr = PICSimLabWifi (ch 1, MAC 10:01:00:c4:0a:56)
|
||
t=100 ap_macaddr = Espressif (ch 5, MAC 10:01:00:c4:0a:51)
|
||
t=150 ap_macaddr = MasseyWifi (ch 10, MAC 10:01:00:c4:0a:52)
|
||
t=200 back to Velxio-GUEST...
|
||
```
|
||
|
||
The Velxio compilation pipeline normalises the sketch SSID to `"Espressif"` so the firmware
|
||
always targets `10:01:00:c4:0a:51`. However, if the firmware sends an auth request at `t=50`
|
||
(when `ap_macaddr` is pointing at PICSimLabWifi), the auth response would be built using
|
||
PICSimLabWifi's parameters. The firmware would reject this response because the source MAC
|
||
and BSSID in the response don't match what it expects (Espressif).
|
||
|
||
### Result
|
||
|
||
Auth and association responses were built with the wrong AP's credentials, causing the
|
||
firmware's state machine to reject them or ignore them.
|
||
|
||
---
|
||
|
||
## 6. Bug #3 — DMA Ring Resets to 0 (The Main Blocker)
|
||
|
||
This was the hardest bug to find and the root cause of the persistent connection failure.
|
||
|
||
### Background — ESP32 WiFi RX DMA
|
||
|
||
When the firmware initialises the WiFi stack, it calls internal WiFi driver code that sets up
|
||
a pool of **static RX management buffers** (`wifi:Init static rx buffer num: 4` in the log).
|
||
These 4 buffers are organised as a linked list of DMA descriptors in firmware RAM.
|
||
|
||
Each descriptor has this layout (from `include/hw/misc/esp32_wifi.h`):
|
||
|
||
```c
|
||
typedef struct dma_list_item {
|
||
unsigned size : 12; // buffer capacity
|
||
unsigned length : 12; // data length written by DMA
|
||
unsigned : 6; // reserved
|
||
unsigned eof : 1; // end-of-frame flag
|
||
unsigned owner : 1; // 1 = DMA owns it, 0 = CPU owns it
|
||
uint32_t address; // pointer to the actual buffer in RAM
|
||
uint32_t next; // pointer to the next descriptor (0 = end of list)
|
||
} QEMU_PACKED dma_list_item;
|
||
```
|
||
|
||
Total size: 12 bytes.
|
||
|
||
The firmware sets up 4 descriptors as a **circular ring**:
|
||
|
||
```
|
||
0x3ffb62d0 → next: 0x3ffb62dc
|
||
0x3ffb62dc → next: 0x3ffb62e8
|
||
0x3ffb62e8 → next: 0x3ffb62f4
|
||
0x3ffb62f4 → next: 0x3ffb62d0 ← points back to head
|
||
```
|
||
|
||
It then writes the **head address** (`0x3ffb62d0`) to `A_WIFI_DMA_INLINK`.
|
||
|
||
### QEMU's frame delivery logic (BEFORE fix)
|
||
|
||
```c
|
||
void Esp32_sendFrame(Esp32WifiState *s, mac80211_frame *frame, int length, int signal_strength)
|
||
{
|
||
if (s->dma_inlink_address == 0) return; // drop if no DMA set up
|
||
|
||
// ... build header, fill buffer ...
|
||
|
||
dma_list_item item;
|
||
address_space_read(&address_space_memory, s->dma_inlink_address,
|
||
MEMTXATTRS_UNSPECIFIED, &item, 12); // read descriptor
|
||
address_space_write(&address_space_memory, item.address,
|
||
MEMTXATTRS_UNSPECIFIED, header, length); // write frame data
|
||
item.length = length;
|
||
item.eof = 1;
|
||
address_space_write(&address_space_memory, s->dma_inlink_address,
|
||
MEMTXATTRS_UNSPECIFIED, &item, 4); // write back word 0 only
|
||
s->dma_inlink_address = item.next; // advance to next slot
|
||
set_interrupt(s, 0x1000024);
|
||
}
|
||
```
|
||
|
||
This looks correct: read the current descriptor, write data to its buffer, mark it done,
|
||
advance to `item.next`. On a clean circular ring it would go:
|
||
`d0 → dc → e8 → f4 → d0 → dc → ...` forever.
|
||
|
||
### The failure sequence
|
||
|
||
We added debug logging to trace what happened:
|
||
|
||
```
|
||
[wifi-dma-inlink] written=0x3ffb62d0 current_inlink=0x0
|
||
[wifi-tx-sent] sub=8 ch=1 → next_inlink=0x3ffb62dc (beacon #1)
|
||
[wifi-tx-sent] sub=8 ch=5 → next_inlink=0x3ffb62e8 (beacon #2)
|
||
[wifi-tx-sent] sub=8 ch=10 → next_inlink=0x3ffb62f4 (beacon #3)
|
||
[wifi-tx-sent] sub=8 ch=6 → next_inlink=0x3ffb62d0 (beacon #4, wrapped)
|
||
[wifi-tx-sent] sub=8 ch=1 → next_inlink=0x3ffb62dc (beacon #5)
|
||
[wifi-tx-sent] sub=8 ch=5 → next_inlink=0x3ffb62e8 (beacon #6)
|
||
[wifi-tx-sent] sub=8 ch=10 → next_inlink=0x3ffb62f4 (beacon #7)
|
||
[wifi-tx-sent] sub=8 ch=6 → next_inlink=0x3ffb62d0 (beacon #8, wrapped again)
|
||
[wifi-tx-sent] sub=8 ch=1 → next_inlink=0x0 ← ZERO! (beacon #9)
|
||
[wifi-fw→ap] subtype=4 ch=5 bssid=ff:ff:ff:ff:ff:ff (probe req, no response delivered)
|
||
[wifi-fw→ap] subtype=4 ch=5 bssid=ff:ff:ff:ff:ff:ff (probe req, no response delivered)
|
||
...
|
||
```
|
||
|
||
After **9 beacons** (two full passes through the 4-slot ring plus one more), the descriptor
|
||
at `0x3ffb62d0` had `item.next = 0`. From that point, `s->dma_inlink_address = 0` and every
|
||
subsequent frame (probe responses, auth responses, assoc responses) was silently dropped.
|
||
|
||
### Why does `item.next` become 0?
|
||
|
||
The firmware processes each received frame from the RX ring. As part of buffer recycling
|
||
(calling `esp_wifi_internal_free_rx_buffer()`), the ESP-IDF WiFi driver clears the `next`
|
||
pointer of the descriptor it just processed. This effectively **breaks the circular ring**
|
||
by removing one link.
|
||
|
||
Specifically:
|
||
- Descriptor `d0` is written to on use #1 and use #5 (both work, `d0.next = dc`)
|
||
- The firmware processes the frame from use #1. During recycling it clears `d0.next = 0`
|
||
- By use #9, QEMU reads `d0` and finds `next = 0`
|
||
- QEMU sets `s->dma_inlink_address = 0`
|
||
- All subsequent frames are dropped
|
||
|
||
### Why the firmware still scans
|
||
|
||
Even with the ring broken at slot d0, the firmware already received enough beacons in the
|
||
first 8 deliveries (including 2 Espressif beacons on ch=5) to start scanning. It sends probe
|
||
requests via the *outgoing* DMA path (write to `A_WIFI_DMA_OUTLINK`), which is separate from
|
||
the RX ring and not affected by this bug.
|
||
|
||
However, the **probe responses** that should come back are delivered via `Esp32_sendFrame()`
|
||
which needs `dma_inlink_address != 0`. Since that address is 0, all probe responses, auth
|
||
responses, and association responses are silently dropped. The firmware sees no responses and
|
||
keeps scanning indefinitely.
|
||
|
||
### For ESP32-C3
|
||
|
||
The same bug exists in `esp32c3_wifi.c`. The C3 boots much faster (WiFi init at ~1090ms vs
|
||
~10000ms for ESP32), so the DMA ring is set up at ~1090ms. The beacon timer fires every 50ms,
|
||
so within 400ms (8 × 50ms) the ring is broken. Auth starts at ~1115ms, succeeds (auth response
|
||
arrives within the 8-delivery window), but association starts at ~1610ms — after the ring has
|
||
been broken — so the association response is dropped. The firmware times out after 1 second
|
||
(`assoc → init (2700)`).
|
||
|
||
---
|
||
|
||
## 7. Fix #1 — Channel Resolution Strategy
|
||
|
||
**File**: `hw/misc/esp32_wifi.c` (and `esp32c3_wifi.c`)
|
||
|
||
Replace the direct assignment `channel = esp32_wifi_channel` with a priority-ordered lookup:
|
||
|
||
```c
|
||
int pkt_channel = esp32_wifi_channel; // fallback: PHY register value
|
||
|
||
if (frame->frame_control.type == IEEE80211_TYPE_MGT) {
|
||
if (frame->frame_control.sub_type == IEEE80211_TYPE_MGT_SUBTYPE_BEACON) {
|
||
// Beacons carry the real channel in DS Parameter Set IE (tag 0x03).
|
||
// Fixed beacon header = 12 bytes (timestamp 8 + interval 2 + capability 2).
|
||
int data_len = length - IEEE80211_HEADER_SIZE;
|
||
int pos = 12;
|
||
while (pos + 2 <= data_len) {
|
||
uint8_t tag = frame->data_and_fcs[pos];
|
||
uint8_t ie_len = frame->data_and_fcs[pos + 1];
|
||
if (tag == 0x03 && ie_len >= 1) {
|
||
pkt_channel = frame->data_and_fcs[pos + 2];
|
||
break;
|
||
}
|
||
pos += 2 + ie_len;
|
||
}
|
||
}
|
||
// For all MGT frames (including beacons): if channel still 0,
|
||
// look up the AP by its source MAC address.
|
||
if (pkt_channel == 0) {
|
||
for (int i = 0; i < nb_aps; i++) {
|
||
if (memcmp(access_points[i].mac_address, frame->source_address, 6) == 0) {
|
||
pkt_channel = access_points[i].channel;
|
||
break;
|
||
}
|
||
}
|
||
}
|
||
} else if (frame->frame_control.type == IEEE80211_TYPE_DATA) {
|
||
// Data frames: look up by BSSID (the AP's MAC).
|
||
if (pkt_channel == 0) {
|
||
for (int i = 0; i < nb_aps; i++) {
|
||
if (memcmp(access_points[i].mac_address, frame->bssid_address, 6) == 0) {
|
||
pkt_channel = access_points[i].channel;
|
||
break;
|
||
}
|
||
}
|
||
}
|
||
}
|
||
```
|
||
|
||
The `access_points[]` array and `nb_aps` counter are defined in `esp32_wifi_ap.c` and
|
||
declared `extern` at the top of `esp32_wifi.c`:
|
||
|
||
```c
|
||
#include "esp32_wlan.h"
|
||
extern access_point_info access_points[];
|
||
extern int nb_aps;
|
||
```
|
||
|
||
**Priority order**:
|
||
1. Beacon: parse DS Parameter Set IE directly from the frame body → exact channel
|
||
2. Any management frame with `channel == 0`: look up by `source_address` MAC → AP's configured channel
|
||
3. Data frame with `channel == 0`: look up by `bssid_address` MAC → AP's configured channel
|
||
4. Fallback: use `esp32_wifi_channel` (the PHY register value)
|
||
|
||
---
|
||
|
||
## 8. Fix #2 — BSSID-First AP Lookup
|
||
|
||
**File**: `hw/misc/esp32_wifi_ap.c`, function `Esp32_WLAN_handle_frame()`
|
||
|
||
Replace the `s->ap_macaddr` lookup (which races with the beacon timer) with a deterministic
|
||
lookup that checks the BSSID in the incoming frame first:
|
||
|
||
```c
|
||
access_point_info *ap_info = NULL;
|
||
|
||
// 1. Look up by BSSID (directed probe/auth/assoc — most reliable)
|
||
if (memcmp(frame->bssid_address, BROADCAST, 6) != 0) {
|
||
for (int i = 0; i < nb_aps; i++) {
|
||
if (memcmp(access_points[i].mac_address, frame->bssid_address, 6) == 0) {
|
||
ap_info = &access_points[i];
|
||
break;
|
||
}
|
||
}
|
||
}
|
||
|
||
// 2. Try destination_address (some frames use this instead)
|
||
if (!ap_info && memcmp(frame->destination_address, BROADCAST, 6) != 0) {
|
||
for (int i = 0; i < nb_aps; i++) {
|
||
if (memcmp(access_points[i].mac_address, frame->destination_address, 6) == 0) {
|
||
ap_info = &access_points[i];
|
||
break;
|
||
}
|
||
}
|
||
}
|
||
|
||
// 3. Fallback by current channel (broadcast probe on an AP's channel)
|
||
if (!ap_info) {
|
||
for (int i = 0; i < nb_aps; i++) {
|
||
if (access_points[i].channel == esp32_wifi_channel) {
|
||
ap_info = &access_points[i];
|
||
break;
|
||
}
|
||
}
|
||
}
|
||
|
||
// 4. Last resort: the last AP that sent a beacon
|
||
if (!ap_info) {
|
||
for (int i = 0; i < nb_aps; i++) {
|
||
if (memcmp(access_points[i].mac_address, s->ap_macaddr, 6) == 0) {
|
||
ap_info = &access_points[i];
|
||
break;
|
||
}
|
||
}
|
||
}
|
||
```
|
||
|
||
**Why this order matters**: After the firmware scans and finds `Espressif` on channel 5, it
|
||
sends auth and association frames with BSSID = `10:01:00:c4:0a:51`. The BSSID lookup (step 1)
|
||
always resolves to Espressif regardless of when the beacon timer last fired. The old code using
|
||
`s->ap_macaddr` would sometimes resolve to a different AP depending on the 50ms timer.
|
||
|
||
---
|
||
|
||
## 9. Fix #3 — DMA Ring Reset on item.next == 0
|
||
|
||
**File**: `hw/misc/esp32_wifi.c`, function `Esp32_sendFrame()`
|
||
|
||
This is the critical fix. Replace the unconditional advance with a reset-to-base fallback:
|
||
|
||
```c
|
||
// BEFORE (broken):
|
||
s->dma_inlink_address = item.next;
|
||
|
||
// AFTER (fixed):
|
||
if (item.next != 0) {
|
||
s->dma_inlink_address = item.next;
|
||
} else {
|
||
/* The firmware cleared the next pointer during buffer recycling,
|
||
* breaking the circular ring. Reset to the ring head (the last
|
||
* value the firmware wrote to A_WIFI_DMA_INLINK) so probe/auth/assoc
|
||
* responses are not permanently dropped. */
|
||
s->dma_inlink_address = s->mem[A_WIFI_DMA_INLINK / 4];
|
||
}
|
||
```
|
||
|
||
### Why `s->mem[A_WIFI_DMA_INLINK/4]`?
|
||
|
||
The write handler stores every register write into `s->mem[]`:
|
||
|
||
```c
|
||
static void esp32_wifi_write(void *opaque, hwaddr addr, uint64_t value, unsigned int size)
|
||
{
|
||
Esp32WifiState *s = ESP32_WIFI(opaque);
|
||
switch (addr) {
|
||
case A_WIFI_DMA_INLINK:
|
||
s->dma_inlink_address = value;
|
||
break;
|
||
...
|
||
}
|
||
s->mem[addr / 4] = value; // always stored
|
||
}
|
||
```
|
||
|
||
So `s->mem[A_WIFI_DMA_INLINK/4]` always holds the last address the firmware wrote as the
|
||
ring head. When the ring is broken (next = 0), we reset to this address, which restores the
|
||
circular behaviour that the firmware originally intended.
|
||
|
||
### Why this is safe
|
||
|
||
- The firmware created the ring to be circular. The `next = 0` is a side effect of buffer
|
||
recycling, not an intentional "stop here" signal.
|
||
- Resetting to the ring head means QEMU will write to slot `d0` again. The firmware has
|
||
already processed or is in the process of processing the data from `d0`. In the worst case,
|
||
QEMU overwrites `d0` with a new beacon before the firmware reads it — losing one beacon.
|
||
Beacons are sent every 50ms and are redundant, so this is acceptable.
|
||
- The critical frames (probe response, auth response, assoc response) are each sent exactly
|
||
once in response to a request. They need to be delivered to *some* valid descriptor slot.
|
||
After the ring reset, they land in `d0` and the firmware receives them.
|
||
|
||
### What happens after the fix (observed in logs)
|
||
|
||
```
|
||
[wifi-dma-inlink] written=0x3ffb5e20
|
||
[wifi-ring-reset] item.next=0, reset inlink→0x3ffb5e20 (many times, beacons)
|
||
[wifi-fw→ap] subtype=4 ch=5 bssid=ff:ff:ff:ff:ff:ff (probe request from firmware)
|
||
[wifi-tx→fw] subtype=5 ch=5 src=10:01:00:c4:0a:51 (probe response DELIVERED)
|
||
[wifi-fw→ap] subtype=11 ch=5 bssid=10:01:00:c4:0a:51 (auth request)
|
||
[wifi-tx→fw] subtype=11 ch=5 src=10:01:00:c4:0a:51 (auth response DELIVERED)
|
||
[wifi-fw→ap] subtype=0 ch=5 bssid=10:01:00:c4:0a:51 (assoc request, state=1)
|
||
[wifi-tx→fw] subtype=1 ch=5 src=10:01:00:c4:0a:51 (assoc response DELIVERED)
|
||
```
|
||
|
||
Then in serial output:
|
||
```
|
||
I (58701) wifi:connected with Espressif, aid = 1, channel 5, BW20, bssid = 10:01:00:c4:0a:51
|
||
I (70300) esp_netif_handlers: sta ip: 192.168.4.x
|
||
Connected!
|
||
IP Address: 192.168.4.x
|
||
```
|
||
|
||
---
|
||
|
||
## 10. Applying Fixes to ESP32-C3
|
||
|
||
**File**: `hw/misc/esp32c3_wifi.c`
|
||
|
||
The ESP32-C3 WiFi emulation is a separate file that mirrors `esp32_wifi.c` but uses different
|
||
register names (`A_C3_WIFI_DMA_INLINK` instead of `A_WIFI_DMA_INLINK`) and a different RX
|
||
control header type (`wifi_pkt_rx_ctrl_c3_t` instead of `wifi_pkt_rx_ctrl_t`).
|
||
|
||
Both Bug #1 (channel = 0) and Bug #3 (DMA ring reset) were present in the C3 file.
|
||
Bug #2 (wrong AP lookup) lives in `esp32_wifi_ap.c` which is shared between ESP32 and C3,
|
||
so it only needed to be fixed once.
|
||
|
||
### Headers added
|
||
|
||
```c
|
||
#include "esp32_wlan.h"
|
||
|
||
extern access_point_info access_points[];
|
||
extern int nb_aps;
|
||
```
|
||
|
||
### Channel fix (same logic, applied to C3)
|
||
|
||
```c
|
||
int pkt_channel = esp32_wifi_channel;
|
||
|
||
if (frame->frame_control.type == IEEE80211_TYPE_MGT) {
|
||
if (frame->frame_control.sub_type == IEEE80211_TYPE_MGT_SUBTYPE_BEACON) {
|
||
// Parse DS Parameter Set IE...
|
||
}
|
||
if (pkt_channel == 0) { /* lookup by source MAC */ }
|
||
} else if (frame->frame_control.type == IEEE80211_TYPE_DATA) {
|
||
if (pkt_channel == 0) { /* lookup by BSSID */ }
|
||
}
|
||
|
||
*pkt = (wifi_pkt_rx_ctrl_c3_t){
|
||
...
|
||
.channel = pkt_channel, // was: .channel = esp32_wifi_channel
|
||
...
|
||
};
|
||
```
|
||
|
||
### DMA ring reset fix (same logic, C3 register name)
|
||
|
||
```c
|
||
if (item.next != 0) {
|
||
s->dma_inlink_address = item.next;
|
||
} else {
|
||
s->dma_inlink_address = s->mem[A_C3_WIFI_DMA_INLINK / 4];
|
||
}
|
||
```
|
||
|
||
### C3-specific timing observation
|
||
|
||
Because the ESP32-C3 boots much faster than the ESP32 (RTOS starts at ~79ms vs ~10000ms),
|
||
the WiFi stack initialises much earlier. The DMA ring is set up at ~1090ms. With 50ms beacons,
|
||
the ring is broken after ~400ms (8 beacons). Authentication starts at ~1115ms and
|
||
*succeeds* (the auth response arrives within the 8-delivery window). Association starts at
|
||
~1610ms but the ring has already broken at ~1490ms, so the association response is dropped.
|
||
This causes the exact 1-second assoc timeout (`assoc → init (2700)`) visible in the original
|
||
log.
|
||
|
||
After the fix, the C3 connects in approximately 3 seconds (compared to ~58 seconds for the
|
||
ESP32, which spends more time scanning).
|
||
|
||
---
|
||
|
||
## 11. How We Debugged
|
||
|
||
### Phase 1 — Establish what frames the firmware was sending
|
||
|
||
Added `fprintf(stderr, ...)` logging to `Esp32_WLAN_handle_frame()` in `esp32_wifi_ap.c`:
|
||
|
||
```c
|
||
if (frame->frame_control.type == IEEE80211_TYPE_MGT &&
|
||
frame->frame_control.sub_type != IEEE80211_TYPE_MGT_SUBTYPE_BEACON) {
|
||
fprintf(stderr, "[wifi-fw→ap] type=%d subtype=%d ch=%d state=%d bssid=%02x:...\n",
|
||
frame->frame_control.type, frame->frame_control.sub_type,
|
||
esp32_wifi_channel, s->ap_state,
|
||
frame->bssid_address[0], ...);
|
||
}
|
||
```
|
||
|
||
**Finding**: The firmware was sending ~950 probe requests (broadcast BSSID, channels 1–11
|
||
rotating). This confirmed `esp32_wifi_channel` IS updated correctly on this VPS, and the
|
||
firmware's scan machinery is working. But zero probe responses were arriving back.
|
||
|
||
### Phase 2 — Confirm probe responses are generated but not delivered
|
||
|
||
Added logging to `Esp32_sendFrame()` for non-beacon management frames:
|
||
|
||
```c
|
||
if (frame->frame_control.sub_type != IEEE80211_TYPE_MGT_SUBTYPE_BEACON) {
|
||
fprintf(stderr, "[wifi-tx→fw] subtype=%d ch=%d src=...\n", ...);
|
||
}
|
||
```
|
||
|
||
**Finding**: The log was empty. `Esp32_sendFrame()` was never being called for probe
|
||
responses. The probe responses were generated but lost before reaching `Esp32_sendFrame`.
|
||
|
||
Then we checked the early return:
|
||
|
||
```c
|
||
if (s->dma_inlink_address == 0) return;
|
||
```
|
||
|
||
Added logging here:
|
||
|
||
```c
|
||
if (s->dma_inlink_address == 0) {
|
||
fprintf(stderr, "[wifi-tx-drop] dma_inlink=0, frame type=%d sub=%d\n", ...);
|
||
return;
|
||
}
|
||
```
|
||
|
||
**Finding**: Every single frame was being dropped here. `dma_inlink_address` was always 0.
|
||
|
||
### Phase 3 — Find when `A_WIFI_DMA_INLINK` is written
|
||
|
||
Added logging in the write handler:
|
||
|
||
```c
|
||
if (addr == A_WIFI_DMA_INLINK) {
|
||
fprintf(stderr, "[wifi-dma-inlink] written=0x%x current_inlink=0x%x\n",
|
||
(unsigned)value, (unsigned)s->dma_inlink_address);
|
||
}
|
||
```
|
||
|
||
**Finding**: The firmware wrote `A_WIFI_DMA_INLINK = 0x3ffb62d0` **exactly once**, after
|
||
about 20 beacon drop log lines. Before that write, all beacons were dropped. After the write,
|
||
frames should start flowing.
|
||
|
||
### Phase 4 — Understand what happens after the DMA is set up
|
||
|
||
Added `item.next` logging after delivery:
|
||
|
||
```c
|
||
fprintf(stderr, "[wifi-tx-sent] sub=%d ch=%d → next_inlink=0x%x\n",
|
||
frame->frame_control.sub_type, pkt_channel, (unsigned)item.next);
|
||
```
|
||
|
||
**Finding** (the smoking gun):
|
||
|
||
```
|
||
d0 → next=0x3ffb62dc (beacon 1)
|
||
dc → next=0x3ffb62e8 (beacon 2)
|
||
e8 → next=0x3ffb62f4 (beacon 3)
|
||
f4 → next=0x3ffb62d0 (beacon 4, circular ✓)
|
||
d0 → next=0x3ffb62dc (beacon 5)
|
||
dc → next=0x3ffb62e8 (beacon 6)
|
||
e8 → next=0x3ffb62f4 (beacon 7)
|
||
f4 → next=0x3ffb62d0 (beacon 8, circular ✓)
|
||
d0 → next=0x0 ← ZERO on beacon 9!
|
||
```
|
||
|
||
The descriptor at `d0` had its `next` field cleared by the firmware's buffer recycling code
|
||
between beacon #5 (where `d0.next = 0x3ffb62dc`) and beacon #9 (where `d0.next = 0`).
|
||
|
||
### Phase 5 — Implement and verify the fix
|
||
|
||
Replaced `s->dma_inlink_address = item.next` with the ring-reset fallback.
|
||
|
||
**Verified** via logs that after the fix:
|
||
1. `[wifi-ring-reset]` fires repeatedly (beacons keep going to `d0` as expected)
|
||
2. Probe request arrives → probe response delivered
|
||
3. Auth request arrives → auth response delivered
|
||
4. Assoc request arrives → assoc response delivered
|
||
5. Serial output shows `connected with Espressif, aid = 1, channel 5`
|
||
|
||
All debug `fprintf` calls were removed before the final commit.
|
||
|
||
---
|
||
|
||
## 12. Key Data Structures
|
||
|
||
### `dma_list_item` (12 bytes)
|
||
|
||
```c
|
||
typedef struct dma_list_item {
|
||
unsigned size : 12; // buffer capacity (set by firmware when queueing)
|
||
unsigned length : 12; // data length (set by QEMU when delivering)
|
||
unsigned : 6; // padding
|
||
unsigned eof : 1; // end-of-frame: set to 1 by QEMU per delivery
|
||
unsigned owner : 1; // 1 = DMA hardware owns it, 0 = CPU owns it
|
||
uint32_t address; // physical address of data buffer
|
||
uint32_t next; // physical address of next descriptor (0 = end)
|
||
} QEMU_PACKED dma_list_item;
|
||
```
|
||
|
||
QEMU only writes back the first 4 bytes (word 0) after a delivery:
|
||
```c
|
||
address_space_write(&address_space_memory, s->dma_inlink_address,
|
||
MEMTXATTRS_UNSPECIFIED, &item, 4); // 4 bytes only!
|
||
```
|
||
This updates `length` and `eof` without touching `address` or `next`.
|
||
|
||
### `wifi_pkt_rx_ctrl_t` (ESP32) / `wifi_pkt_rx_ctrl_c3_t` (ESP32-C3)
|
||
|
||
The firmware-facing RX frame header prepended by QEMU before writing to the DMA buffer.
|
||
Key fields:
|
||
|
||
```c
|
||
typedef struct {
|
||
signed rssi : 8; // received signal strength (dBm, negative)
|
||
unsigned rate : 4; // data rate
|
||
unsigned sig_len : 12; // length of the 802.11 frame
|
||
unsigned channel : 4; // channel number ← must be non-zero!
|
||
unsigned timestamp : 32; // QEMU virtual clock (microseconds)
|
||
unsigned noise_floor : 8;
|
||
// ... match flags (damatch0/1, bssidmatch0/1) ...
|
||
} wifi_pkt_rx_ctrl_t;
|
||
```
|
||
|
||
The `channel` field is 4 bits (values 1–13). **If it is 0, ESP-IDF firmware discards the
|
||
frame silently** without any log output. This is the most common cause of frames "disappearing"
|
||
in the emulation layer.
|
||
|
||
### `access_point_info` (from `esp32_wlan.h`)
|
||
|
||
```c
|
||
typedef struct {
|
||
char ssid[32];
|
||
uint8_t mac_address[6];
|
||
uint8_t channel;
|
||
uint8_t auth_mode;
|
||
// ...
|
||
} access_point_info;
|
||
```
|
||
|
||
Configured APs (as of writing):
|
||
|
||
| SSID | Channel | MAC | Notes |
|
||
|---|---|---|---|
|
||
| `Espressif` | 5 | `10:01:00:c4:0a:51` | Default target (Velxio normalises to this) |
|
||
| `PICSimLabWifi` | 1 | `10:01:00:c4:0a:56` | |
|
||
| `MasseyWifi` | 10 | `10:01:00:c4:0a:52` | |
|
||
| `Velxio-GUEST` | 6 | `42:13:37:55:aa:01` | |
|
||
|
||
---
|
||
|
||
## 13. Complete WiFi Association Flow (After Fixes)
|
||
|
||
```
|
||
t = 0ms
|
||
QEMU starts beacon timer (50ms interval)
|
||
dma_inlink_address = 0
|
||
|
||
t ≈ 10-11s (ESP32) / 90ms (ESP32-C3)
|
||
Firmware WiFi stack initialises
|
||
Firmware writes A_WIFI_DMA_INLINK = 0x3ffb62d0
|
||
→ dma_inlink_address = 0x3ffb62d0
|
||
|
||
t = 50ms intervals
|
||
Beacon timer fires, Esp32_sendFrame() called for each of 4 APs
|
||
Beacons delivered to ring slots d0 → dc → e8 → f4 → d0 (circular)
|
||
After ~8 deliveries, ring reset triggers: d0.next was cleared by firmware
|
||
→ dma_inlink_address resets to 0x3ffb62d0 (ring head)
|
||
Firmware receives beacons including Espressif on ch=5
|
||
|
||
t = (after sufficient beacons received)
|
||
Firmware decides to connect to "Espressif" (the normalised SSID)
|
||
Firmware sends PROBE REQUEST (type=0, subtype=4) with broadcast BSSID
|
||
|
||
QEMU: Esp32_WLAN_handle_frame() receives probe req
|
||
QEMU: builds PROBE RESPONSE for Espressif (SSID IE + channel IE + rates)
|
||
QEMU: Esp32_sendFrame() → channel = 5 (from DS IE or MAC lookup)
|
||
QEMU: delivers probe response to dma_inlink_address
|
||
QEMU: fires interrupt
|
||
|
||
Firmware: receives probe response with channel=5 for "Espressif"
|
||
Firmware: state: init → auth
|
||
|
||
Firmware sends AUTH REQUEST (subtype=11) with BSSID=10:01:00:c4:0a:51
|
||
QEMU: lookup AP by BSSID → Espressif
|
||
QEMU: builds AUTH RESPONSE (algorithm=Open, seq=2, status=0)
|
||
QEMU: delivers auth response
|
||
Firmware: state: auth → assoc
|
||
|
||
Firmware sends ASSOC REQUEST (subtype=0) with BSSID=10:01:00:c4:0a:51
|
||
QEMU: lookup AP by BSSID → Espressif
|
||
QEMU: builds ASSOC RESPONSE (status=0, AID=1, capability, rates)
|
||
QEMU: delivers assoc response
|
||
Firmware: state: assoc → run
|
||
|
||
Firmware: "connected with Espressif, aid = 1, channel 5"
|
||
Firmware: starts DHCP (sends DHCPDISCOVER to 192.168.4.1 via SLIRP)
|
||
SLIRP: responds with DHCPOFFER / DHCPACK
|
||
Firmware: gets IP address (e.g. 192.168.4.15)
|
||
|
||
Serial: "Connected!\nIP Address: 192.168.4.15"
|
||
```
|
||
|
||
Total time: ~58 seconds (ESP32, includes long PHY init), ~3 seconds (ESP32-C3).
|
||
|
||
---
|
||
|
||
## 14. File Map
|
||
|
||
```
|
||
hw/misc/
|
||
├── esp32_wifi.c Main WiFi emulation for ESP32 (Xtensa)
|
||
│ ├── esp32_wifi_read() Register read handler
|
||
│ ├── esp32_wifi_write() Register write handler (DMA TX, INLINK setup)
|
||
│ └── Esp32_sendFrame() Delivers a frame to firmware via RX DMA
|
||
│ ← Bug #1 fix (channel), Bug #3 fix (ring reset)
|
||
│
|
||
├── esp32c3_wifi.c WiFi emulation for ESP32-C3 (RISC-V) — mirrors esp32_wifi.c
|
||
│ └── Esp32_sendFrame() ← Bug #1 fix + Bug #3 fix (same, different reg names)
|
||
│
|
||
├── esp32_wifi_ap.c Access point simulation, shared by ESP32 and C3
|
||
│ ├── access_points[] Array of 4 configured APs
|
||
│ ├── Esp32_WLAN_handle_frame() Dispatches frames from firmware
|
||
│ │ ← Bug #2 fix (BSSID-first AP lookup)
|
||
│ └── beacon timer callback Sends beacons for each AP in rotation
|
||
│
|
||
├── esp32_wlan_packet.c Frame construction helpers
|
||
│ ├── Esp32_WLAN_init_probe_response_frame()
|
||
│ ├── Esp32_WLAN_init_auth_response_frame()
|
||
│ └── Esp32_WLAN_init_assoc_response_frame()
|
||
│
|
||
└── esp32_ana.c PHY/analog peripherals including channel update
|
||
└── Updates esp32_wifi_channel when PHY register 0xC4 is written
|
||
|
||
include/hw/misc/
|
||
├── esp32_wifi.h Esp32WifiState struct, dma_list_item, register offsets
|
||
└── esp32c3_wifi.h Same for C3 variant
|
||
|
||
hw/misc/esp32_wlan.h access_point_info struct declaration
|
||
```
|
||
|
||
---
|
||
|
||
## 15. Build & Deploy Pipeline (Velxio)
|
||
|
||
### Source repo
|
||
|
||
```
|
||
https://github.com/davidmonterocrespo24/qemu-lcgamboa
|
||
branch: picsimlab-esp32
|
||
```
|
||
|
||
### Build trigger
|
||
|
||
Every push to `picsimlab-esp32` triggers `.github/workflows/build-libqemu.yml`.
|
||
The workflow compiles both `libqemu-xtensa.so` (ESP32) and `libqemu-riscv32.so` (ESP32-C3)
|
||
and uploads them as assets to the `qemu-prebuilt` release in the velxio repo.
|
||
|
||
### Deploy to container
|
||
|
||
```bash
|
||
# Deploy ESP32 library
|
||
docker exec velxio-app bash -c "
|
||
curl -L -H 'Authorization: token TOKEN' \
|
||
'https://github.com/davidmonterocrespo24/velxio/releases/download/qemu-prebuilt/libqemu-xtensa.so' \
|
||
-o /app/lib/libqemu-xtensa.so.new && \
|
||
mv /app/lib/libqemu-xtensa.so.new /app/lib/libqemu-xtensa.so
|
||
"
|
||
|
||
# Deploy ESP32-C3 library
|
||
docker exec velxio-app bash -c "
|
||
curl -L -H 'Authorization: token TOKEN' \
|
||
'https://github.com/davidmonterocrespo24/velxio/releases/download/qemu-prebuilt/libqemu-riscv32.so' \
|
||
-o /app/lib/libqemu-riscv32.so.new && \
|
||
mv /app/lib/libqemu-riscv32.so.new /app/lib/libqemu-riscv32.so
|
||
"
|
||
|
||
# Restart uvicorn (not supervised — must be done manually)
|
||
docker exec -d velxio-app bash -c "
|
||
pkill -f uvicorn; sleep 2
|
||
cd /app && . /opt/esp-idf/export.sh > /dev/null 2>&1
|
||
uvicorn app.main:app --host 127.0.0.1 --port 8001 > /tmp/uvicorn.log 2>&1
|
||
"
|
||
```
|
||
|
||
### Important notes
|
||
|
||
- `uvicorn` is **not supervised**. If killed (e.g. by `pkill`), it must be manually restarted.
|
||
nginx (PID 1) stays up but all API requests return 502.
|
||
- Debug output from the `.so` (`fprintf(stderr, ...)`) appears in `/tmp/uvicorn.log` inside
|
||
the container, prefixed with the worker ID.
|
||
- Both `.so` files live in `/app/lib/` inside the container.
|
||
- The ESP32-C3 board name in the Velxio API is `esp32-c3` (with hyphen), **not** `esp32c3`.
|
||
The C3 board uses `libqemu-riscv32.so`; all other ESP32 variants use `libqemu-xtensa.so`.
|
||
|
||
---
|
||
|
||
## 16. Regression Test
|
||
|
||
A Python test script is available at `/tmp/test_wifi_debug.py` (ESP32) and
|
||
`/tmp/test_c3_wifi.py` (ESP32-C3) on the host machine. They compile a minimal HTTP Server
|
||
sketch via the Velxio API, start a simulation via WebSocket, and wait for the `Connected!`
|
||
string or an IP address in the serial output.
|
||
|
||
Expected results after fixes:
|
||
- **ESP32**: connects in ~55–60 seconds, prints `connected with Espressif, aid = 1, channel 5`
|
||
- **ESP32-C3**: connects in ~3 seconds, same message
|
||
|
||
To run:
|
||
```bash
|
||
python3 /tmp/test_wifi_debug.py # ESP32
|
||
python3 /tmp/test_c3_wifi.py # ESP32-C3
|
||
```
|
||
|
||
Both scripts cache the compiled binary in `/tmp/` to avoid recompiling on subsequent runs.
|
||
Delete `/tmp/esp32_wifi_binary.b64` or `/tmp/esp32c3_wifi_binary.b64` to force recompilation.
|
||
|
||
---
|
||
|
||
## Commit History (relevant)
|
||
|
||
| SHA | Message |
|
||
|---|---|
|
||
| `86ad10b` | fix: channel resolution and BSSID-first AP lookup |
|
||
| `3b22e64` | fix: reset DMA inlink to ring base when item.next=0 |
|
||
| `824b967` | chore: remove debug logging from WiFi emulation |
|
||
| `3237387` | fix: apply DMA ring reset and channel lookup fixes to ESP32-C3 WiFi |
|