"AP mode failed" since commit 5197999 #40

jwyse · 2019-10-27T23:44:27Z

Fresh install on ESP32. No previous configuration. VSCode, PlatformIO, boards, etc. are all up-to-date. Build succeeds but I get the below error at runtime. I tried a few different commits and found that the issue started with commit 517999 from Oct 19.

latest commit, 7e9f1d8... (Oct 26)

[...] // serial monitor during bootup:
DIN MIDI started
Skipped connection to last AP and/or SmartConfig/WPS setup
SYSTEM_EVENT_WIFI_READY
### Starting AP [] with password [] // <- I added this DPRINT for debugging
[E][WiFiAP.cpp:103] softAP(): SSID missing!
AP mode failed
Internal Total Heap 323120, Internal Free Heap 242560
SYSTEM_EVENT_AP_START
Loading profile ...
Reading NVS Profile [E][Preferences.cpp:38] begin(): nvs_open failed: NOT_FOUND
Pedal autosensing...

Relevant code from WifiConnect.h, with an added DPRINT line:

    DPRINT("### Starting AP [%s] with password [%s]\n",
                ssidSoftAP.c_str(), passwordSoftAP.c_str());
    if (WiFi.softAP(ssidSoftAP.c_str(), passwordSoftAP.c_str())) {
        DPRINT("AP %s started with password %s\n", ssidSoftAP.c_str(), passwordSoftAP.c_str());
        // [...]
        start_services();
    }
    else
        DPRINT("AP mode failed\n");

This issue seems to have been introduced in commit 5197999 when the ssidSoftAP variable was introduced alongside, and sort of replacing, wifiSSID. At this point within WifiConnect.h, ssidSoftAP and passwordSoftAP are null or empty. It appears that there are no local variables by those names.

The previous commit, 3710def from Oct 12, does not have this issue, although it does seem to have an issue with mDNS that I have not tried to chase down.

SYSTEM_EVENT_WIFI_READY
AP Pedalino-3C40A24 started with password
SYSTEM_EVENT_AP_STOP
AP SSID : Pedalino-3C40A24
AP PSK :
AP MAC : 24:0A:C4:03:A6:D5
SYSTEM_EVENT_AP_START
SYSTEM_EVENT_AP_START
AP IP : 192.168.4.1
Channel : 1
Connect to Pedalino-3C40A24 wireless network with password
[I][ArduinoOTA.cpp:356] end(): OTA server stopped.
[E][ESPmDNS.cpp:72] begin(): Failed setting MDNS hostname
[I][ArduinoOTA.cpp:130] begin(): OTA server at: esp32-240ac403a6d4.local:3232

The text was updated successfully, but these errors were encountered:

alf45tar · 2019-10-28T08:13:29Z

Did you try a reset PedalinoMini to factory default?
The settings saved into EEPROM are changed in commit 5197999.

jwyse · 2019-10-28T16:19:32Z

Resetting to defaults did get past this issue, but revealed two more. I'm about to submit a pull request that should address the first one, and prevent the second one.

I think you should be able to reproduce my issue (and upcoming pull request) by factory-resetting with the latest code and boards/libraries in PlatformIO.

The default AP password is the chip ID, which is 7 hexadecimal characters. The ESP32 wifi library now requires at least 8 characters for the password, so PedalinoMini failed with the following error:

SYSTEM_EVENT_AP_START
[E][WiFiAP.cpp:109] softAP(): passphrase too short!
AP mode failed

WiFiAP now requires 8 characters for the passphrase.

    if(passphrase && (strlen(passphrase) > 0 && strlen(passphrase) < 8)) {
        // fail passphrase too short
        log_e("passphrase too short!");
        return false;
    }

Unhandled exception during first boot after resetting defaults, AND any time a button was pressed.
This unhandled exception crashed/rebooted the ESP32. Caused by an inconsistent state where the wifiEnabled variable is true, but the wifi connection failed (not configured as a client, and AP failed), and it tries to send an ipMIDI message with no connection.

Serial output from bootup, with no buttons pressed or held after triggering the factory default:

Hostname: 3C40A24
Internal Total Heap 324672, Internal Free Heap 298108
PSRAM Total Heap 0, PSRAM Free Heap 0
Reading NVS Global ... done
####################################################################################################################################################
Reset EEPROM to factory default
Updating NVS ...
done
[NVS][Global][Device Name]: 3C40A24
Updating NVS ...
done
[NVS][Global][Boot Mode]: 1
Updating NVS ... done
[NVS][Global][STA SSID]:     
[NVS][Global][STA Password]: 
Updating NVS ... done
[NVS][Global][AP SSID]:     Pedalino-3C40A24
[NVS][Global][AP Password]: 3C40A24
Updating NVS ... done
[NVS][Global][Bootstrap Theme]: bootstrap
Updating NVS ... done
[NVS][Global][Current Profile]: 0
Updating NVS ... done
[NVS][Global[Tap Dance Mode]: 0
Updating NVS ... done
[NVS][Global[Bank Switch]: 0
Updating NVS ... done
[NVS][Global[Single Time]: 200
[NVS][Global[Double Time]: 400
[NVS][Global[Long   Time]: 500
[NVS][Global[Repeat Time]: 500
Updating NVS ... done
[NVS][Global[Blynk Cloud]: 0
Updating NVS ... done
[NVS][Global][Blynk Token]: 
Updating NVS Profile A ... done
Updating NVS Profile B ... done
Updating NVS Profile C ... done
Reading NVS Global ... done
USB MIDI started
DIN MIDI started
SYSTEM_EVENT_WIFI_READY
SYSTEM_EVENT_AP_STOP
SmartConfig started
SYSTEM_EVENT_STA_START
SYSTEM_EVENT_STA_START
SmartConfig timeout
WPS started
WPS timeout
SYSTEM_EVENT_AP_START
[E][WiFiAP.cpp:109] softAP(): passphrase too short!
AP mode failed
Internal Total Heap 322456, Internal Free Heap 224876
SYSTEM_EVENT_AP_START
Loading profile ...
Reading NVS Profile A ... done
Pedal autosensing...
Pedal  1   autosensing disabled
Pedal  2   autosensing disabled
Pedal  3   autosensing disabled
Pedal  4   autosensing disabled
Pedal  5   autosensing disabled
Pedal  6   autosensing disabled
Bank  1
Pedal  1     MIDI         MOMENTARY1   PRESS_1       POLARITY+   NOTE_ON_OFF     60   Channel  1   Pin D25
Pedal  2     MIDI         MOMENTARY1   PRESS_1       POLARITY+   NOTE_ON_OFF     62   Channel  1   Pin D26
Pedal  3     MIDI         MOMENTARY1   PRESS_1       POLARITY+   NOTE_ON_OFF     64   Channel  1   Pin D27
Pedal  4     MIDI         MOMENTARY1   PRESS_1       POLARITY+   NOTE_ON_OFF     65   Channel  1   Pin D14
Pedal  5     MIDI         ANALOG                     POLARITY-   CONTROL_CHANGE  12   Channel  1   Pin A32 D12
Pedal  6     MIDI         ANALOG                     POLARITY-   CONTROL_CHANGE  13   Channel  1   Pin A33 D13
MTC None
Guru Meditation Error: Core  1 panic'ed (StoreProhibited). Exception was unhandled.
Core 1 register dump:
PC      : 0x401b3eae  PS      : 0x00060830  A0      : 0x801b3ecc  A1      : 0x3ffb1eb0  
A2      : 0x3ffc1984  A3      : 0x000000ff  A4      : 0x3ffb91b4  A5      : 0x00000000  
A6      : 0x00000000  A7      : 0x00000000  A8      : 0x00000000  A9      : 0x00000000  
A10     : 0x00000001  A11     : 0x00000000  A12     : 0x00000000  A13     : 0x00000001  
A14     : 0x00060220  A15     : 0x00000000  SAR     : 0x00000016  EXCCAUSE: 0x0000001d  
EXCVADDR: 0x00000000  LBEG    : 0x4000c28c  LEND    : 0x4000c296  LCOUNT  : 0x00000000

Backtrace: 0x401b3eae:0x3ffb1eb0 0x401b3ec9:0x3ffb1ed0 0x400e37fc:0x3ffb1ef0 0x400e38a2:0x3ffb1f20 0x400ea945:0x3ffb1f40 0x401b3c81:0x3ffb1f60 0x400eb6b2:0x3ffb1f80 0x40106389:0x3ffb1fb0 0x40089859:0x3ffb1fd0

Rebooting...

Decoded backtrace:

Decoding stack results
0x401b3eae: WiFiUDP::write(unsigned char) at C:\...\.platformio\packages\framework-arduinoespressif32\libraries\WiFi\src\WiFiUdp.cpp line 194
0x401b3ec9: WiFiUDP::write(unsigned char const*, unsigned int) at C:\...\.platformio\packages\framework-arduinoespressif32\libraries\WiFi\src\WiFiUdp.cpp line 201
0x400e37fc: ipMIDISendRealTimeMessage(unsigned char) at src/UdpMidiOut.h line 260
0x400e38a2: ipMIDISendSystemReset() at src/UdpMidiOut.h line 353
0x400ea945: OnSerialMidiSystemReset() at src/SerialMidi.h line 409
0x401b3c81: midi::MidiInterface ::launchCallback() at .pio/libdeps/esp32dev/MIDI Library/src/MIDI.hpp line 1230
0x400eb6b2: loop() at .pio/libdeps/esp32dev/MIDI Library/src/MIDI.hpp line 666
0x40106389: loopTask(void*) at C:\...\.platformio\packages\framework-arduinoespressif32\cores\esp32\main.cpp line 19
0x40089859: vPortTaskWrapper at /home/runner/work/esp32-arduino-lib-builder/esp32-arduino-lib-builder/esp-idf/components/freertos/port.c line 143

Relevant code in UdpMidiOut.h:

void ipMIDISendRealTimeMessage(byte type)
{
  byte midiPacket[1];

  if (!wifiEnabled || !interfaces[PED_IPMIDI].midiOut) return;

  // wifiEnabled is true, but there is no wifi connection, so the below call to write() throws an unhandled exception.
  // This could be improved by checking for an active connection instead of just checking the wifiEnabled variable.

  midiPacket[0] = type;
  ipMIDI.beginMulticastPacket();
  ipMIDI.write(midiPacket, 1);
  ipMIDI.endPacket();
}

I solved this by changing the default passphrase to repeat the chip ID. It is now 14 characters instead of 7, and still predictable based on the chip ID which is part of the default SSID.

void eeprom_update_ap_wifi_credentials(
    String ssid = String("Pedalino-") + getChipId(),
    String pass = getChipId() + getChipId())

It now boots and handles button presses without crashing/rebooting.

AP Pedalino-3C40A24 started with password 3C40A243C40A24
SYSTEM_EVENT_AP_START
AP SSID     : Pedalino-3C40A24
AP PSK      : 3C40A243C40A24
AP MAC      : 24:0A:C4:03:A6:D5
SYSTEM_EVENT_AP_STOP
SYSTEM_EVENT_AP_START
SYSTEM_EVENT_AP_START
AP IP       : 192.168.4.1
Channel     : 1
Connect to Pedalino-3C40A24 wireless network with password 3C40A243C40A24

alf45tar · 2019-10-28T19:48:22Z

@jwyse thank you very much for your debugging and very precise report.

The bug is in the getChipId function. It should return 8 hex digits from MAC address (the low 4 bytes) converted to a String. Due to a bug in my implementation it return only 7 digit when the first is zero like in your case 03C40A24.

alf45tar · 2019-10-28T19:58:33Z

@jwyse How do you decode backtrace in Platformio?

jwyse · 2019-10-28T21:32:28Z

You don't. :(
There are some workarounds referenced in this open issue.

I used me-no-dev's EspExceptionDecoder in the Arduino IDE. It's just a wrapper within Arduino IDE, so you could use a command line version instead.

If you do install the tool in the Arduino IDE, you can use it without actually loading/building/flashing the code there. Just launch the tool, point it to the ELF file in .pio\build\esp32dev\firmware.elf, and then paste the backtrace string.

jwyse · 2019-10-29T00:07:01Z

Your latest commit a few hours ago solved this problem. This issue can be closed. Thanks!

alf45tar added the bug Something isn't working label Oct 28, 2019

alf45tar closed this as completed Oct 29, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"AP mode failed" since commit 5197999 #40

"AP mode failed" since commit 5197999 #40

jwyse commented Oct 27, 2019

alf45tar commented Oct 28, 2019

jwyse commented Oct 28, 2019 •

edited

Loading

alf45tar commented Oct 28, 2019

alf45tar commented Oct 28, 2019

jwyse commented Oct 28, 2019

jwyse commented Oct 29, 2019

"AP mode failed" since commit 5197999 #40

"AP mode failed" since commit 5197999 #40

Comments

jwyse commented Oct 27, 2019

alf45tar commented Oct 28, 2019

jwyse commented Oct 28, 2019 • edited Loading

alf45tar commented Oct 28, 2019

alf45tar commented Oct 28, 2019

jwyse commented Oct 28, 2019

jwyse commented Oct 29, 2019

jwyse commented Oct 28, 2019 •

edited

Loading