espressif / arduino-esp32

Arduino core for the ESP32
GNU Lesser General Public License v2.1
13.78k stars 7.44k forks source link

WiFiGeneric Crash on WIFI_REASON_UNSPECIFIED #7959

Closed mrengineer7777 closed 1 year ago

mrengineer7777 commented 1 year ago

Board

ESP32-WROOM-32UE

Device Description

Custom hardware

Hardware Configuration

NA

Version

v2.0.7

IDE Name

PIO

Operating System

Win11

Flash frequency

40

PSRAM enabled

yes

Upload speed

460800

Description

Unexpected crash in WiFiGeneric.cpp with debug level 3 (info). I expect the WiFi module to print debug messages without crashing.

Crashed on WiFiGeneric WIFI_REASON_UNSPECIFIED line 953: log_w("Reason: %u - %s", reason, reason2str(reason));.

#define reason2str(r) ((r>176)?system_event_reasons[r-176]:system_event_reasons[r-1])

const char * system_event_reasons[] = { "UNSPECIFIED", "AUTH_EXPIRE", "AUTH_LEAVE", "ASSOC_EXPIRE", "ASSOC_TOOMANY", "NOT_AUTHED", "NOT_ASSOCED", "ASSOC_LEAVE", "ASSOC_NOT_AUTHED", "DISASSOC_PWRCAP_BAD", "DISASSOC_SUPCHAN_BAD", "UNSPECIFIED", "IE_INVALID", "MIC_FAILURE", "4WAY_HANDSHAKE_TIMEOUT", "GROUP_KEY_UPDATE_TIMEOUT", "IE_IN_4WAY_DIFFERS", "GROUP_CIPHER_INVALID", "PAIRWISE_CIPHER_INVALID", "AKMP_INVALID", "UNSUPP_RSN_IE_VERSION", "INVALID_RSN_IE_CAP", "802_1X_AUTH_FAILED", "CIPHER_SUITE_REJECTED", "BEACON_TIMEOUT", "NO_AP_FOUND", "AUTH_FAIL", "ASSOC_FAIL", "HANDSHAKE_TIMEOUT", "CONNECTION_FAIL" };

Not sure why it crashed. I think system_event_reasons[] is being indexed correctly.

Likely related to #7414. If we continue getting crashes on define reason2str then I recommend converting it to a function.

This is how I print WiFi errors in my code:

const char* wifiErrToString(wifi_err_reason_t reason);

/**
 * @brief Convert a wifi_err_reason_t code to a string.
 * @param [in] reason The error code to be converted.
 * @return A string representation of the error code.
 * @note: wifi_err_reason_t values as of Mar 2023 are: (1-39, 46-51, 67-68, 200-208) and are defined in /tools/sdk/esp32/include/esp_wifi/include/esp_wifi_types.h.
 */
const char* wifiErrToString(wifi_err_reason_t reason) {
    switch(reason) {
        case WIFI_REASON_UNSPECIFIED: return "WIFI_REASON_UNSPECIFIED";
        case WIFI_REASON_AUTH_EXPIRE: return "WIFI_REASON_AUTH_EXPIRE";
        case WIFI_REASON_AUTH_LEAVE: return "WIFI_REASON_AUTH_LEAVE";
        case WIFI_REASON_ASSOC_EXPIRE: return "WIFI_REASON_ASSOC_EXPIRE";
        case WIFI_REASON_ASSOC_TOOMANY: return "WIFI_REASON_ASSOC_TOOMANY";
        case WIFI_REASON_NOT_AUTHED: return "WIFI_REASON_NOT_AUTHED";
        case WIFI_REASON_NOT_ASSOCED: return "WIFI_REASON_NOT_ASSOCED";
        case WIFI_REASON_ASSOC_LEAVE: return "WIFI_REASON_ASSOC_LEAVE";
        case WIFI_REASON_ASSOC_NOT_AUTHED: return "WIFI_REASON_ASSOC_NOT_AUTHED";
        case WIFI_REASON_DISASSOC_PWRCAP_BAD: return "WIFI_REASON_DISASSOC_PWRCAP_BAD";
        case WIFI_REASON_DISASSOC_SUPCHAN_BAD: return "WIFI_REASON_DISASSOC_SUPCHAN_BAD";
        case WIFI_REASON_BSS_TRANSITION_DISASSOC: return "WIFI_REASON_BSS_TRANSITION_DISASSOC";
        case WIFI_REASON_IE_INVALID: return "WIFI_REASON_IE_INVALID";
        case WIFI_REASON_MIC_FAILURE: return "WIFI_REASON_MIC_FAILURE";
        case WIFI_REASON_4WAY_HANDSHAKE_TIMEOUT: return "WIFI_REASON_4WAY_HANDSHAKE_TIMEOUT";
        case WIFI_REASON_GROUP_KEY_UPDATE_TIMEOUT: return "WIFI_REASON_GROUP_KEY_UPDATE_TIMEOUT";
        case WIFI_REASON_IE_IN_4WAY_DIFFERS: return "WIFI_REASON_IE_IN_4WAY_DIFFERS";
        case WIFI_REASON_GROUP_CIPHER_INVALID: return "WIFI_REASON_GROUP_CIPHER_INVALID";
        case WIFI_REASON_PAIRWISE_CIPHER_INVALID: return "WIFI_REASON_PAIRWISE_CIPHER_INVALID";
        case WIFI_REASON_AKMP_INVALID: return "WIFI_REASON_AKMP_INVALID";
        case WIFI_REASON_UNSUPP_RSN_IE_VERSION: return "WIFI_REASON_UNSUPP_RSN_IE_VERSION";
        case WIFI_REASON_INVALID_RSN_IE_CAP: return "WIFI_REASON_INVALID_RSN_IE_CAP";
        case WIFI_REASON_802_1X_AUTH_FAILED: return "WIFI_REASON_802_1X_AUTH_FAILED";
        case WIFI_REASON_CIPHER_SUITE_REJECTED: return "WIFI_REASON_CIPHER_SUITE_REJECTED";
        case WIFI_REASON_TDLS_PEER_UNREACHABLE: return "WIFI_REASON_TDLS_PEER_UNREACHABLE";
        case WIFI_REASON_TDLS_UNSPECIFIED: return "WIFI_REASON_TDLS_UNSPECIFIED";
        case WIFI_REASON_SSP_REQUESTED_DISASSOC: return "WIFI_REASON_SSP_REQUESTED_DISASSOC";
        case WIFI_REASON_NO_SSP_ROAMING_AGREEMENT: return "WIFI_REASON_NO_SSP_ROAMING_AGREEMENT";
        case WIFI_REASON_BAD_CIPHER_OR_AKM: return "WIFI_REASON_BAD_CIPHER_OR_AKM";
        case WIFI_REASON_NOT_AUTHORIZED_THIS_LOCATION: return "WIFI_REASON_NOT_AUTHORIZED_THIS_LOCATION";
        case WIFI_REASON_SERVICE_CHANGE_PERCLUDES_TS: return "WIFI_REASON_SERVICE_CHANGE_PERCLUDES_TS";
        case WIFI_REASON_UNSPECIFIED_QOS: return "WIFI_REASON_UNSPECIFIED_QOS";
        case WIFI_REASON_NOT_ENOUGH_BANDWIDTH: return "WIFI_REASON_NOT_ENOUGH_BANDWIDTH";
        case WIFI_REASON_MISSING_ACKS: return "WIFI_REASON_MISSING_ACKS";
        case WIFI_REASON_EXCEEDED_TXOP: return "WIFI_REASON_EXCEEDED_TXOP";
        case WIFI_REASON_STA_LEAVING: return "WIFI_REASON_STA_LEAVING";
        case WIFI_REASON_END_BA: return "WIFI_REASON_END_BA";
        case WIFI_REASON_UNKNOWN_BA: return "WIFI_REASON_UNKNOWN_BA";
        case WIFI_REASON_TIMEOUT: return "WIFI_REASON_TIMEOUT";
        case WIFI_REASON_PEER_INITIATED: return "WIFI_REASON_PEER_INITIATED";
        case WIFI_REASON_AP_INITIATED: return "WIFI_REASON_AP_INITIATED";
        case WIFI_REASON_INVALID_FT_ACTION_FRAME_COUNT: return "WIFI_REASON_INVALID_FT_ACTION_FRAME_COUNT";
        case WIFI_REASON_INVALID_PMKID: return "WIFI_REASON_INVALID_PMKID";
        case WIFI_REASON_INVALID_MDE: return "WIFI_REASON_INVALID_MDE";
        case WIFI_REASON_INVALID_FTE: return "WIFI_REASON_INVALID_FTE";
        case WIFI_REASON_TRANSMISSION_LINK_ESTABLISH_FAILED: return "WIFI_REASON_TRANSMISSION_LINK_ESTABLISH_FAILED";
        case WIFI_REASON_ALTERATIVE_CHANNEL_OCCUPIED: return "WIFI_REASON_ALTERATIVE_CHANNEL_OCCUPIED";
        case WIFI_REASON_BEACON_TIMEOUT: return "WIFI_REASON_BEACON_TIMEOUT";
        case WIFI_REASON_NO_AP_FOUND: return "WIFI_REASON_NO_AP_FOUND";
        case WIFI_REASON_AUTH_FAIL: return "WIFI_REASON_AUTH_FAIL";
        case WIFI_REASON_ASSOC_FAIL: return "WIFI_REASON_ASSOC_FAIL";
        case WIFI_REASON_HANDSHAKE_TIMEOUT: return "WIFI_REASON_HANDSHAKE_TIMEOUT";
        case WIFI_REASON_CONNECTION_FAIL: return "WIFI_REASON_CONNECTION_FAIL";
        case WIFI_REASON_AP_TSF_RESET: return "WIFI_REASON_AP_TSF_RESET";
        case WIFI_REASON_ROAMING: return "WIFI_REASON_ROAMING";
        case WIFI_REASON_ASSOC_COMEBACK_TIME_TOO_LONG: return "WIFI_REASON_ASSOC_COMEBACK_TIME_TOO_LONG";
        default: return nullptr;
    }
}

const char *errmsg = wifiErrToString((wifi_err_reason_t)WiFiCtrl.WiFiDisconnectedReason); //Usage in my code. WiFiCtrl adds on to WiFi.h.

Sketch

Unavailable

Debug Message

09:47:44.205 > Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.
09:47:44.337 >
09:47:44.337 > Core  1 register dump:
09:47:44.337 > PC      : 0x4008999c  PS      : 0x00060030  A0      : 0x8016f289  A1      : 0x3ffbb880
=> 0x4008999c: memchr at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/string/memchr.c:120
09:47:44.337 > A2      : 0x000000ff  A3      : 0x00000000  A4      : 0x000000fe  A5      : 0x00000002
09:47:44.337 > A6      : 0x401732a4  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x3ffbb850
=> 0x401732a4: __ssputs_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/nano-vfprintf.c:179
09:47:44.337 > A10     : 0x00000000  A11     : 0x3ffbb921  A12     : 0x00000000  A13     : 0x00000000
09:47:44.337 > A14     : 0x3ffbb8f9  A15     : 0x00000000  SAR     : 0x0000000a  EXCCAUSE: 0x0000001c
09:47:44.337 > EXCVADDR: 0x000000ff  LBEG    : 0x40084b7d  LEND    : 0x40084b85  LCOUNT  : 0x00000027
=> 0x40084b7d: esp_timer_impl_get_counter_reg at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_timer/src/esp_timer_impl_lac.c:118 (discriminator 2)
=> 0x40084b85: esp_timer_impl_get_counter_reg at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/esp_timer/src/esp_timer_impl_lac.c:128 (discriminator 1)
09:47:44.337 >
09:47:44.337 >
09:47:44.337 > Backtrace: 0x40089999:0x3ffbb880 0x4016f286:0x3ffbb8a0 0x401736ed:0x3ffbb8e0 0x40171356:0x3ffbb990 0x40171392:0x3ffbba20 0x400dd4a4:0x3ffbba60 0x400dd511:0x3ffbbaa0 0x40160015:0x3ffbbaf0 0x40160275:0x3ffbbc80
=> 0x40089999: memchr at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/string/memchr.c:118
=> 0x4016f286: _printf_i at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/nano-vfprintf_i.c:219
=> 0x401736ed: _svfprintf_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/nano-vfprintf.c:636
=> 0x40171356: _vsnprintf_r at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vsnprintf.c:70 (discriminator 4)
=> 0x40171392: vsnprintf at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/newlib/newlib/libc/stdio/vsnprintf.c:40
=> 0x400dd4a4: log_printfv at C:/Users/UserName/.platformio/packages/framework-arduinoespressif32/cores/esp32/esp32-hal-uart.c:543
=> 0x400dd511: log_printf at C:/Users/UserName/.platformio/packages/framework-arduinoespressif32/cores/esp32/esp32-hal-uart.c:576
=> 0x40160015: WiFiGenericClass::_eventCallback(arduino_event_t*) at C:/Users/UserName/.platformio/packages/framework-arduinoespressif32/libraries/WiFi/src/WiFiGeneric.cpp:953 (discriminator 4)
=> 0x40160275: _arduino_event_task(void*) at C:/Users/UserName/.platformio/packages/framework-arduinoespressif32/libraries/WiFi/src/WiFiGeneric.cpp:303

Other Steps to Reproduce

Have not reproduced the initial crash yet

I have checked existing issues, online documentation and the Troubleshooting Guide

VojtechBartoska commented 1 year ago

@PilnyTomas Can you please check this issue? Thanks

mrengineer7777 commented 1 year ago

I've been thinking about this. The macro reason2str could cause a crash if the index passed doesn't match the expected range. The debug messages should be rewritten as a function to avoid this. Would you like me to submit a PR?

nplan commented 1 year ago

I'm experiencing a similar issue in my project.

ESP32-S2 on arduino-esp32 v2.0.6.

A user has reported it. It occurs every time he tries to use the device. But I haven't been able to reproduce it myself.

The ESP32 is waking up from deep sleep and trying to connect to a WPA3 network.

[  1414][I][network.cpp:134] update(): [NET] connecting Wi-Fi (normal mode): SSID: ********
[  1417][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 202 - AUTH_FAIL
E (1870) wifi:sta is connecting, return error
[  2201][E][WiFiSTA.cpp:278] begin(): connect failed!
[  6199][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 2 - AUTH_EXPIRE
[  8055][I][network.cpp:154] update(): [NET] Wi-Fi connected (normal mode) in 5854 ms. Saving settings for quick mode...
[  8056][I][network.cpp:155] update(): [NET] IP: 192.168.132.167
[  8067][I][network.cpp:162] update(): [NET] SSID: ********, BSSID: xx:yy:zz:aa:bb:cc, CH: 6
[  8073][W][WiFiGeneric.cpp:955] _eventCallback(): Reason: 8 - ASSOC_LEAVE
E (7878) wifi:Set status to INIT
Guru Meditation Error: Core  0 panic'ed (LoadProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x40007e40  PS      : 0x00060d30  A0      : 0x8011ad4c  A1      : 0x3ffe7250  
A2      : 0x00000000  A3      : 0xfffffffc  A4      : 0x000000ff  A5      : 0x0000ff00  
A6      : 0x00ff0000  A7      : 0xff000000  A8      : 0x00000000  A9      : 0x00000000  
A10     : 0x00000000  A11     : 0x3ffe7452  A12     : 0x00000000  A13     : 0x00000000  
A14     : 0x50000000  A15     : 0x00000000  SAR     : 0x00000004  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x00000000  LBEG    : 0x00000000  LEND    : 0x00000000  LCOUNT  : 0x40027945  

Backtrace: 0x40007e3d:0x3ffe7250 0x4011ad49:0x3ffe7260 0x4011f942:0x3ffe7570 0x4011f97e:0x3ffe7600 0x4009f56d:0x3ffe7640 0x4009f62a:0x3ffe7680 0x400a8a2d:0x3ffe76d0 0x400a8e0d:0x3ffe77c0

Stack trace decoder (https://maximeborges.github.io/esp-stacktrace-decoder/) is reporting this:

0x4011ad49: _svfprintf_r at /Users/brnomac003/.gitlab-runner/builds/qR2TxTby/1/idf/crosstool-NG/.build/xtensa-esp32s2-elf/src/newlib/newlib/libc/stdio/vfprintf.c:1528
0x4011f942: _vsnprintf_r at /Users/brnomac003/.gitlab-runner/builds/qR2TxTby/1/idf/crosstool-NG/.build/xtensa-esp32s2-elf/src/newlib/newlib/libc/stdio/vsnprintf.c:70
0x4011f97e: vsnprintf at /Users/brnomac003/.gitlab-runner/builds/qR2TxTby/1/idf/crosstool-NG/.build/xtensa-esp32s2-elf/src/newlib/newlib/libc/stdio/vsnprintf.c:40
0x4009f56d: log_printfv at /Users/nejc/.platformio/packages/framework-arduinoespressif32/cores/esp32/esp32-hal-uart.c:543
0x4009f62a: log_printf at /Users/nejc/.platformio/packages/framework-arduinoespressif32/cores/esp32/esp32-hal-uart.c:576
0x400a8a2d: WiFiGenericClass::_eventCallback(arduino_event_t*) at /Users/nejc/.platformio/packages/framework-arduinoespressif32/libraries/WiFi/src/WiFiGeneric.cpp:955
0x400a8e0d: _arduino_event_task at /Users/nejc/.platformio/packages/framework-arduinoespressif32/libraries/WiFi/src/WiFiGeneric.cpp:305

Is there any progress on the issue?

mrengineer7777 commented 1 year ago

@nplan Thanks for confirming it's not just me. Ironically it's the debug log message that causes the crash.

I'll submit a PR later to convert the reason2str macro into a function. That should resolve a potential crash due to bad index.

mrengineer7777 commented 1 year ago

I have started working on this PR. Will submit next week.

mrengineer7777 commented 1 year ago

Just had another crash on WiFiGeneric line 953, log_w("Reason: %u - %s", reason, reason2str(reason)); Time to finish the PR.

mrengineer7777 commented 1 year ago

Completed by #8043