ESP32-S3: NEWLIB_NANO_FORMAT=y with debug log level crashes wifi station example (LoadProhibited) (IDFGH-8954)

[ncmiller]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v5.1-dev-2283-gc92f2394f2

Operating System used.

Linux

How did you build your project?

Command line with idf.py

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-S3-DevKitC-1 v1.0

Power Supply used.

USB

What is the expected behavior?

With an ESP32-S3 target, if the following two items are set in sdkconfig:

CONFIG_NEWLIB_NANO_FORMAT=y
CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y

it is expected that the WiFi station example (examples/wifi/getting_started/station) should run normally, and connect to WiFi.

What is the actual behavior?

The WiFi station example crashes (see debug logs)

Steps to reproduce.

1. Set CONFIG_NEWLIB_NANO_FORMAT=y
2. Set CONFIG_LOG_DEFAULT_LEVEL_DEBUG=y
3. Build and flash examples/wifi/getting_started/station for the ESP32-S3
4. Observe crash at runtime during WiFi connection

Debug Logs.

I (1219) wifi station: wifi_init_sta finished.
D (1229) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3fcebef4
D (1239) esp_netif_lwip: check: local, if=0x3fcebef4 fn=0x4200f528

D (1239) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcebef4
D (1249) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (1259) event: running post WIFI_EVENT:2 with handler 0x42008a20 and context 0x3fcece90 on loop 0x3fceb1c8
D (1269) wifi:Start wifi connect
D (1269) wifi:connect status 0 -> 0
D (1269) wifi:connect chan=0
D (1269) wifi:first chan=1
D (1279) wifi:connect status 0 -> 1
D (1279) wifi:filter: set rx policy=3
D (1279) wifi:clear scan ap list
D (1289) wifi:start scan: type=0x50f, priority=2, cb=0x4202c014, arg=0, ss_state=0x1, time=1290556, index=0
D (1299) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
D (1299) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (1309) wifi:profile match: ss_state=0x7
D (1309) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (1309) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0>
D (1319) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
D (1329) wifi:profile match: ss_state=0x7
D (1329) wifi:scan end: arg=0, status=0, ss_state=0x7
D (1339) wifi:find first mathched ssid, scan done
D (1339) wifi:filter: set rx policy=4
D (1339) wifi:first chan=1
D (1349) wifi:handoff_cb: status=0
D (1349) wifi:ap found, mac=b0:e4:d5:1e:ae:61
D (1349) wifi:new_bss=0x3fc9bcc8, cur_bss=0, new_chan=<1,0>, cur_chan=1
D (1359) wifi:filter: set rx policy=5
I (1359) wifi:new:<1,0>, old:<1,0>, ap:<255,255>, sta:<1,0>, prof:1
D (1369) wifi:connect_op: status=0, auth=5, cipher=3 
D (1369) wifi:auth mode is not none
D (1379) wifi:connect_bss: auth=1, reconnect=0
I (1379) wifi:state: init -> auth (b0)
D (1389) wifi:start 1s AUTH timer
D (1389) wifi:clear scan ap list
D (1399) wifi:recv auth: seq=2, status=0
I (1399) wifi:state: auth -> assoc (0)
D (1399) wifi:restart connect 1s timer for assoc
D (1409) wifi:recv assoc: type=0x10
D (1409) wifi:filter: set rx policy=6
I (1409) wifi:state: assoc -> run (10)
D (1409) wifi:start 10s connect timer for 4 way handshake
D (1419) gdma: new group (0) at 0x3fca0404
D (1419) gdma: new pair (0,0) at 0x3fca0440
D (1429) gdma: new tx channel (0,0) at 0x3fca03d4
D (1429) gdma: new rx channel (0,0) at 0x3fca0460
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40056ea0  PS      : 0x00060a30  A0      : 0x82064f9e  A1      : 0x3fcede10  
A2      : 0x00000001  A3      : 0x00000000  A4      : 0x00000000  A5      : 0x3fcedeb3  
A6      : 0x42064274  A7      : 0x00000000  A8      : 0x3fcf0855  A9      : 0x3fcf0856  
A10     : 0x3fcee74c  A11     : 0x00000020  A12     : 0x3fcf05d4  A13     : 0x3fcedeb3  
A14     : 0x3fcede89  A15     : 0x0000cdcd  SAR     : 0x0000001f  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000001  LBEG    : 0x400570e8  LEND    : 0x400570f3  LCOUNT  : 0x00000000  


Backtrace: 0x40056e9d:0x3fcede10 |<-CORRUPTED




ELF file SHA256: 0e273b51d49b97ce

Rebooting...
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x3 (RTC_SW_SYS_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x4037570c
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3810,len:0x1678
load:0x403c9700,len:0xbe0
load:0x403cc700,len:0x2e10
entry 0x403c9900

More Information.

• Does not crash with CONFIG_NEWLIB_NANO_FORMAT=y and info log level
• Does not crash on ESP32

[ncmiller]

I see now this is probably the same issue as #9631