Preferences - begin() : nvs_open failed: NOT_FOUND

rowifi commented 3 years ago

I don't think this is a problem with Autoconnect as such, but I cannot resolve it and there are few details that I can find that clearly explain how to resolve it. I have two different ESP323 modules ( one OLED another TFT ) Both have seen different programs uploaded at various times and both have used wifi successfully.

The issue arises when Autoconnect is included to provide non-hard coded credentials. With the two boards running identical programs except for the display library and display functions I get two different startup message streams. One has no problem with nvs yet the other fails. I can only assume that this is to do with the partitions or some other action that has changed the nonvolatile section in one of the boards. Both programs have been compiled with the same partition settings in Arduino IDE.

The code has a feature that allows the credentials to be erased ( before deploying to a customer) and thus should cause the Portal to run. It works on one board but not the other. Although I suspect this would be resolved if the nvs is fixed.

Both boards work fine using programs with hard coded credentials - so I suspect it is something not setup correctly on one board that causes the nvs failure which I guess is now required by autoconnect.

Since I have one board exhibiting this error - with the same ( almost) code, what is it that I have done or need to do to resolve the problem?

NEW MODULE

[D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 3 - STA_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [E][Preferences.cpp:38] begin(): nvs_open failed: NOT_FOUND [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 4 - STA_CONNECTED [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 7 - STA_GOT_IP [D][WiFiGeneric.cpp:381] _eventCallback(): STA IP: 192.168.1.3, MASK: 255.255.255.0, GW: 192.168.1.1 HTTP server:192.168.1.3

EXISTING MODULE

[D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 3 - STA_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 4 - STA_CONNECTED [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 7 - STA_GOT_IP [D][WiFiGeneric.cpp:381] _eventCallback(): STA IP: 192.168.1.12, MASK: 255.255.255.0, GW: 192.168.1.1 HTTP server:192.168.1.12

Added Partition table of each device.:

NEW MODULE

ets Jul 29 2019 12:21:46

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:1 load:0x3fff0018,len:4 load:0x3fff001c,len:1216 ho 0 tail 12 room 4 load:0x40078000,len:9720 ho 0 tail 12 room 4 load:0x40080400,len:6352 entry 0x400806b8 [W][esp32-hal-psram.c:30] psramInit(): PSRAM init failed! Flash chip size: 16777216 Partiton table: 0 - 10 - 10000 - 140000 - app0 - 0 0 - 11 - 150000 - 140000 - app1 - 0 1 - 2 - 9000 - 5000 - nvs - 0 1 - 0 - e000 - 2000 - otadata - 0 1 - 82 - 290000 - 170000 - spiffs - 0 Test complete

EXISTING MODULE

ets Jun 8 2016 00:22:57

rst:0x1 (POWERON_RESET),boot:0x17 (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:1 load:0x3fff0018,len:4 load:0x3fff001c,len:1216 ho 0 tail 12 room 4 load:0x40078000,len:9720 ho 0 tail 12 room 4 load:0x40080400,len:6352 entry 0x400806b8 [W][esp32-hal-psram.c:30] psramInit(): PSRAM init failed! Flash chip size: 16777216 Partiton table: 0 - 10 - 10000 - 140000 - app0 - 0 0 - 11 - 150000 - 140000 - app1 - 0 1 - 2 - 9000 - 5000 - nvs - 0 1 - 0 - e000 - 2000 - otadata - 0 1 - 82 - 290000 - 170000 - spiffs - 0 Test complete

rowifi commented 3 years ago

Here's an update. I forced the Portal and entered the wifi credentials, restarted and now the nvs has gone. Can anyone offer an explanation as to what has happened?

[D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 3 - STA_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 4 - STA_CONNECTED [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 7 - STA_GOT_IP [D][WiFiGeneric.cpp:381] _eventCallback(): STA IP: 192.168.1.3, MASK: 255.255.255.0, GW: 192.168.1.1 HTTP server:192.168.1.3

Connected.

Connecting to AWS IoT

[D][ssl_client.cpp:208] start_ssl_client(): Protocol is TLSv1.2 Ciphersuite is TLS-ECDHE-RSA-WITH-AES-128-GCM-SHA256 [D][ssl_client.cpp:210] start_ssl_client(): Record expansion is 29 Connected. Subscribed. Finished connection to AWS IoT.

Show RSSI Show RSSI Show RSSI Show RSSI

Hieromon commented 3 years ago

Which board is equipped with OLED or TFT that fails to open NVS? If it is a TFT-equipped one, is it giving enough current? #250

rowifi commented 3 years ago

It was the TFT, but the issue resolved itself after I forced the Portal at boot ( a pin option) and set / reset wifi credentials. After I did that the nvs problem disappeared. I had seen it before on the OLED but never investigated properly so I would have used the AP to set credentials on that some time ago. What I will do is erase the flash completely and reload the program to see if it is repeatable.

rowifi commented 3 years ago

After a chip erase and a fresh program load, the nvs error reappears. If the AP is forced using a pin option on reboot - it enters Access Point mode and allows credentials to be entered. The code then runs and subsequent reboots show no nvs problem.

After a chip erase and fresh load of program. ( no wifi creds will be there) Start Normal [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 3 - STA_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [E][Preferences.cpp:38] begin(): nvs_open failed: NOT_FOUND [E][WiFiSTA.cpp:219] begin(): connect failed! [E][Preferences.cpp:38] begin(): nvs_open failed: NOT_FOUND ...........................................

Restart program while forcing portal , entering wifi credentials and reboots show no problem.

Start Normal [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 0 - WIFI_READY [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 14 - AP_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 3 - STA_STOP [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 2 - STA_START [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 4 - STA_CONNECTED [D][WiFiGeneric.cpp:337] _eventCallback(): Event: 7 - STA_GOT_IP [D][WiFiGeneric.cpp:381] _eventCallback(): STA IP: 192.168.1.3, MASK: 255.255.255.0, GW: 192.168.1.1 HTTP server:192.168.1.3

Connected.

Hieromon commented 3 years ago

Thank you for your report. There may be something wrong with the nvs initialization sequence in AutoConnect. I will start the investigation.

Hieromon commented 3 years ago

I verified the sequence of the procedure for the nvs initialization. There is no wrong procedure with the steps in the current AutoConnectCredential class. Immediately after erasing the ESP32 flash, the AutoConnect Preferences key does not exist. NVS does not provide an API just to determine if an area with the specified key exists, so the AutoConnectCredential class checks it with NVS OPEN. That is the cause of the ESP32 core message you saw. This is correct behavior.

playground commented 1 year ago

Hi @Hieromon, the same version of my firmware has been working all along using v1.2.2 and I'm using ESP-WROOM-32, the portal used to pop up right the way when I join esp32ap, but today it stops working for some reason and it's throwing these errors. I tried erasing the ESP32, upgrade to v1.4.2 but still same errors. Any idea?

[  2004][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[  2012][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[  2030][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

Hieromon commented 1 year ago

@playground Hello, you can ignore that error. See FAQ.

playground commented 1 year ago

Hi @Hieromon, the problem is that I can't get to the portal to add new AP. This is the first time I have seen this error. Now the wifi is not working. The firmware is available here playground.github.io/liquid-prep-web-tools/

Hieromon commented 1 year ago

@playground First, I can't flash ESP32 with JS exception in my environment with the URL you provided.

For Arduino Core 2.0.5 or later, Is there room in the partition table for a larger your BIN size? If you take the AC_DEBUG trace, you may be able to see the cause of the problem a bit more.

playground commented 1 year ago

@Hieromon , that web tool only supports Chrome and Edge. And that has been working all along until yesterday. Curious to know why it would just stop working. I will try AC_DEBUG.

playground commented 1 year ago

@Hieromon, looks like it's hanging on Portal.begin(), not sure what this is? Again this code has not changed.

`⸮P0'⸮b�⸮A%]A⸮0xee

Connecting

`⸮P0'⸮b⸮A%]A⸮0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1044
load:0x40078000,len:10124
load:0x40080400,len:5856
entry 0x400806a8

Hieromon commented 1 year ago

@playground , I tried again in my other environment. It is Win10 Chrome. And I registered two new APs with AutoConnect, and they seem to be connecting fine, no nvs errors were detected. The following log is the serial output of the attempts in my environment.

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:1184
load:0x40078000,len:13132
load:0x40080400,len:3036
entry 0x400805e4

Starting BLE work!
Characteristic defined! Now you can read it in your phone!
Failed to read file, using default configuration
EmptyInput
Connecting
WiFi connected: 192.168.1.10
sensor reading: 582 - 100.000000
sensor reading: 173 - 100.000000
sensor reading: 298 - 100.000000
sensor reading: 194 - 100.000000
sensor reading: 265 - 100.000000
sensor reading: 272 - 100.000000

I was a little concerned in experiencing your firmware, it seems that the AutoConnect menu response is a little delayed. Is there a delay or some kind of waiting process during the execution of the loop function? Usually, they interfere with the response of the WebServer request handler.

Hieromon commented 1 year ago

@playground The partition size is different between your boot loader and mine. Are you successful in ESP flashing?

Your boot

mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1044
load:0x40078000,len:10124
load:0x40080400,len:5856
entry 0x400806a8

My boot

mode:DIO, clock div:2
load:0x3fff0030,len:1184
load:0x40078000,len:13132
load:0x40080400,len:3036
entry 0x400805e4

playground commented 1 year ago

@Hieromon, flashing the ESP is successful. I have tried to re-flash on two different ESP32 that already had the same firmware flashed last month and are running, as soon as I re-flashed them, I got these same errors.

Tried erasing them but got the same errors

esptool.py --chip esp32 -p /dev/cu.usbserial-0001 erase_flash

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371 
ets Jun  8 2016 00:22:57

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371 
Ŋ"⸮?   ⸮A%]A⸮0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:1
load:0x3fff0018,len:4
load:0x3fff001c,len:1044
load:0x40078000,len:10124
load:0x40080400,len:5856
entry 0x400806a8

Hieromon commented 1 year ago

@playground , Is the version of esptool.py the same as the one you used in your previous success?

playground commented 1 year ago

@Hieromon, it's weird that web tool url is working for you and it stopped working for me starting yesterday.

The complete code is here https://github.com/Liquid-Prep/LiquidPrep-Hardware/blob/websocket/esp32-websocket-client/src/main.cpp

About your question on esptool.py. I have been using my Mbp M1 to develop for several months ago. And I just re-installed esptool v4.6-dev recently.

I tried it on my other computer that is still running esptool v4.4 but it's too throwing the same error :-(

[  2004][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[  2012][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[  2030][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

@Hieromon, does the portal pop up for you?

Hieromon commented 1 year ago

@playground,

does the portal pop up for you?

Yes, works fine. It's similar to an issue on the ESP32 Arduino core topic. https://github.com/espressif/arduino-esp32/issues/7538

And now I am trying to rebuild and try your main.cpp with ESP32 Core 2.0.6. But it does not fit in the min_spiffs partition in core 2.0.6 with AC_DEBUG enabled. core2.0.6 is fat compared to previous versions.

playground commented 1 year ago

I'm pulling my hair here, why it works for you and others but not for me anymore :-(

Hieromon commented 1 year ago

@playground, Make changes to min_spiffs.csv in Arduino Core 2.0.6 to extend app0 and app1 a bit. In return, reduce spiffs a little. Build with Core 2.0.6 using the partition table with your changes. That should give you a little more room in new partitions. The problem may be because your main.cpp is close to the limit of the partition size. However, we don't know for sure, so you will have to repeat the trial. I will do a little verification tomorrow on my part.

Another validation is to try a simpler sketch: exclude BLE and take advantage of AutoConnect and WebSockets only. Temporarily discard the sensor measurement logic as well. Then build with core 2.0.6 and check the behavior of AutoConnect and WebServer. If this fails, further reduce the sketch. If the nvs open error disappears during this process, then the problem may be with the BIN size.

playground commented 1 year ago

@Hieromon, That still doesn't explain why it was working with https://playground.github.io/liquid-prep-web-tools/ and still does for you.

I commented out bluetooth still getting the same errors.

I also tried it with the older version https://github.com/Liquid-Prep/LiquidPrep-Hardware/tree/websocket/Soil%20Moisture%20Sensor/src with just bluetooth and AutoConnect. Same problem.

Hieromon commented 1 year ago

@playground, Which ESP32 Core version did you build the firmware downloaded to me using the URL https://playground.github.io/liquid-prep-web-tools/ you provided?

The message below often occurs when the BIN is not placed in the correct position in the first place. Since the bootloader cannot read the built binary, it is caught in the WDT of FreeRTOS and reset.

rst:0x10 (RTCWDT_RTC_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
flash read err, 1000
ets_main.c 371

This happens when the partition location is misaligned or the flash memory has a physical error. I have never seen this caused by an error in a user sketch. If the app partition is misaligned, so will the NVS partition. So nvs open fails.

playground commented 1 year ago

@Hieromon, I used PlatformIO with this ini file

[platformio]
default_envs = esp32-websocket-client
description = 

[env:esp32-websocket-client]
platform = espressif32
board = esp32doit-devkit-v1
framework = arduino
upload_port = /dev/cu.usbserial-0001
upload_speed = 115200
monitor_speed = 115200
board_build.partitions = min_spiffs.csv
build_flags = -D_GLIBCXX_USE_C99
lib_deps = 
    hieromon/AutoConnect@^1.2.2
    links2004/WebSockets@^2.3.7

Hieromon commented 1 year ago

@playground Which Version of ESP32 Arduino Core? You can confirm it from PlatformIO build log. It refers to the ESP32 Arduio Core version you were using when you built the firmware I just downloaded.

playground commented 1 year ago

@Hieromon, https://www.amazon.com/gp/product/B086MJGFVV/ref=ppx_yo_dt_b_search_asin_title?ie=UTF8&psc=1

playground commented 1 year ago

@Hieromon Here is what I noticed,

Reflash firmware on ESP32 that's already running the same firmware -> this work as expected
Erase flash on ESP32 that has a running/working firmware -> not working
Flash the same firmware on a new ESP32 -> not working
Remove Bluetooth and SPIFFS -> not working

Looks like it used to be able to write to SPIFFS, now even comment out SPIFFS, still get the same errors.

1) ESP32 with working firmware that was flashed a while ago, If I reflash it, it still works as expected.

Reconnecting to /dev/cu.usbserial-0001 ...       Connected!

32
Starting BLE work!
Characteristic defined! Now you can read it in your phone!
Connecting
WiFi connected: 192.168.86.53
192.168.86.24, 3003, /
Websocket Connected

 *  Executing task in folder esp32-websocket-client: platformio run --target upload 

Processing esp32-websocket-client (platform: espressif32; board: esp32doit-devkit-v1; framework: arduino)
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Verbose mode can be enabled via `-v, --verbose` option
CONFIGURATION: https://docs.platformio.org/page/boards/espressif32/esp32doit-devkit-v1.html
PLATFORM: Espressif 32 (5.2.0) > DOIT ESP32 DEVKIT V1
HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash
DEBUG: Current (cmsis-dap) External (cmsis-dap, esp-bridge, esp-prog, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa)
PACKAGES: 
 - framework-arduinoespressif32 @ 3.20005.220925 (2.0.5) 
 - tool-esptoolpy @ 1.40201.0 (4.2.1) 
 - tool-mkfatfs @ 2.0.1 
 - tool-mklittlefs @ 1.203.210628 (2.3) 
 - tool-mkspiffs @ 2.230.0 (2.30) 
 - toolchain-xtensa-esp32 @ 8.4.0+2021r2-patch3
LDF: Library Dependency Finder -> https://bit.ly/configure-pio-ldf
LDF Modes: Finder ~ chain, Compatibility ~ soft
Found 36 compatible libraries
Scanning dependencies...
Dependency Graph
|-- AutoConnect @ 1.4.2
|   |-- PageBuilder @ 1.5.6
|   |   |-- FS @ 2.0.0
|   |   |-- LittleFS @ 2.0.0
|   |   |   |-- FS @ 2.0.0
|   |   |-- SPIFFS @ 2.0.0
|   |   |   |-- FS @ 2.0.0
|   |   |-- WebServer @ 2.0.0
|   |   |   |-- WiFi @ 2.0.0
|   |   |   |-- FS @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- ArduinoJson @ 6.20.1
|   |-- Update @ 2.0.0
|   |-- WiFi @ 2.0.0
|   |-- SD @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |   |-- SPI @ 2.0.0
|   |-- SPI @ 2.0.0
|   |-- HTTPClient @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |   |-- WiFiClientSecure @ 2.0.0
|   |   |   |-- WiFi @ 2.0.0
|   |-- HTTPUpdate @ 2.0.0
|   |   |-- HTTPClient @ 2.0.0
|   |   |   |-- WiFi @ 2.0.0
|   |   |   |-- WiFiClientSecure @ 2.0.0
|   |   |   |   |-- WiFi @ 2.0.0
|   |   |-- Update @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- DNSServer @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- EEPROM @ 2.0.0
|   |-- WebServer @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |-- FS @ 2.0.0
|   |-- LittleFS @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |-- SPIFFS @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |-- Preferences @ 2.0.0
|   |-- Ticker @ 2.0.0
|-- WebSockets @ 2.3.7
|   |-- Ethernet @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- SPI @ 2.0.0
|   |-- WiFi @ 2.0.0
|   |-- WiFiClientSecure @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|-- ArduinoJson @ 6.20.1
|-- ESP32 BLE Arduino @ 2.0.0
|-- WebServer @ 2.0.0
|   |-- WiFi @ 2.0.0
|   |-- FS @ 2.0.0
|-- WiFi @ 2.0.0
Building in release mode
Retrieving maximum program size .pio/build/esp32-websocket-client/firmware.elf
Checking size .pio/build/esp32-websocket-client/firmware.elf
Advanced Memory Usage is available via "PlatformIO Home > Project Inspect"
RAM:   [==        ]  16.8% (used 55056 bytes from 327680 bytes)
Flash: [==========]  98.3% (used 1931857 bytes from 1966080 bytes)
Configuring upload protocol...
AVAILABLE: cmsis-dap, esp-bridge, esp-prog, espota, esptool, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa
CURRENT: upload_protocol = esptool
Looking for upload port...
Using manually specified: /dev/cu.usbserial-0001
Uploading .pio/build/esp32-websocket-client/firmware.bin
esptool.py v4.2.1
Serial port /dev/cu.usbserial-0001
Connecting......
Chip is ESP32-D0WDQ6-V3 (revision 3)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 78:21:84:8c:f0:10
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Flash will be erased from 0x00001000 to 0x00005fff...
Flash will be erased from 0x00008000 to 0x00008fff...
Flash will be erased from 0x0000e000 to 0x0000ffff...
Flash will be erased from 0x00010000 to 0x001e9fff...
Compressed 17440 bytes to 12127...
Writing at 0x00001000... (100 %)
Wrote 17440 bytes (12127 compressed) at 0x00001000 in 1.4 seconds (effective 100.1 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 129...
Writing at 0x00008000... (100 %)
Wrote 3072 bytes (129 compressed) at 0x00008000 in 0.1 seconds (effective 307.3 kbit/s)...
Hash of data verified.
Compressed 8192 bytes to 47...
Writing at 0x0000e000... (100 %)
Wrote 8192 bytes (47 compressed) at 0x0000e000 in 0.1 seconds (effective 464.6 kbit/s)...
Hash of data verified.
Compressed 1937632 bytes to 1205411...
Writing at 0x00010000... (1 %)
Writing at 0x0001bb2d... (2 %)
...
Writing at 0x001e0537... (98 %)
Writing at 0x001e5b62... (100 %)
Wrote 1937632 bytes (1205411 compressed) at 0x00010000 in 106.6 seconds (effective 145.5 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
======================================================================== [SUCCESS] Took 117.50 seconds ========================================================================

After reflashed still working as expected

 *  Executing task in folder esp32-websocket-client: platformio device monitor 

pyenv shell 3.11.0
--- Terminal on /dev/cu.usbserial-0001 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
Characteristic defined! Now you can read it in your phone!
Connecting
WiFi connected: 192.168.86.53
192.168.86.24, 3003, /...     **(Added ... to show re-flash still works)**
ELx400
Websocket Connected
ELx400
sensor reading: 100.00
Sending: {"moisture": 100.00}
sensor reading: 100.00
Sending: {"moisture": 100.00}
sensor reading: 100.00
Sending: {"moisture": 100.00}

2) Erase Flash with PlatformIO in VScode, then flash firmware again

 *  Executing task in folder esp32-websocket-client: platformio run --target upload 

Processing esp32-websocket-client (platform: espressif32; board: esp32doit-devkit-v1; framework: arduino)
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Verbose mode can be enabled via `-v, --verbose` option
CONFIGURATION: https://docs.platformio.org/page/boards/espressif32/esp32doit-devkit-v1.html
PLATFORM: Espressif 32 (5.2.0) > DOIT ESP32 DEVKIT V1
HARDWARE: ESP32 240MHz, 320KB RAM, 4MB Flash
DEBUG: Current (cmsis-dap) External (cmsis-dap, esp-bridge, esp-prog, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa)
PACKAGES: 
 - framework-arduinoespressif32 @ 3.20005.220925 (2.0.5) 
 - tool-esptoolpy @ 1.40201.0 (4.2.1) 
 - tool-mkfatfs @ 2.0.1 
 - tool-mklittlefs @ 1.203.210628 (2.3) 
 - tool-mkspiffs @ 2.230.0 (2.30) 
 - toolchain-xtensa-esp32 @ 8.4.0+2021r2-patch3
LDF: Library Dependency Finder -> https://bit.ly/configure-pio-ldf
LDF Modes: Finder ~ chain, Compatibility ~ soft
Found 36 compatible libraries
Scanning dependencies...
Dependency Graph
|-- AutoConnect @ 1.4.2
|   |-- PageBuilder @ 1.5.6
|   |   |-- FS @ 2.0.0
|   |   |-- LittleFS @ 2.0.0
|   |   |   |-- FS @ 2.0.0
|   |   |-- SPIFFS @ 2.0.0
|   |   |   |-- FS @ 2.0.0
|   |   |-- WebServer @ 2.0.0
|   |   |   |-- WiFi @ 2.0.0
|   |   |   |-- FS @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- ArduinoJson @ 6.20.1
|   |-- Update @ 2.0.0
|   |-- WiFi @ 2.0.0
|   |-- SD @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |   |-- SPI @ 2.0.0
|   |-- SPI @ 2.0.0
|   |-- HTTPClient @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |   |-- WiFiClientSecure @ 2.0.0
|   |   |   |-- WiFi @ 2.0.0
|   |-- HTTPUpdate @ 2.0.0
|   |   |-- HTTPClient @ 2.0.0
|   |   |   |-- WiFi @ 2.0.0
|   |   |   |-- WiFiClientSecure @ 2.0.0
|   |   |   |   |-- WiFi @ 2.0.0
|   |   |-- Update @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- DNSServer @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- EEPROM @ 2.0.0
|   |-- WebServer @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |-- FS @ 2.0.0
|   |-- LittleFS @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |-- SPIFFS @ 2.0.0
|   |   |-- FS @ 2.0.0
|   |-- Preferences @ 2.0.0
|   |-- Ticker @ 2.0.0
|-- WebSockets @ 2.3.7
|   |-- Ethernet @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|   |-- SPI @ 2.0.0
|   |-- WiFi @ 2.0.0
|   |-- WiFiClientSecure @ 2.0.0
|   |   |-- WiFi @ 2.0.0
|-- ArduinoJson @ 6.20.1
|-- ESP32 BLE Arduino @ 2.0.0
|-- WebServer @ 2.0.0
|   |-- WiFi @ 2.0.0
|   |-- FS @ 2.0.0
|-- WiFi @ 2.0.0
Building in release mode
Retrieving maximum program size .pio/build/esp32-websocket-client/firmware.elf
Checking size .pio/build/esp32-websocket-client/firmware.elf
Advanced Memory Usage is available via "PlatformIO Home > Project Inspect"
RAM:   [==        ]  16.8% (used 55056 bytes from 327680 bytes)
Flash: [==========]  98.3% (used 1931857 bytes from 1966080 bytes)
Configuring upload protocol...
AVAILABLE: cmsis-dap, esp-bridge, esp-prog, espota, esptool, iot-bus-jtag, jlink, minimodule, olimex-arm-usb-ocd, olimex-arm-usb-ocd-h, olimex-arm-usb-tiny-h, olimex-jtag-tiny, tumpa
CURRENT: upload_protocol = esptool
Looking for upload port...
Using manually specified: /dev/cu.usbserial-0001
Uploading .pio/build/esp32-websocket-client/firmware.bin
esptool.py v4.2.1
Serial port /dev/cu.usbserial-0001
Connecting.........
Chip is ESP32-D0WDQ6 (revision 1)
Features: WiFi, BT, Dual Core, 240MHz, VRef calibration in efuse, Coding Scheme None
Crystal is 40MHz
MAC: 78:21:84:7d:7d:58
Uploading stub...
Running stub...
Stub running...
Configuring flash size...
Flash will be erased from 0x00001000 to 0x00005fff...
Flash will be erased from 0x00008000 to 0x00008fff...
Flash will be erased from 0x0000e000 to 0x0000ffff...
Flash will be erased from 0x00010000 to 0x001e9fff...
Compressed 17440 bytes to 12127...
Writing at 0x00001000... (100 %)
Wrote 17440 bytes (12127 compressed) at 0x00001000 in 1.3 seconds (effective 107.1 kbit/s)...
Hash of data verified.
Compressed 3072 bytes to 129...
Writing at 0x00008000... (100 %)
Wrote 3072 bytes (129 compressed) at 0x00008000 in 0.1 seconds (effective 404.0 kbit/s)...
Hash of data verified.
Compressed 8192 bytes to 47...
Writing at 0x0000e000... (100 %)
Wrote 8192 bytes (47 compressed) at 0x0000e000 in 0.1 seconds (effective 682.2 kbit/s)...
Hash of data verified.
Compressed 1937632 bytes to 1205411...
Writing at 0x00010000... (1 %)
Writing at 0x0001bb2d... (2 %)
...
Writing at 0x001e0537... (98 %)
Writing at 0x001e5b62... (100 %)
Wrote 1937632 bytes (1205411 compressed) at 0x00010000 in 106.5 seconds (effective 145.5 kbit/s)...
Hash of data verified.

Leaving...
Hard resetting via RTS pin...
======================================================================== [SUCCESS] Took 118.45 seconds ========================================================


 *  Executing task in folder esp32-websocket-client: platformio device monitor 

pyenv shell 3.11.0
--- Terminal on /dev/cu.usbserial-0001 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H

E (1034) SPIFFS: mount failed, -10025
[  1039][E][SPIFFS.cpp:89] begin(): Mounting SPIFFS failed! Error: -1
[  1039][E][vfs_api.cpp:24] open(): File system is not mounted
[  1043][E][vfs_api.cpp:24] open(): File system is not mounted
Starting BLE work!
Characteristic defined! Now you can read it in your phone!
[  1923][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[  1931][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[  1951][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

3) Flash a brand new ESP32, get the same errors

 *  Executing task in folder esp32-websocket-client: platformio device monitor 

pyenv shell 3.11.0
--- Terminal on /dev/cu.usbserial-0001 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
Characteristic defined! Now you can read it in your phone!
[  1949][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[  1969][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[  1988][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

4) Remove Bluetooth and SPIFFS File size much smaller 1176832 bytes (712733 compressed) vs. 1937632 bytes (1205411 compressed)

Writing at 0x00121850... (95 %)
Writing at 0x00126fa1... (97 %)
Writing at 0x0012c6cc... (100 %)
Wrote 1176832 bytes (712733 compressed) at 0x00010000 in 63.0 seconds (effective 149.4 kbit/s)...
Hash of data verified.

 *  Executing task in folder esp32-websocket-client: platformio device monitor 

pyenv shell 3.11.0
--- Terminal on /dev/cu.usbserial-0001 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
ets Jul 29 2019 12:21:46

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:1184
load:0x40078000,len:13132
load:0x40080400,len:3036
entry 0x400805e4

[  1252][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[  1260][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[  1277][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

Hieromon commented 1 year ago

@playground, I am comfortable with your test log. It appears to be AutoConnect working fine.

The NVS partition immediately after erasing FLASH does not have the nvs key for AutoConnect. It is created upon the first successful connection of the access point via the Configure New AP menu. Therefore, AutoConnect::begin executed immediately after erasing will cause nvs_open failure. This is described in the documentation.

Also, the file system is not initialized immediately after the FLASH erasure. You need to specify the formatOnFail argument for the SPIFFS::begin to prompt initialization. Therefore, SPIFFS.begin() in the setup function of your main.cpp you commented this post will generate a -10025 error.

But the older version you mention in this comment specifies formatOnFail. I’m not sure which your sketch version you are using.

playground commented 1 year ago

@Hieromon, adding formatOnFail back, the -10025 error went away but didn't make a difference, still throws the same errors. Anyway, now neither the older version nor the current version is working for me when flashing a new ESP32 or on an erased ESP32 :-(

  while (!SPIFFS.begin(true) && waitCount++ < 3) {
    delay(1000);
  }

pyenv shell 3.11.0
--- Terminal on /dev/cu.usbserial-0001 | 115200 8-N-1
--- Available filters and text transformations: colorize, debug, default, direct, esp32_exception_decoder, hexlify, log2file, nocontrol, printable, send_on_enter, time
--- More details at https://bit.ly/pio-monitor-filters
--- Quit: Ctrl+C | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H
ets Jul 29 2019 12:21:46

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:1184
load:0x40078000,len:13132
load:0x40080400,len:3036
entry 0x400805e4

Failed to read file, using default configuration
EmptyInput
Starting BLE work!
Characteristic defined! Now you can read it in your phone!
[  1951][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[  1959][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[  1979][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

Hieromon commented 1 year ago

@playground,

still throws the same errors. Anyway, now neither the older version nor the current version is working for me when flashing a new ESP32 or on an erased

adding formatOnFail back,

I'm not sure. For which one? And clarify what you mean by the same error. I partially traced your code, but that doesn't mean I'm your debugger. How does this relate to your first comment?

playground commented 1 year ago

@Hieromon, I meant I'm still getting this same error which is related to my first comment.

[  1951][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[  1959][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[  1979][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

Hieromon commented 1 year ago

@playground, I have already answered it twice on the comment and this one. It is the normal operation of the Preferences library of the ESP32 Arduino Core. See https://hieromon.github.io/AutoConnect/faq.html#nvs_open-failed-not_found-occurs

[ 1951][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND

AutoConnect saves the credentials of the access point to which it was able to connect to the NVS of the ESP32 module as Preferences instances. The above error occurs when the area keyed for AutoConnect credentials does not exist in NVS. Usually, this error occurs immediately after erasing the ESP32 module flash or when running the AutoConnect sketch for the first time. If the AutoConnect credentials area does not exist in NVS, AutoConnect will automatically allocate it. Therefore, this error can be ignored and will not affect the execution of the sketch.

Also, the following error is part of the expected behavior and is normal. See the documentation.

[ 1959][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a

playground commented 1 year ago

@Hieromon, right I saw that, the problem I'm having is that the Portal does not pop up anymore when joining esp32ap, I know you said it's popping up for you. I can't get to the portal and esp is not able to connect to my wifi. How can I get to it? I can't get to http://172.217.28.1/_ac/config either.

Hieromon commented 1 year ago

@playground, Turn on AC_DEBUG and get the trace log on Serial monitor. Then check FAQ on the AutoConnect Documentation.

In my environment, The captive portal will open automatically and you can select Config New from the AutoConnect menu. Below is the evidence.

For Safari with iOS 16.2

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:1184
load:0x40078000,len:13104
load:0x40080400,len:3036
entry 0x400805e4

[AC] Deserialize error:EmptyInput
Failed to read file, using default configuration
EmptyInput
[AC] /update_config not registered, handler ignored
[AC] /save_config not registered, handler ignored
[AC] / not registered, handler ignored
[AC] Set persistance
[AC] Current:
[  1290][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[AC] Preferences begin failed to import AC_CREDT
[AC] WiFi.config(IP=0.0.0.0, Gateway=0.0.0.0, Subnetmask=0.0.0.0, DNS1=0.0.0.0, DNS2=0.0.0.0)
[  1309][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[AC] WiFi.begin() failed
[AC] autoReconnect[  1325][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[AC] Preferences begin failed to import AC_CREDT
 failed
[AC] SoftAP configure 172.217.28.1, 172.217.28.1, 255.255.255.0 
[AC] SoftAP esp32ap/12345678 Ch(1) IP:172.217.28.1 
[AC] http server started
[AC] DNS server started
[AC] s_cap placed on /_ac/update
[AC] cap placed on /_ac/update
[AC] bin placed on /_ac/update
[AC] update placed on /_ac/update
[AC] js placed on /_ac/update
[AC] bin placed on /_ac/update_act
[AC] result placed on /_ac/update_act
[AC] rc placed on /_ac/update_act
[AC] /_ac/update on hands
[AC] /_ac/update_act on hands
[AC] Host:,/hotspot-detect.html,ignored
[8419695][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, captive.apple.com, 0.0.0.0
[AC] Host:captive.apple.com,/_ac,generated:/_ac, allocated
[AC] Host:172.217.28.1,/_ac,already allocated
[AC] Host:172.217.28.1,/hotspot-detect.html,ignored
[8421953][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, captive.apple.com, 0.0.0.0
[AC] Host:captive.apple.com,/_ac,generated:/_ac, allocated
[AC] Host:172.217.28.1,/_ac,already allocated
[AC] Host:172.217.28.1,/hotspot-detect.html,ignored
[8422111][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, captive.apple.com, 0.0.0.0
[AC] Host:captive.apple.com,/_ac,generated:/_ac, allocated
[AC] Host:172.217.28.1,/_ac,already allocated

For Chrome on Windows 10

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:1184
load:0x40078000,len:13104
load:0x40080400,len:3036
entry 0x400805e4

[AC] Deserialize error:EmptyInput
Failed to read file, using default configuration
EmptyInput
[AC] /update_config not registered, handler ignored
[AC] /save_config not registered, handler ignored
[AC] / not registered, handler ignored
[AC] Set persistance
[AC] Current:
[  1286][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[AC] Preferences begin failed to import AC_CREDT
[AC] WiFi.config(IP=0.0.0.0, Gateway=0.0.0.0, Subnetmask=0.0.0.0, DNS1=0.0.0.0, DNS2=0.0.0.0)
[  1305][E][WiFiSTA.cpp:317] begin(): connect failed! 0x300a
[AC] WiFi.begin() failed
[AC] autoReconnect[  1313][E][Preferences.cpp:50] begin(): nvs_open failed: NOT_FOUND
[AC] Preferences begin failed to import AC_CREDT
 failed
[AC] SoftAP configure 172.217.28.1, 172.217.28.1, 255.255.255.0 
[AC] SoftAP esp32ap/12345678 Ch(1) IP:172.217.28.1 
[AC] http server started
[AC] DNS server started
[AC] s_cap placed on /_ac/update
[AC] cap placed on /_ac/update
[AC] bin placed on /_ac/update
[AC] update placed on /_ac/update
[AC] js placed on /_ac/update
[AC] bin placed on /_ac/update_act
[AC] result placed on /_ac/update_act
[AC] rc placed on /_ac/update_act
[AC] /_ac/update on hands
[AC] /_ac/update_act on hands
[AC] Host:,/connecttest.txt,ignored
[ 14656][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, www.msftconnecttest.com, 0.0.0.0
[AC] Host:www.msftconnecttest.com,/connecttest.txt,ignored
[ 15106][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, www.msftconnecttest.com, 0.0.0.0
[AC] Host:www.msftconnecttest.com,/connecttest.txt,ignored
[ 15147][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, www.msftconnecttest.com, 0.0.0.0
[AC] Host:www.msftconnecttest.com,/connecttest.txt,ignored
[ 15557][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, www.msftconnecttest.com, 0.0.0.0
[AC] Host:www.msftconnecttest.com,/redirect,ignored
[ 15723][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, www.msftconnecttest.com, 0.0.0.0
[AC] Host:www.msftconnecttest.com,/_ac,generated:/_ac, allocated
[AC] Host:172.217.28.1,/_ac,already allocated
[AC] Host:172.217.28.1,/favicon.ico,ignored
[ 19327][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Host:172.217.28.1,/connecttest.txt,ignored
[ 20610][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, www.msftconnecttest.com, 0.0.0.0
[AC] Host:www.msftconnecttest.com,/connecttest.txt,ignored
[ 20901][E][WebServer.cpp:649] _handleRequest(): request handler not found
[AC] Detected application, www.msftconnecttest.com, 0.0.0.0

playground commented 1 year ago

@Hieromon, I decided to delete and reinstall PlatformIO, and it started to work again. One thing that is still not working is that the captive port won't pop open on Mbp M1, but I can get to it via http://172.217.28.1/_ac/update. Thanks for your help.

Hieromon commented 1 year ago

@playground, When the ESP32 side does not have STA connectivity, it redirects all HTTP requests to SoftAP to /_ac. On the other hand, the client device OS makes an HTTP request to the default URL to check internet transparency when binding the WiFi connection to the TCP stack. ESP32 returns /_ac content in response to that request.

At this point, it is the OS of the client device that initiates the captive portal session. An automatic popup will work when that session starts. Auto popups are only part of a captive portal session.

So, I'm not sure what changes the macOS made in M1. But the place you should look into, I believe, is not the AutoConnect repository.

https://discussions.apple.com/thread/254400603

Hieromon / AutoConnect

Preferences - begin() : nvs_open failed: NOT_FOUND #289

For Safari with iOS 16.2

For Chrome on Windows 10