esp-rs / esp-hal

no_std Hardware Abstraction Layers for ESP32 microcontrollers
https://docs.esp-rs.org/esp-hal/
Apache License 2.0
718 stars 194 forks source link

BLE and Wifi examples not working on ESP32S3. #1626

Open hydra opened 4 months ago

hydra commented 4 months ago

Hi,

I'm testing the examples on board here, and none of the wifi or bluetooth examples that I tried work.

I was initially using the cargo-generate code and after initialising the wifi the code just crashed, so when that didn't work I tried the examples here to rule out any of my code and got an identical issue.

Here's logs:

$ cargo esp32s3 --release --example access_point --features=wifi -- --before no-reset
    Finished release [optimized + debuginfo] target(s) in 0.66s
     Running `espflash flash --monitor D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\target\xtensa-esp32s3-none-elf\release\examples\access_point --before no-reset`
[2024-05-13T22:27:42Z WARN ] Pre-connection option 'NoReset' was selected. Connection may fail if the chip is not in bootloader or flasher stub mode.
[2024-05-13T22:27:42Z INFO ] Detected 4 serial ports
[2024-05-13T22:27:42Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-13T22:27:42Z INFO ] Please select a port
[2024-05-13T22:27:43Z INFO ] Serial port: 'COM15'
[2024-05-13T22:27:43Z INFO ] Connecting...
[2024-05-13T22:27:44Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.2)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       dc:54:75:d8:7e:e4
App/part. size:    466,912/1,048,576 bytes, 44.53%
[2024-05-13T22:27:46Z INFO ] Segment at address '0x0' has not changed, skipping write
[2024-05-13T22:27:46Z INFO ] Segment at address '0x8000' has not changed, skipping write
[2024-05-13T22:27:46Z INFO ] Segment at address '0x10000' has not changed, skipping write
[2024-05-13T22:27:46Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x29 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=1217ch ( 74108) map
I (123) esp_image: segment 1: paddr=000221a4 vaddr=3fc8e238 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=000231d4 vaddr=3fca7670 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=00023344 vaddr=40378000 size=06238h ( 25144) load
I (145) esp_image: segment 4: paddr=00029584 vaddr=00000000 size=06a94h ( 27284)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51f90h (335760) map
I (240) boot: Loaded app from partition at offset 0x10000
I (240) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeou

for this log, note that the output is truncated, the last log message is incomplete, no further output occurs.

I'm using a bench PSU and observe that after a few moments an AP does actually start, both my phone and PC are able to connect to it, and after configuring IP addresses as per the examples I'm unable to open the url in the examples nor ping the device.

Wireless LAN adapter Wi-Fi:

   Connection-specific DNS Suffix  . :
   Description . . . . . . . . . . . : Killer(R) Wi-Fi 6 AX1650x 160MHz Wireless Network Adapter (200NGW)
   Physical Address. . . . . . . . . : B0-A4-60-FB-53-06
   DHCP Enabled. . . . . . . . . . . : No
   Autoconfiguration Enabled . . . . : Yes
   Link-local IPv6 Address . . . . . : fe80::74b6:d5:739a:a598%14(Preferred)
   IPv4 Address. . . . . . . . . . . : 192.168.2.2(Preferred)
   Subnet Mask . . . . . . . . . . . : 255.255.255.0
   Default Gateway . . . . . . . . . : 192.168.2.1
   DHCPv6 IAID . . . . . . . . . . . : 212903008
   DHCPv6 Client DUID. . . . . . . . : 00-01-00-01-28-C6-BD-02-B0-A4-60-FB-53-06
   DNS Servers . . . . . . . . . . . : 8.8.8.8
   NetBIOS over Tcpip. . . . . . . . : Enabled

I tried another example, similar results:

$ cargo esp32s3 --release --example embassy_access_point --features "async,wifi,embassy-net" -- --before no-reset
  Downloaded embassy-futures v0.1.1
  Downloaded 1 crate (6.7 KB) in 0.18s
   Compiling embassy-futures v0.1.1
   Compiling esp-hal v0.17.0
   Compiling esp-wifi v0.5.1 (D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\esp-wifi)
    Finished release [optimized + debuginfo] target(s) in 7.41s
     Running `espflash flash --monitor D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\target\xtensa-esp32s3-none-elf\release\examples\embassy_access_point --before no-reset`
[2024-05-13T22:29:59Z WARN ] Pre-connection option 'NoReset' was selected. Connection may fail if the chip is not in bootloader or flasher stub mode.
[2024-05-13T22:29:59Z INFO ] Detected 4 serial ports
[2024-05-13T22:29:59Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-13T22:29:59Z INFO ] Please select a port
[2024-05-13T22:30:05Z INFO ] Serial port: 'COM15'
[2024-05-13T22:30:05Z INFO ] Connecting...
[2024-05-13T22:30:05Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.2)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       dc:54:75:d8:7e:e4
App/part. size:    470,576/1,048,576 bytes, 44.88%
[2024-05-13T22:30:07Z INFO ] Segment at address '0x0' has not changed, skipping write
[2024-05-13T22:30:07Z INFO ] Segment at address '0x8000' has not changed, skipping write
[00:00:28] [========================================]     290/290     0x10000
[2024-05-13T22:30:36Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x29 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=12794h ( 75668) map
I (123) esp_image: segment 1: paddr=000227bc vaddr=3fc8e248 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=000237ec vaddr=3fcaad40 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=0002395c vaddr=40378000 size=06248h ( 25160) load
I (145) esp_image: segment 4: paddr=00029bac vaddr=00000000 size=0646ch ( 25708)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=52de0h (339424) map
I (241) boot: Loaded app from partition at offset 0x10000
I (241) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_

again note the log is truncated.

i tried also the BLE example:

$ cargo esp32s3 --release --example ble --features "ble" -- --before no-reset
    Finished release [optimized + debuginfo] target(s) in 0.66s
     Running `espflash flash --monitor D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\target\xtensa-esp32s3-none-elf\release\examples\ble --before no-reset`
[2024-05-13T22:31:39Z WARN ] Pre-connection option 'NoReset' was selected. Connection may fail if the chip is not in bootloader or flasher stub mode.
[2024-05-13T22:31:39Z INFO ] Detected 4 serial ports
[2024-05-13T22:31:39Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-13T22:31:39Z INFO ] Please select a port
[2024-05-13T22:31:40Z INFO ] Serial port: 'COM15'
[2024-05-13T22:31:40Z INFO ] Connecting...
[2024-05-13T22:31:40Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.2)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       dc:54:75:d8:7e:e4
App/part. size:    465,616/1,048,576 bytes, 44.40%
[2024-05-13T22:31:43Z INFO ] Segment at address '0x0' has not changed, skipping write
[2024-05-13T22:31:43Z INFO ] Segment at address '0x8000' has not changed, skipping write
[00:00:28] [========================================]     290/290     0x10000
[2024-05-13T22:32:12Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x29 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=12440h ( 74816) map
I (123) esp_image: segment 1: paddr=00022468 vaddr=3fc8fe78 size=01068h (  4200) load
I (125) esp_image: segment 2: paddr=000234d8 vaddr=3fca9c60 size=001b4h (   436) load
I (129) esp_image: segment 3: paddr=00023694 vaddr=40378000 size=07e78h ( 32376) load
I (147) esp_image: segment 4: paddr=0002b514 vaddr=00000000 size=04b04h ( 19204)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51a84h (334468) map
I (240) boot: Loaded app from partition at offset 0x10000
I (241) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3

again note the log is truncated.

The board is a self-designed board, however I'm using the same regulators and wifi circuits as per other designs that have working wifi using another codebase.

my code:

    log::info!("B");
    let timer = esp_hal::timer::TimerGroup::new(peripherals.TIMG1, &clocks, None).timer0;
    let init = esp_wifi::initialize(
        esp_wifi::EspWifiInitFor::Wifi,
        timer,
        esp_hal::rng::Rng::new(peripherals.RNG),
        system.radio_clock_control,
        &clocks,
    )
    .unwrap();
    let wifi = peripherals.WIFI;

    log::info!("C");
    let (iface, device, mut controller, sockets) =
        create_network_interface(&init, wifi, WifiApDevice, socket_set_entries_static_ref).unwrap();

log from my code:

INFO - A
INFO - B
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }

and nothing else is output, and no AP appears (note that "INFO - C" is never printed.

Any suggestions?

hydra commented 4 months ago

I was able to run the 'access_point' example on a ESP32-WROOM-32 module OK, as follows:

$ cargo esp32 --release --example access_point --features=wifi
    Finished release [optimized + debuginfo] target(s) in 0.67s
     Running `espflash flash --monitor D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\target\xtensa-esp32-none-elf\release\examples\access_point`
[2024-05-13T22:57:01Z INFO ] Detected 5 serial ports
[2024-05-13T22:57:01Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-13T22:57:01Z INFO ] Please select a port
[2024-05-13T22:57:03Z INFO ] Serial port: 'COM3'
[2024-05-13T22:57:03Z INFO ] Connecting...
[2024-05-13T22:57:04Z INFO ] Using flash stub
Chip type:         esp32 (revision v1.0)
Crystal frequency: 40 MHz
Flash size:        4MB
Features:          WiFi, BT, Dual Core, 240MHz, Coding Scheme None
MAC address:       3c:71:bf:63:cf:d8
App/part. size:    497,616/4,128,768 bytes, 12.05%
[2024-05-13T22:57:05Z INFO ] Segment at address '0x1000' has not changed, skipping write
[2024-05-13T22:57:05Z INFO ] Segment at address '0x8000' has not changed, skipping write
[2024-05-13T22:57:05Z INFO ] Segment at address '0x10000' has not changed, skipping write
[2024-05-13T22:57:06Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ets Jun  8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:7104
0x3fff0030 - esp_wifi::HEAP_DATA
    at ??:??
load:0x40078000,len:15576
load:0x40080400,len:4
ho 8 tail 4 room 4
load:0x40080404,len:3876
entry 0x4008064c
0x4008064c - <&mut W as core::fmt::Write::write_fmt::SpecWriteFmt>::spec_write_fmt
    at D:\Users\Hydra\.rustup\toolchains\esp\lib\rustlib\src\rust\library\core\src\fmt\mod.rs:211
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 07:48:23
I (32) boot: Multicore bootloader
I (37) boot: chip revision: v1.0
I (40) boot.esp32: SPI Speed      : 40MHz
I (45) boot.esp32: SPI Mode       : DIO
I (50) boot.esp32: SPI Flash Size : 4MB
I (54) boot: Enabling RNG early entropy source...
I (60) boot: Partition Table:
I (63) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (78) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 003f0000
I (93) boot: End of partition table
I (97) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=12c90h ( 76944) map
I (133) esp_image: segment 1: paddr=00022cb8 vaddr=3ffb0000 size=00e10h (  3600) load
I (135) esp_image: segment 2: paddr=00023ad0 vaddr=3ffb9314 size=00190h (   400) load
I (139) esp_image: segment 3: paddr=00023c68 vaddr=40080000 size=0c3b0h ( 50096) load
I (168) esp_image: segment 4: paddr=00030020 vaddr=400d0020 size=58810h (362512) map
I (300) esp_image: segment 5: paddr=00088838 vaddr=4008c3b0 size=00f74h (  3956) load
I (308) boot: Loaded app from partition at offset 0x10000
I (308) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
Error:   × The device does not recognize the command. (os error 22)

error: process didn't exit successfully: `espflash flash --monitor D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\target\xtensa-esp32-none-elf\release\examples\access_point` (exit code: 1)

The tool errored out, but the AP was present and I could load the page and ping it.

I also tried an ESP32-S3-DEVKIT with an cmodule and that worked, as follows:

$ cargo esp32s3 --release --example access_point --features=wifi
    Finished release [optimized + debuginfo] target(s) in 0.67s
     Running `espflash flash --monitor D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\target\xtensa-esp32s3-none-elf\release\examples\access_point`
[2024-05-13T22:59:44Z INFO ] Detected 5 serial ports
[2024-05-13T22:59:44Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-13T22:59:44Z INFO ] Please select a port
[2024-05-13T22:59:46Z INFO ] Serial port: 'COM12'
[2024-05-13T22:59:46Z INFO ] Connecting...
[2024-05-13T22:59:46Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       7c:df:a1:e6:b1:2c
App/part. size:    466,912/1,048,576 bytes, 44.53%
[00:00:01] [========================================]      14/14      0x0
[00:00:00] [========================================]       1/1       0x8000
[00:00:28] [========================================]     286/286     0x10000
[2024-05-13T23:00:19Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0xb (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.1
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=1217ch ( 74108) map
I (123) esp_image: segment 1: paddr=000221a4 vaddr=3fc8e238 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=000231d4 vaddr=3fca7670 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=00023344 vaddr=40378000 size=06238h ( 25144) load
I (145) esp_image: segment 4: paddr=00029584 vaddr=00000000 size=06a94h ( 27284)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51f90h (335760) map
I (240) boot: Loaded app from partition at offset 0x10000
I (245) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
is wifi started: Ok(true)
Ok(EnumSet(AccessPoint))
INFO - Set hardware address: Ethernet(Address([126, 223, 161, 230, 177, 44]))
Start busy loop on main. Connect to the AP `esp-wifi` and point your browser to http://192.168.2.1:8080/
Use a static IP in the range 192.168.2.2 .. 192.168.2.255, use gateway 192.168.2.1
Connected
GET / HTTP/1.1
Host: 192.168.2.1:8080
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:125.0) Gecko/20100101 Firefox/125.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,*/*;q=0.8
Accept-Language: en-GB,en;q=0.7,es;q=0.3
Accept-Encoding: gzip, deflate
DNT: 1
Connection: keep-alive
Upgrade-Insecure-Requests: 1

Done

However, notice the later chip revision between my board and the ESP32-S3-WROOM-1 module (from the logs above) my board:

I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2

vs ESP32-S3-WROOM-1:

I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.1

For reference, the markings on the S3 on my board are as follows:

ESP32-S3-PICO-1
202023
N8RC2018154
MNP632000
FC00EAE007

And the MCUs were purchased from Digikey: https://www.digikey.com/en/products/detail/espressif-systems/ESP32-S3-PICO-1-N8R2/21264372

Can anyone else confirm that esp-wifi works for them on an ESP32-S3 with chip revision 0.2.

JurajSadel commented 4 months ago

Hi @hydra, I tested examples you've mentioned, and I can confirm they work fine for me (tested with esp32s3 revision 0.2).

hydra commented 4 months ago

Hi @JurajSadel can you give details on exactly what board you tested on, and if you have any logs that would be helpful in attempting to figure out why they don't work.

It feels like this might be closed a bit prematurely and should be kept open until we've identified the problem.

JurajSadel commented 4 months ago

@hydra Sure, I'm using the ESP32-S3-DevkitC-1 v1.1

Logs:

cargo esp32s3 --release --example access_point --features=wifi
    Finished release [optimized + debuginfo] target(s) in 0.10s
     Running `espflash flash --monitor /Users/jurajsadel/esp-rs/esp-wifi/target/xtensa-esp32s3-none-elf/release/examples/access_point`
[2024-05-14T14:32:04Z INFO ] Detected 2 serial ports
[2024-05-14T14:32:04Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-14T14:32:04Z INFO ] Please select a port
[2024-05-14T14:32:05Z INFO ] Serial port: '/dev/cu.usbserial-1140'
[2024-05-14T14:32:05Z INFO ] Connecting...
[2024-05-14T14:32:05Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.2)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       dc:da:0c:61:dd:b0
App/part. size:    466,912/1,048,576 bytes, 44.53%
[2024-05-14T14:32:07Z INFO ] Segment at address '0x0' has not changed, skipping write
[2024-05-14T14:32:07Z INFO ] Segment at address '0x8000' has not changed, skipping write
[2024-05-14T14:32:08Z INFO ] Segment at address '0x10000' has not changed, skipping write
[2024-05-14T14:32:08Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=12224h ( 74276) map
I (123) esp_image: segment 1: paddr=0002224c vaddr=3fc8e238 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=0002327c vaddr=3fca7670 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=000233ec vaddr=40378000 size=06238h ( 25144) load
I (145) esp_image: segment 4: paddr=0002962c vaddr=00000000 size=069ech ( 27116)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51f90h (335760) map
I (240) boot: Loaded app from partition at offset 0x10000
I (240) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
is wifi started: Ok(true)
Ok(EnumSet(AccessPoint))
INFO - Set hardware address: Ethernet(Address([222, 218, 12, 97, 221, 176]))
Start busy loop on main. Connect to the AP `esp-wifi` and point your browser to http://192.168.2.1:8080/
Use a static IP in the range 192.168.2.2 .. 192.168.2.255, use gateway 192.168.2.1
Connected
GET / HTTP/1.1
Host: 192.168.2.1:8080
Upgrade-Insecure-Requests: 1
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/17.4.1 Safari/605.1.15
Accept-Language: en-US,en;q=0.9
Accept-Encoding: gzip, deflate
Connection: keep-alive

Done

Sorry for closing the issue, I thought it could eb closed after verifying that examples are working correctly.

hydra commented 4 months ago

@JurajSadel thanks for the log, i'll diff it to mine and see if there's anything obviously wrong, I also have 2 other boards with S3's on and will test them and report back.

also for reference, the S3 devkit board I have with a chip-revision v0.1 was purchased from mouser, via this page: https://eu.mouser.com/ProductDetail/Espressif-Systems/ESP32-S3-DevKitC-1-N8R2

purchased JUL 17, 2023

it too was sold as 'ESP32-S3-DevKitC-1 v1.1' but it contains an module with the marking 'P2N8R2' on the ESP32-S3-WROOM-1 module's lid/can whereas the one in the picture here https://docs.espressif.com/projects/esp-idf/en/latest/esp32s3/hw-reference/esp32s3/user-guide-devkitc-1.html has 'E1N8' written on it.

I am curious to know if the one you have is using a Pico chip, or a non-Pico chip, and exactly what chip the module you're testing on with the 0.2 revision is.

Do you have a high-res photo of the board you were using please?

hydra commented 4 months ago

So another board I have here, different design, with a chip from the same batch of MCUs runs the example just fine...

$ cargo esp32s3 --release --example access_point --features=wifi -- --before no-reset
    Finished release [optimized + debuginfo] target(s) in 0.67s
     Running `espflash flash --monitor D:\Users\Hydra\Documents\dev\libraries\rust\esp-wifi\target\xtensa-esp32s3-none-elf\release\examples\access_point --before no-reset`
[2024-05-14T16:40:18Z WARN ] Pre-connection option 'NoReset' was selected. Connection may fail if the chip is not in bootloader or flasher stub mode.
[2024-05-14T16:40:18Z INFO ] Detected 4 serial ports
[2024-05-14T16:40:18Z INFO ] Ports which match a known common dev board are highlighted
[2024-05-14T16:40:18Z INFO ] Please select a port
[2024-05-14T16:40:23Z INFO ] Serial port: 'COM15'
[2024-05-14T16:40:23Z INFO ] Connecting...
[2024-05-14T16:40:24Z INFO ] Using flash stub
Chip type:         esp32s3 (revision v0.2)
Crystal frequency: 40 MHz
Flash size:        8MB
Features:          WiFi, BLE
MAC address:       dc:54:75:d8:7e:f8
App/part. size:    466,912/1,048,576 bytes, 44.53%
[00:00:01] [========================================]      14/14      0x0
[00:00:00] [========================================]       1/1       0x8000
[00:00:28] [========================================]     286/286     0x10000
[2024-05-14T16:40:56Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

�ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x0 (DOWNLOAD(USB/UART0))
waiting for download
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=1217ch ( 74108) map
I (123) esp_image: segment 1: paddr=000221a4 vaddr=3fc8e238 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=000231d4 vaddr=3fca7670 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=00023344 vaddr=40378000 size=06238h ( 25144) load
I (145) esp_image: segment 4: paddr=00029584 vaddr=00000000 size=06a94h ( 27284)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51f90h (335760) map
I (240) boot: Loaded app from partition at offset 0x10000
I (240) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
is wifi started: Ok(true)
Ok(EnumSet(AccessPoint))
INFO - Set hardware address: Ethernet(Address([222, 84, 117, 216, 126, 248]))
Start busy loop on main. Connect to the AP `esp-wifi` and point your browser to http://192.168.2.1:8080/
Use a static IP in the range 192.168.2.2 .. 192.168.2.255, use gateway 192.168.2.1

most odd indeed!

I'll continue to identify the differences and will also try a few more boards here in case there's something wrong with the first one I tried.

EDIT: I will re-check the other board from the panel that I thought was working, but since the error is intermittent I probably just got lucky.

bjoernQ commented 4 months ago

One thing which might be worth checking would be the power-supply. Curious about the outcome of this

hydra commented 4 months ago

The 2nd board from the same panel as the first one works just fine, indicating that the power supply circuit must be ok. I use the same components, regulators, caps, etc, on other ESP32S3 and D4 designs so I know they're good. I'll do more testing and see if I can identify the issue with the first board and report back with findings.

This is the panel, the one that I was having issues with is the one in the lower left.

IMG_20240515_145111

hydra commented 4 months ago

The issue seems to be intermittent.


    let timer = esp_hal::timer::TimerGroup::new(peripherals.TIMG1, &clocks, None).timer0;
    let init = esp_wifi::initialize(
        esp_wifi::EspWifiInitFor::Wifi,
        timer,
        esp_hal::rng::Rng::new(peripherals.RNG),
        system.radio_clock_control,
        &clocks,
    )
    .unwrap();
    let wifi = peripherals.WIFI;

    wait_for_button(&mut rwdt);

    let (iface, device, mut controller, sockets) =
        create_network_interface(&init, wifi, WifiApDevice, socket_set_entries_static_ref).unwrap();

    wait_for_button(&mut rwdt);

    let mut wifi_stack = WifiStack::new(iface, device, sockets, current_millis);

    wait_for_button(&mut rwdt);

    let client_config = Configuration::AccessPoint(AccessPointConfiguration {
        ssid: ssid.as_str().try_into().unwrap(),
        ..Default::default()
    });
    let res = controller.set_configuration(&client_config);
    log::info!("wifi_set_configuration returned {:?}", res);

    wait_for_button(&mut rwdt);

    controller.start().unwrap();
    // <-- control not returned here
    log::info!("is wifi started: {:?}", controller.is_started());

    wait_for_button(&mut rwdt);

    log::info!("{:?}", controller.get_capabilities());

    wait_for_button(&mut rwdt);

yields:

INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
INFO - Waiting for button press
INFO - !B!
INFO - Waiting for button press
INFO - !B!
INFO - Waiting for button press
INFO - !B!
INFO - wifi_set_configuration returned Ok(())
INFO - Waiting for button press
INFO - !B!

Corresponding scope trace: RigolDS160

here's a more zoomed in view: image

Yellow = 3v3, Cyan = 5V, Blue = IO0 (button)

hydra commented 4 months ago

When it works, it looks like this - scope zoomed in a bit to show detail.

log:

INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
INFO - Waiting for button press
INFO - !B!
INFO - Waiting for button press
INFO - !B!
INFO - Waiting for button press
INFO - !B!
INFO - wifi_set_configuration returned Ok(())
INFO - Waiting for button press
INFO - !B!
INFO - is wifi started: Ok(true)
INFO - Waiting for button press
INFO - !B!
INFO - Ok(EnumSet(AccessPoint))
INFO - Waiting for button press
INFO - !B!
INFO - Set hardware address: Ethernet(Address([222, 84, 117, 216, 126, 184]))

image

hydra commented 4 months ago

And here's a log showing that it's intermittent:

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x29 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=1217ch ( 74108) map
I (123) esp_image: segment 1: paddr=000221a4 vaddr=3fc8e238 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=000231d4 vaddr=3fca7670 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=00023344 vaddr=40378000 size=06238h ( 25144) load
I (145) esp_image: segment 4: paddr=00029584 vaddr=00000000 size=06a94h ( 27284)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51f90h (335760) map
I (240) boot: Loaded app from partition at offset 0x10000
I (240) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
is wifi started: Ok(true)
Ok(EnumSet(AccessPoint))
INFO - Set hardware address: Ethernet(Address([222, 84, 117, 216, 126, 184]))
Start busy loop on main. Connect to the AP `esp-wifi` and point your browser to http://192.168.2.1:8080/
Use a static IP in the range 192.168.2.2 .. 192.168.2.255, use gateway 192.168.2.1
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x29 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=1217ch ( 74108) map
I (123) esp_image: segment 1: paddr=000221a4 vaddr=3fc8e238 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=000231d4 vaddr=3fca7670 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=00023344 vaddr=40378000 size=06238h ( 25144) load
I (145) esp_image: segment 4: paddr=00029584 vaddr=00000000 size=06a94h ( 27284)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51f90h (335760) map
I (240) boot: Loaded app from partition at offset 0x10000
I (240) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
is wifi started: Ok(true)
Ok(EnumSet(AccessPoint))
INFO - Set hardware address: Ethernet(Address([222, 84, 117, 216, 126, 184]))
Start busy loop on main. Connect to the AP `esp-wifi` and point your browser to http://192.168.2.1:8080/
Use a static IP in the range 192.168.2.2 .. 192.168.2.255, use gateway 192.168.2.1
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x29 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (30) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (30) boot: compile time Jun  7 2023 08:07:32
I (31) boot: Multicore bootloader
I (35) boot: chip revision: v0.2
I (39) boot.esp32s3: Boot SPI Speed : 40MHz
I (44) boot.esp32s3: SPI Mode       : DIO
I (49) boot.esp32s3: SPI Flash Size : 4MB
I (53) boot: Enabling RNG early entropy source...
I (59) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (70) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (77) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (85) boot:  2 factory          factory app      00 00 00010000 00100000
I (92) boot: End of partition table
I (96) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=1217ch ( 74108) map
I (123) esp_image: segment 1: paddr=000221a4 vaddr=3fc8e238 size=01028h (  4136) load
I (125) esp_image: segment 2: paddr=000231d4 vaddr=3fca7670 size=00168h (   360) load
I (129) esp_image: segment 3: paddr=00023344 vaddr=40378000 size=06238h ( 25144) load
I (145) esp_image: segment 4: paddr=00029584 vaddr=00000000 size=06a94h ( 27284)
I (152) esp_image: segment 5: paddr=00030020 vaddr=42000020 size=51f90h (335760) map
I (240) boot: Loaded app from partition at offset 0x10000
I (240) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout:

image

On the scope you can see the wifi initialized on the first 2 attempts, and the logs show it too, but on the 3rd attempt it dies in controller.start().unwrap(); before the MCU has had the chance to clock-out the remaining UART buffer.

hydra commented 4 months ago

I also tried adding an extra 10uF capacitor to the 3v3 reg's output, made no different. I tried adding hacking i nesp_wifi_result!(esp_wifi_sys::include::esp_wifi_set_max_tx_power(8))?; (8 is the lowest power setting) into wifi_start() which makes a noticable difference on the 3v3 rail but it's still intermittent.

tomorrow I'll try hooking up a JTAG debugger to see if that sheds more light on things.

I could also try just populating another board without anything connected to the S3 other than the regs, caps and other required components, but that's a bit of a faff and involves a full day of manufacturing and mucking around with my PnP machine...

On other software that I've written, when encountering intermittent issues, I've found that they can often be caused by uninitialised memory, wondering if perhaps there's something worth investigating there. In C this is especially true when initialising structures without using {0} at the time the structure is initialised and then relying on the compiler and MCU init code to correctly zero the heap.

Based on the scope traces above, I don't think there's anything wrong with the power rails, I'm using a 3v3 switching regulator that's capable of delivering 1.5A, and my bench PSU's current limiter is set to 600mA and it's also configured to turn off the 5V supply if this limit is reached, and that doesn't happen.

If anyone has any other thoughts of things to try I'm all ears.

hydra commented 4 months ago

Well, getting to this point was a bit of a challenge:

image

I'll report back with findings now that I'm able to flash, and connect a debugger.

hydra commented 4 months ago

Seems like when it gets stuck, it gets stuck like this:

(gdb) info frame
Stack level 0, frame at 0x3fc91ec0:
 pc = 0x4201b7c4 in esp_hal::critical_section_impl::multicore::ReentrantMutex::lock (src/lib.rs:420); saved pc = 0x4200f543
 inlined into frame 1
 source language rust.
 Arglist at unknown address.
 Locals at unknown address, Previous frame's sp in a1
(gdb) info stack
#0  esp_hal::critical_section_impl::multicore::ReentrantMutex::lock (self=0x3fc8e3b0 <esp_hal::critical_section_impl::multicore::MULTICORE_LOCK>) at src/lib.rs:420
esp-rs/esp-wifi-sys#1  esp_hal::critical_section_impl::xtensa::{impl#0}::acquire () at src/lib.rs:296
esp-rs/esp-wifi-sys#2  0x4200f543 in critical_section::acquire () at D:\Users\Hydra\.cargo\registry\src\index.crates.io-6f17d22bba15001f\critical-section-1.1.2\src/lib.rs:183
esp-rs/esp-wifi-sys#3  critical_section::with<core::option::Option<[u8; 8]>, esp_wifi::compat::common::receive_queued::{closure_env#0}> () at D:\Users\Hydra\.cargo\registry\src\index.crates.io-6f17d22bba15001f\critical-section-1.1.2\src/lib.rs:226
esp-rs/esp-wifi-sys#4  esp_wifi::compat::common::receive_queued (queue=<optimized out>, item=<optimized out>, block_time_tick=4294967295) at esp-wifi\src\compat/common.rs:293
esp-rs/esp-wifi-sys#5  0x4200d7ff in esp_wifi::wifi::os_adapter::queue_recv (queue=0x3fc942e4 <_ZN8esp_wifi5timer13arch_specific15TIMER_OVERFLOWS17h7090171393f353e8E.llvm.8773300724186734139>, item=0x3fca45fc <log::MAX_LOG_LEVEL_FILTER>, block_time_tick=1107408804) at esp-wifi\src\wifi/os_adapter.rs:515
esp-rs/esp-wifi-sys#6  0x4037a648 in ppTask ()
esp-rs/esp-wifi-sys#7  0x42010734 in esp_wifi::compat::task_runner::run_c_task () at esp-wifi\src\compat/task_runner.rs:47
(gdb) info threads
  Id   Target Id         Frame 
* 1    Remote target     esp_hal::critical_section_impl::multicore::ReentrantMutex::lock (self=0x3fc8e3b0 <esp_hal::critical_section_impl::multicore::MULTICORE_LOCK>) at src/lib.rs:420
(gdb) info registers
pc             0x4201b7c4          0x4201b7c4 <esp_hal::critical_section_impl::xtensa::{impl#0}::acquire+32>
lbeg           0x40056f5c          1074098012
lend           0x40056f72          1074098034
lcount         0x0                 0
sar            0x3                 3
ps             0x60105             393477
threadptr      0x0                 0
br             0x0                 0
scompare1      0x100               256
acclo          0x0                 0
acchi          0x0                 0
m0             0x0                 0
m1             0x0                 0
m2             0x0                 0
m3             0x0                 0
fcr            0x0                 0
fsr            0x0                 0
pwrctl         0x0                 0
pwrstat        0x0                 0
eristat        0x0                 0
cs_itctrl      0x0                 0
cs_claimset    0x0                 0
cs_claimclr    0x0                 0
cs_lockaccess  0x0                 0
cs_lockstatus  0x0                 0
cs_authstatus  0x0                 0
fault_info     0x0                 0
trax_id        0x0                 0
trax_control   0x0                 0
trax_status    0x0                 0
trax_data      0x0                 0
trax_address   0x0                 0
trax_pctrigger 0x0                 0
trax_pcmatch   0x0                 0
trax_delay     0x0                 0
trax_memstart  0x0                 0
trax_memend    0x0                 0
pmg            0x0                 0
pmpc           0x0                 0
pm0            0x0                 0
pm1            0x0                 0
pmctrl0        0x0                 0
pmctrl1        0x0                 0
pmstat0        0x0                 0
pmstat1        0x0                 0
ocdid          0x0                 0
ocd_dcrclr     0x0                 0
ocd_dcrset     0x0                 0
ocd_dsr        0x0                 0
a0             0x8200f543          -2113866429
a1             0x3fc91ea0          1070145184
a2             0x60105             393477
a3             0xffffffff          -1
a4             0x3fc9001c          1070137372
a5             0x3c0678ac          1007057068
a6             0x3c0678ac          1007057068
a7             0x0                 0
a8             0x0                 0
a9             0x100               256
a10            0x3fc8e3b0          1070130096
a11            0x0                 0
a12            0x803793f5          -2143841291
a13            0x3fcda910          1070442768
a14            0x2                 2
a15            0x35                53

image

in esp_wifi::compat::common::receive_queued

EDIT: it doesn't always get stuck here.

I'll try and turn on some more logging.

hydra commented 4 months ago

here's what it looks like with `wifi-logs' enabled, when it fails:

INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
INFO - pp rom version: e7ae62f

INFO - net80211 rom version: e7ae62f

INFO - I (2231) wifi:
INFO - wifi driver task: 00, prio:253, stack:6656, core=0
INFO -

INFO - I (2239) wifi:
INFO - wifi firmware version: e309346
INFO -

INFO - I (2244) wifi:
INFO - wifi certification version: v7.0
INFO -

INFO - I (2250) wifi:
INFO - config NVS flash: disabled
INFO -

INFO - I (2256) wifi:
INFO - config nano formating: disabled
INFO -

INFO - I (2262) wifi:
INFO - Init data frame dynamic rx buffer num: 32
INFO -

INFO - I (2269) wifi:
INFO - Init static rx mgmt buffer num: 10
INFO -

INFO - I (2275) wifi:
INFO - Init management short buffer num: 32
INFO -

INFO - I (2282) wifi:
INFO - Init dynamic tx buffer num: 32
INFO -

INFO - I (2288) wifi:
INFO - Init static tx FG buffer num: 2
INFO -

INFO - I (2294) wifi:
INFO - Init static rx buffer size: 2212
INFO -

INFO - I (2300) wifi:
INFO - Init static rx buffer num: 10
INFO -

INFO - I (2306) wifi:
INFO - Init dynamic rx buffer num: 32
INFO -

INFO - V (2312) wifi:
INFO - hint=255, act_dur=<0,120>, pas_dur=360, nchans=14 history_num=0
INFO -

INFO - W (2322) wifi:
INFO - Affected by the ESP-NOW encrypt num, set the max connection num to 10
INFO -

INFO - W (2331) wifi:
INFO - Affected

and when it works:

INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
INFO - pp rom version: e7ae62f

INFO - net80211 rom version: e7ae62f

INFO - I (2232) wifi:
INFO - wifi driver task: 00, prio:253, stack:6656, core=0
INFO -

INFO - I (2241) wifi:
INFO - wifi firmware version: e309346
INFO -

INFO - I (2246) wifi:
INFO - wifi certification version: v7.0
INFO -

INFO - I (2252) wifi:
INFO - config NVS flash: disabled
INFO -

INFO - I (2257) wifi:
INFO - config nano formating: disabled
INFO -

INFO - I (2264) wifi:
INFO - Init data frame dynamic rx buffer num: 32
INFO -

INFO - I (2270) wifi:
INFO - Init static rx mgmt buffer num: 10
INFO -

INFO - I (2277) wifi:
INFO - Init management short buffer num: 32
INFO -

INFO - I (2283) wifi:
INFO - Init dynamic tx buffer num: 32
INFO -

INFO - I (2289) wifi:
INFO - Init static tx FG buffer num: 2
INFO -

INFO - I (2295) wifi:
INFO - Init static rx buffer size: 2212
INFO -

INFO - I (2301) wifi:
INFO - Init static rx buffer num: 10
INFO -

INFO - I (2307) wifi:
INFO - Init dynamic rx buffer num: 32
INFO -

INFO - V (2314) wifi:
INFO - hint=255, act_dur=<0,120>, pas_dur=360, nchans=14 history_num=0
INFO -

INFO - W (2323) wifi:
INFO - Affected by the ESP-NOW encrypt num, set the max connection num to 10
INFO -

INFO - W (2332) wifi:
INFO - Affected by the ESP-NOW encrypt num, set the max connection num to 10
INFO -

wifi_set_configuration returned Ok(())
INFO - V (2371) wifi:
INFO - ht40u freq=2422, chan=1
INFO -

INFO - D (2372) wifi:
INFO - filter: set rx policy=0
INFO -

INFO - I (2373) wifi:
INFO - mode : softAP (de:54:75:d8:7e:b8)
INFO -

INFO - D (2377) wifi:
INFO - filter: set rx policy=9
INFO -

INFO - V (2383) wifi:
INFO - ht40u freq=2422, chan=1
INFO -

INFO - I (2389) wifi:
INFO - Total power save buffer number: 16
INFO -

INFO - I (2394) wifi:
INFO - Init max length of beacon: 752/752
INFO -

INFO - I (2401) wifi:
INFO - Init max length of beacon: 752/752
INFO -

INFO - I (2408) wifi:
INFO - Set ps type: 0, coexist: 0

INFO -

INFO - I (2413) wifi:
INFO - set country: cc=CN schan=1 nchan=13 policy=1

INFO -

is wifi started: Ok(true)
Ok(EnumSet(AccessPoint))
INFO - Set hardware address: Ethernet(Address([222, 84, 117, 216, 126, 184]))
Start busy loop on main. Connect to the AP `esp-wifi` and point your browser to http://192.168.2.1:8080/
Use a static IP in the range 192.168.2.2 .. 192.168.2.255, use gateway 192.168.2.1

When it crashes, the debugger gives the following backtrace.

#0  0x4037d342 in ram_chip_i2c_writeReg ()
esp-rs/esp-wifi-sys#1  0x4003589a in ?? ()
esp-rs/esp-wifi-sys#2  0x40035939 in ?? ()
esp-rs/esp-wifi-sys#3  0x4203f004 in get_bias_ref_code ()
esp-rs/esp-wifi-sys#4  0x4203f022 in phy_get_vdd33 ()
esp-rs/esp-wifi-sys#5  0x4203d659 in txpwr_offset ()
esp-rs/esp-wifi-sys#6  0x4203b7d7 in bb_init ()
esp-rs/esp-wifi-sys#7  0x4203bc91 in register_chipv7_phy ()
esp-rs/esp-wifi-sys#8  0x42011a01 in esp_wifi::common_adapter::chip_specific::phy_enable::{closure#0} () at esp-wifi\src\common_adapter/common_adapter_esp32s3.rs:84
esp-rs/esp-wifi-sys#9  critical_section::with<(), esp_wifi::common_adapter::chip_specific::phy_enable::{closure_env#0}> () at D:\Users\Hydra\.cargo\registry\src\index.crates.io-6f17d22bba15001f\critical-section-1.1.2\src/lib.rs:229
esp-rs/esp-wifi-sys#10 esp_wifi::common_adapter::chip_specific::phy_enable () at esp-wifi\src\common_adapter/common_adapter_esp32s3.rs:66
esp-rs/esp-wifi-sys#11 0x4200dea2 in esp_wifi::wifi::os_adapter::phy_enable () at esp-wifi\src\wifi/os_adapter.rs:993
esp-rs/esp-wifi-sys#12 0x4202ae2d in wifi_hw_start ()
esp-rs/esp-wifi-sys#13 0x4202b53c in wifi_start_process ()
esp-rs/esp-wifi-sys#14 0x42029d79 in ieee80211_ioctl_process ()
esp-rs/esp-wifi-sys#15 0x4037a6c0 in ppTask ()
esp-rs/esp-wifi-sys#16 0x420108b4 in esp_wifi::compat::task_runner::run_c_task () at esp-wifi\src\compat/task_runner.rs:47
hydra commented 4 months ago

It seems that the crash is occuring in the code for register_chipv7_phy_init_param, see above stack trace.

For good measure, I erased the entire flash, after reading that the RF calibration data might be stored there, though with regards to the CONFIG_ESP_PHY_INIT_DATA_IN_PARTITION I'm not familiar with the interaction between the ROM functions and the rust ESP libs. https://docs.espressif.com/projects/esp-idf/en/v5.0/esp32/api-guides/RF_calibration.html#_CPPv429esp_phy_erase_cal_data_in_nvsv or if it was actually stored there. I figure it's probably good practice to fully erase the flash to be sure there wasn't some potentially incorrect RF calibration data being used.

Also, after reading that RF calibration can use a lot of power (https://github.com/espressif/esp-idf/issues/7324) I decided to bypass the 5V regulator entirely and supply the S3 MCU with 3.3V directly from the bench PSU. However, I still get the same intermittent result.

When the example runs, I get about 230mA draw on the 3v3 rail, when it fails the PSU has a reading which varies anywhere between 60mA and 200mA. Due to the variance in current draw, it seems fairly clear to me that the RF calibration is failing, but why I don't know...

hydra commented 4 months ago

@JurajSadel Please can you re-test your board and a) cold-boot it a few times, while monitoring the output of the CP2102 UART port. b) reboot it a few times, using the reset button, while monitoring the output of the CP2102 UART port.

please paste the logs too, it would help get a clearer picture.

I'm curious to know if your Rev v0.2 board is also intermittent.

Sorry for closing the issue, I thought it could eb closed after verifying that examples are working correctly.

please can you re-open this?

hydra commented 4 months ago

I tested the same exact code on a board with a different design I made which uses the exact same regulators, capcitors, inductors, power supply scheme and so on and everything works just fine, here's the log of me power-cycling it a bunch of times.

power-cycle-boot-log.txt

I also tried:

The power traces are wide, using minimum 2 vias per power trace, etc as per the ESP32 S3 hardware guidelines. Using a mostly star topology.

One other issue I have with the boards is that the I2C communication interface is fine at say 4Khz, but over 16Khz results in I2C timeouts and ack failures, I have no idea if this is related. It's possibly related as someone mentioned to me that the internal wifi might be using I2C and certainly when you step through the esp-wifi init code in the debugger you see it calling these methods:

ram_chip_i2c_readReg
ram_get_i2c_hostid
ram_chip_i2c_writeReg

See also the stacktraces posted previously.

I'll also try populating a fresh PCB with just the regs, and mcu as I mentioned previously to see if the issue is related to some other components (such as the 3 I2C components)

For good measure, I'll try some other non-esp-rust wifi example software and see how that works.

hydra commented 4 months ago

Here's a fresh install of the ArduinoIDE and the WifiAP example, it runs just fine.

image

Also, with the arduino I2C communication to the M10Q UBlox GPS at 400,000kbit works flawlessly without locking up, which again is probably related, as follows:

image

See: https://github.com/esp-rs/esp-hal/pull/1184#issuecomment-2106194991

@JurajSadel please re-open this issue as it looks like there's a software issue either in esp-wifi or with the esp-hal libs to me. I can send a board to any interested developer that wants to work on this issue.

JurajSadel commented 4 months ago

Hi @hydra, sorry for late reply. Sure, I can reopen, however, our time is limited and it looks like a weird issue. I can't say right now, when someone will have adequate amount of time to look into this.

hydra commented 4 months ago

Hi @hydra, sorry for late reply. Sure, I can reopen, however, our time is limited and it looks like a weird issue. I can't say right now, when someone will have adequate amount of time to look into this.

Hi, thanks for re-opening it, there was probably quite a lot of noise/notifcations while I was digging into it it.

If you have any ideas on where you think I or someone else could start investigating why this might not work please let me know. I was thinking of comparing the startup code between the arduino code where wifi works and the esp rust crates where it's not working and seeing if I can spot anything obvious/missing/different.

ProfFan commented 4 months ago

I think I hit the same issue, initializing esp-wifi immediately switched off the USB-SERIAL-JTAG and no way to even get the debug output. I have phy-enable-usb enabled so this part is definitely broken. HAL is 0.17.0 and with esp-wifi 0.5.1

It's brownout, ESP32S3 has huge transients at wifi init...

etiennetremel commented 4 months ago

I'm not sure how I ended up on this thread and I'm also not sure if it's related but I was also experiencing unexpected wifi behavior with my ESP32 WROOM 4Mb Devkit V1 Board (esp32 revision v3.1 chip).

esp-wifi was always working as expected after flashing with the debugger on. But didn't work with the same code after flashing, disconnecting from the laptop and connecting directly to the power supply (without debugger).

Looking at this thread and comment from @ProfFan about "huge transient", I added added a 1second delay before initializing esp-wifi and magically it resolved my issue:

Timer::after(Duration::from_millis(1000)).await;

let init = initialize(
    EspWifiInitFor::Wifi,
    timer,
    Rng::new(peripherals.RNG),
    system.radio_clock_control,
    &clocks,
).unwrap();
hydra commented 4 months ago

In my case, since I have the same issue when powering the MCU directly from bench PSU, which can easily handle any transients, and added extra capacitance, and the MCU never resets nor does it ever give the brownout reset code on boot, and have monitored the 3.3v rail on my scope, and have used the same batch of components on other designs, and that the arduino codebase allows the wifi to start, I'm 100% certain that this isn't a power supply issue.

And since I've also single-stepped the code and have had break-points before the call to initialise and also had a 20 second timer to allow a debugger to connect and halt the target on a cold boot that adding a 1 second delay will do nothing for me that hasn't already been tried.

DeppLearning commented 3 months ago

I am running into the same problem, I guess, at least same behavior. After hours of debugging I can now reliably reproduce both behaviors on my ESP32-S3-DevKitC1 revision 0.1. The example works (somewhat) when I connect the board via UART. When connected to USB I am getting the same problematic behavior as described by OP.

It works only somewhat because I am not getting an IP address with a recent commit on the main branch. However, that seems to be a regression. I have a little bit older code that is very similar and works but is using older dependencies.

esp-wifi = { git = "https://github.com/DeppLearning/esp-wifi", rev = "2117378dea297268e7347a9c6d0ed35f7eeedf12", default-features = false, features = [ "embassy-net", "esp32s3", "embassy-time-timg0", "utils", "wifi", "wifi-default", "vectored", "rt"] }
esp32s3-hal = { git = "https://github.com/esp-rs/esp-hal", rev = "c18b5b4e78ab68494c567829da2c6f96e98b9096", default-features = false, features = [ "async", "eh1", "embassy", "embassy-executor-thread", "embassy-time-timg0", "vectored"] }

edit: The example in this commit from 3 weeks ago works fine with UART: https://github.com/esp-rs/esp-hal/commit/fb90fe780cd858db68c180f14dd911afb8145633 . With current master I won't get an IP address.

My problem is that I am targeting the ESP32-S3-Box-3 and there I don't have the option to just switch to UART. I didn't try this yet with the ESP-S3-Box but on the DevKit I can flash with USB and the program will run through, it will only get stuck when I monitor it. Guess there goes my ability to debug monitor in this project :(

ESP32-S3-DevKitC-1 connected to USB

[2024-07-03T21:04:49Z INFO ] Serial port: '/dev/ttyACM0'
[2024-07-03T21:04:49Z INFO ] Connecting...
[2024-07-03T21:04:50Z INFO ] Using flash stub
    Finished release [optimized + debuginfo] target(s) in 0.19s
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40 MHz
Flash size:        32MB
Features:          WiFi, BLE
MAC address:       68:b6:b3:3d:6b:c0
App/part. size:    430,368/1,048,576 bytes, 41.04%
[00:00:00] [========================================]      14/14      0x0                                                                               
[00:00:00] [========================================]       1/1       0x8000                                                                            
[00:00:03] [========================================]     280/280     0x10000                                                                           [2024-07-03T21:04:55Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40378bda
0x40378bda - esp_backtrace::arch::backtrace_internal
    at /home/me/git/esp-hal/esp-backtrace/src/xtensa.rs:314
SPIWP:0xee
Octal Flash Mode Enabled
For OPI Flash, Use Default Flash Boot Mode
mode:SLOW_RD, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (43) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (43) boot: compile time Jun  7 2023 08:07:32
I (44) boot: Multicore bootloader
I (48) boot: chip revision: v0.1
I (52) boot.esp32s3: Boot SPI Speed : 40MHz
I (57) boot.esp32s3: SPI Mode       : SLOW READ
I (62) boot.esp32s3: SPI Flash Size : 4MB
I (67) boot: Enabling RNG early entropy source...
I (72) boot: Partition Table:
I (76) boot: ## Label            Usage          Type ST Offset   Length
I (83) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (91) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (98) boot:  2 factory          factory app      00 00 00010000 00100000
I (106) boot: End of partition table
I (110) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=0fed8h ( 65240) map
I (142) esp_image: segment 1: paddr=0001ff00 vaddr=3fc8e350 size=00118h (   280) load
I (143) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=51cf8h (335096) map
I (271) esp_image: segment 3: paddr=00071d20 vaddr=3fc8e468 size=00f0ch (  3852) load
I (273) esp_image: segment 4: paddr=00072c34 vaddr=3fca7788 size=00168h (   360) load
I (277) esp_image: segment 5: paddr=00072da4 vaddr=40378000 size=06350h ( 25424) load
I (298) boot: Loaded app from partition at offset 0x10000
I (298) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
(got stuck here)

ESP32-S3-BOX-3

[2024-07-03T21:07:04Z INFO ] Serial port: '/dev/ttyACM0'
[2024-07-03T21:07:04Z INFO ] Connecting...
[2024-07-03T21:07:04Z INFO ] Using flash stub
    Finished release [optimized + debuginfo] target(s) in 0.18s
Chip type:         esp32s3 (revision v0.2)
Crystal frequency: 40 MHz
Flash size:        16MB
Features:          WiFi, BLE
MAC address:       3c:84:27:05:06:b4
App/part. size:    430,368/1,048,576 bytes, 41.04%
[00:00:00] [========================================]      14/14      0x0                                                                               
[00:00:00] [========================================]       1/1       0x8000                                                                            
[00:00:02] [========================================]     280/280     0x10000                                                                           [2024-07-03T21:07:09Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x15 (USB_UART_CHIP_RESET),boot:0xa (SPI_FAST_FLASH_BOOT)
Saved PC:0x40378bd7
0x40378bd7 - esp_backtrace::arch::backtrace_internal
    at /home/me/git/esp-hal/esp-backtrace/src/xtensa.rs:314
SPIWP:0xee
mode:DIO, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (24) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (24) boot: compile time Jun  7 2023 08:07:32
I (25) boot: Multicore bootloader
I (29) boot: chip revision: v0.2
I (33) boot.esp32s3: Boot SPI Speed : 40MHz
I (38) boot.esp32s3: SPI Mode       : DIO
I (42) boot.esp32s3: SPI Flash Size : 4MB
I (47) boot: Enabling RNG early entropy source...
I (53) boot: Partition Table:
I (56) boot: ## Label            Usage          Type ST Offset   Length
I (63) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (71) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (78) boot:  2 factory          factory app      00 00 00010000 00100000
I (86) boot: End of partition table
I (90) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=0fed8h ( 65240) map
I (115) esp_image: segment 1: paddr=0001ff00 vaddr=3fc8e350 size=00118h (   280) load
I (115) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=51cf8h (335096) map
I (204) esp_image: segment 3: paddr=00071d20 vaddr=3fc8e468 size=00f0ch (  3852) load
I (205) esp_image: segment 4: paddr=00072c34 vaddr=3fca7788 size=00168h (   360) load
I (210) esp_image: segment 5: paddr=00072da4 vaddr=40378000 size=06350h ( 25424) load
I (228) boot: Loaded app from partition at offset 0x10000
I (228) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
(got stuck here)

ESP32-S3-DevKitC1 on UART

[2024-07-03T21:41:43Z INFO ] Serial port: '/dev/ttyUSB0'
[2024-07-03T21:41:43Z INFO ] Connecting...
[2024-07-03T21:41:44Z INFO ] Using flash stub
    Finished release [optimized + debuginfo] target(s) in 0.18s
Chip type:         esp32s3 (revision v0.1)
Crystal frequency: 40 MHz
Flash size:        32MB
Features:          WiFi, BLE
MAC address:       68:b6:b3:3d:6b:c0
App/part. size:    430,368/1,048,576 bytes, 41.04%
[00:00:01] [========================================]      14/14      0x0                                                                                                 
[00:00:00] [========================================]       1/1       0x8000                                                                                              
[00:00:28] [========================================]     280/280     0x10000                                                                                             [2024-07-03T21:42:17Z INFO ] Flashing has completed!
Commands:
    CTRL+R    Reset chip
    CTRL+C    Exit

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
Octal Flash Mode Enabled
For OPI Flash, Use Default Flash Boot Mode
mode:SLOW_RD, clock div:2
load:0x3fce3818,len:0x16f8
load:0x403c9700,len:0x4
load:0x403c9704,len:0xc00
load:0x403cc700,len:0x2eb0
entry 0x403c9908
I (43) boot: ESP-IDF v5.1-beta1-378-gea5e0ff298-dirt 2nd stage bootloader
I (43) boot: compile time Jun  7 2023 08:07:32
I (44) boot: Multicore bootloader
I (49) boot: chip revision: v0.1
I (52) boot.esp32s3: Boot SPI Speed : 40MHz
I (57) boot.esp32s3: SPI Mode       : SLOW READ
I (62) boot.esp32s3: SPI Flash Size : 4MB
I (67) boot: Enabling RNG early entropy source...
I (73) boot: Partition Table:
I (76) boot: ## Label            Usage          Type ST Offset   Length
I (83) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (91) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (98) boot:  2 factory          factory app      00 00 00010000 00100000
I (106) boot: End of partition table
I (110) esp_image: segment 0: paddr=00010020 vaddr=3c060020 size=0fed8h ( 65240) map
I (142) esp_image: segment 1: paddr=0001ff00 vaddr=3fc8e350 size=00118h (   280) load
I (143) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=51cf8h (335096) map
I (271) esp_image: segment 3: paddr=00071d20 vaddr=3fc8e468 size=00f0ch (  3852) load
I (273) esp_image: segment 4: paddr=00072c34 vaddr=3fca7788 size=00168h (   360) load
I (277) esp_image: segment 5: paddr=00072da4 vaddr=40378000 size=06350h ( 25424) load
I (298) boot: Loaded app from partition at offset 0x10000
I (298) boot: Disabling RNG early entropy source...
INFO - esp-wifi configuration Config { rx_queue_size: 5, tx_queue_size: 3, static_rx_buf_num: 10, dynamic_rx_buf_num: 32, static_tx_buf_num: 0, dynamic_tx_buf_num: 32, ampdu_rx_enable: 0, ampdu_tx_enable: 0, amsdu_tx_enable: 0, rx_ba_win: 6, max_burst_size: 1, country_code: "CN", country_code_operating_class: 0, mtu: 1492, heap_size: 65536, tick_rate_hz: 100, listen_interval: 3, beacon_timeout: 6, ap_beacon_timeout: 300, failure_retry_cnt: 1, scan_method: 0 }
wifi_set_configuration returned Ok(())
is wifi started: Ok(true)
Start Wifi Scan
... (continues to show correct AccessPointInfo output)
Ok(EnumSet(Client))
wifi_connect Ok(())
Wait to get connected
Ok(true)
Wait to get an ip address
(got stuck here)
bjoernQ commented 3 months ago

Regarding getting the IP: it sometimes takes "forever" for me but generally works. Definitely something to look into.

Regarding USB connection: You need to use the phy-enable-usb feature, see https://github.com/esp-rs/esp-hal/tree/main/esp-wifi#usb-serial-jtag

bjoernQ commented 2 months ago

Any news here?

ProfFan commented 2 months ago

I think this issue is now filled with a few different issues though: mine was a power transient issue but there could also be issues that is not hardware-related. One of the biggest thing is the scheduling: esp-wifi is using its own scheduler and its behavior is not very observable, especially mixed with embassy. The bigger issue is that since the USB-JTAG got disabled momentarily even with the feature flag, it is impossible to debug esp-wifi related issues on "production" hardware.

@hydra I wonder if you have your board with the full JTAG GPIOs available, and is willing to attach a physical JTAG? maybe also open a new issue?

@bjoernQ Could the esp-wifi scheduler be replaced by an embassy task instead (as an option)?

bjoernQ commented 2 months ago

@bjoernQ Could the esp-wifi scheduler be replaced by an embassy task instead (as an option)?

No, we need a preemptive scheduler for the drivers to work

ProfFan commented 2 months ago

@bjoernQ Or multiple embassy tasks with different priorities?

bjoernQ commented 2 months ago

@bjoernQ Or multiple embassy tasks with different priorities?

Can't really think of how to do that but everyone is certainly welcome to do some research/POC. But t.b.h. even if it works, I don't see how it would improve things (i.e. it would add more overhead instead of reducing overhead). But I would be happy to be proven wrong 😄