espressif / esp-rainmaker

ESP RainMaker Agent for firmware development
Apache License 2.0
433 stars 146 forks source link

ESP32 stuck at Confirming Wi-Fi connection while provisioning. (MEGH-3825) #167

Closed maxakash closed 1 year ago

maxakash commented 1 year ago

I am adding new device in ESP Rainmaker app(tried both in iOS & android), but the provisioning process always stuck at confirming wi-fi connection and show Device disconnected error. I can see in the serial monitor that the ESP32 is connected to the wifi. The error is caused as the ESP32 restarts after connecting.

Here is the debug output

01:45:10.155 -> Reset Button Pressed!
01:45:15.297 -> Reset Wi-Fi.
01:45:15.333 -> [222834][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 3 - STA_STOP
01:45:17.327 -> ets Jun  8 2016 00:22:57
01:45:17.362 -> 
01:45:17.362 -> rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
01:45:17.362 -> configsip: 0, SPIWP:0xee
01:45:17.362 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
01:45:17.362 -> mode:DIO, clock div:1
01:45:17.362 -> load:0x3fff0030,len:1344
01:45:17.362 -> load:0x40078000,len:13864
01:45:17.362 -> load:0x40080400,len:3608
01:45:17.362 -> entry 0x400805f0
01:45:17.900 -> [�⸮⸮mum⸮⸮⸮⸮2-hal-cpu.c:214] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
01:45:17.973 -> [    56][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 0 - WIFI_READY
01:45:18.009 -> [    83][I][RMaker.cpp:14] event_handler(): RainMaker Initialised.
01:45:18.009 -> 
01:45:18.009 -> Chip ID:  12913848 Service Name: ESP32
01:45:18.009 -> 
01:45:18.009 -> Starting ESP-RainMaker
01:45:18.009 -> [    87][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 33 - PROV_INIT
01:45:18.009 -> [    91][I][WiFiProv.cpp:133] beginProvision(): Starting AP using BLE. service_name : ESP32, pop : maxakash
01:45:18.085 -> [   190][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 2 - STA_START
01:45:18.532 -> [   601][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Living Room TV, Param Name : Power, Val : false
01:45:18.532 -> [   601][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Living Room Cove Light, Param Name : Power, Val : false
01:45:18.532 -> [   602][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 35 - PROV_START
01:45:18.532 -> 
01:45:18.532 -> Provisioning Started with name "ESP32" and PoP "maxakash" on BLE
01:45:18.532 -> Scan this QR code from the ESP RainMaker phone app.
01:45:18.568 ->                                       
01:45:18.568 ->   █▀▀▀▀▀█ ▀██▄▀▀█▀▀▄▄█ ▄ ▀▄ █▀▀▀▀▀█   
01:45:18.606 ->   █ ███ █ ▄█▀▀█▄▄██▀▄ █▀▀▄  █ ███ █   
01:45:18.606 ->   █ ▀▀▀ █ █▄▄█▀  ▀▄▄▄▄ ██▀█ █ ▀▀▀ █   
01:45:18.606 ->   ▀▀▀▀▀▀▀ █ █▄█ █▄▀▄█▄█▄█▄█ ▀▀▀▀▀▀▀   
01:45:18.606 ->   ▀ ▄▄█ ▀▀▀ ▄█▀  ▄█  ▄▀▀▀███▀▀▀▀▄▄▀   
01:45:18.606 ->   █ ██▀▀▀ ▀█  ▀ █▀██▀▄ █▄█▄▄██ ▀▀ ▄   
01:45:18.644 ->    █▄█▄▀▀▄ █▄▀▄▀█▄▄▀█▀▀▀███▄▀▄▀▀▄█    
01:45:18.644 ->   █▀▀ ▄█▀▄█▀▄▄▄█▄█▀█   █▀▀  ▄▄█▀▀▄▄   
01:45:18.644 ->     █▀█▄▀ ▄█▀   ██ ▀▀▀█▀▀▄█ ▀▀▀▄▄▀    
01:45:18.644 ->   ▀▄▀  ▀▀█ ▄ ▀▀  █▀▄ ▄ ▄█▀ ▄ █▄▀▀ ▄   
01:45:18.682 ->   ██▀██▀▀ █▀ ▄█ ▄█▄▀▀  █▀▄█ ▀▄▀▄ ▀▀   
01:45:18.682 ->      ▄▀█▀ ▀ █▀ ▀▀▀█▄▄▄▀█ █ ▀▄█▀  ▀▄   
01:45:18.682 ->   ▀▀▀   ▀ ▄▀▄▀█▄█▄ █▀▀▄▀▀▀█▀▀▀█▄▄▄    
01:45:18.682 ->   █▀▀▀▀▀█ ▀ ▄▀▀ ▄▀█▄ ▄ █▀▄█ ▀ █       
01:45:18.682 ->   █ ███ █ ▀▄ ▀▄██▄▄▀█▀ ▀▀▄███▀█▀▄▀▀   
01:45:18.720 ->   █ ▀▀▀ █   ▀ ▄▀ ▀█▄ ▄▄█ █▄▀▀█▀       
01:45:18.720 ->   ▀▀▀▀▀▀▀ ▀   ▀▀   ▀▀ ▀▀ ▀▀    ▀  ▀   
01:45:18.720 ->                                       
01:45:18.720 -> 
01:45:18.720 -> If QR code is not visible, copy paste the below URL in a browser.
01:45:18.720 -> https://rainmaker.espressif.com/qrcode.html?data={"ver":"v1","name":"ESP32","pop":"maxakash","transport":"ble"}
01:45:18.720 -> [   618][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Living Room Chandelier, Param Name : Power, Val : false
01:45:18.758 -> [   820][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Dining Room Chandelier, Param Name : Power, Val : false
01:45:18.758 -> [   831][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Kitchen Chandelier, Param Name : Power, Val : false
01:45:18.758 -> [   842][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Outside Profile Light, Param Name : Power, Val : false
01:45:18.758 -> [   852][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Curtain Open, Param Name : Power, Val : false
01:45:18.792 -> [   862][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Curtain Close, Param Name : Power, Val : false
01:45:55.088 -> [ 37195][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 1 - SCAN_DONE
01:46:00.027 -> [ 42102][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 37 - PROV_CRED_RECV
01:46:02.373 -> [ 44457][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
01:46:02.373 -> 
01:46:02.373 -> Connected to Wi-Fi!
01:46:02.692 -> [ 44784][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
01:46:02.692 -> [ 44784][D][WiFiGeneric.cpp:991] _eventCallback(): STA IP: 192.168.68.109, MASK: 255.255.255.0, GW: 192.168.68.1
01:46:02.725 -> [ 44790][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 39 - PROV_CRED_SUCCESS
01:46:05.283 -> E (59355) wifi_prov_mgr: Failed to create prov_stop_task!
01:46:05.316 -> 
01:46:05.316 -> abort() was called at PC 0x40177e67 on core 0
01:46:05.316 -> 
01:46:05.316 -> 
01:46:05.316 -> Backtrace:0x40083815:0x3ffe2a700x40094d09:0x3ffe2a90 0x4009a429:0x3ffe2ab0 0x40177e67:0x3ffe2b30 0x40179345:0x3ffe2b60 0x401793e4:0x3ffe2b80 0x4017958f:0x3ffe2ba0 0x40179e45:0x3ffe2c20 0x4017a003:0x3ffe2c90 0x401815cf:0x3ffe2cd0 0x40182d45:0x3ffe2d20 0x40183381:0x3ffe2d60 0x401342f2:0x3ffe2da0 0x40134c5a:0x3ffe2dc0 0x40128971:0x3ffe2e10 0x4012a7e7:0x3ffe2e30 
01:46:05.354 -> 
01:46:05.354 -> 
01:46:05.354 -> 
01:46:05.354 -> 
01:46:05.354 -> ELF file SHA256: 0000000000000000
01:46:05.354 -> 
01:46:05.354 -> Rebooting...
01:46:05.354 -> ets Jun  8 2016 00:22:57
01:46:05.354 -> 
01:46:05.354 -> rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
01:46:05.354 -> configsip: 0, SPIWP:0xee
01:46:05.354 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
01:46:05.354 -> mode:DIO, clock div:1
01:46:05.354 -> load:0x3fff0030,len:1344
01:46:05.354 -> load:0x40078000,len:13864
01:46:05.354 -> load:0x40080400,len:3608
01:46:05.354 -> entry 0x400805f0
01:46:05.907 -> [�⸮⸮mum⸮⸮⸮⸮2-hal-cpu.c:214] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz
01:46:05.975 -> [    58][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 0 - WIFI_READY
01:46:06.013 -> [    85][I][RMaker.cpp:14] event_handler(): RainMaker Initialised.
01:46:06.013 -> 
01:46:06.013 -> Chip ID:  12913848 Service Name: ESP32
01:46:06.013 -> 
01:46:06.013 -> Starting ESP-RainMaker
01:46:06.013 -> [    89][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 33 - PROV_INIT
01:46:06.013 -> [    93][I][WiFiProv.cpp:149] beginProvision(): Already Provisioned
01:46:06.013 -> [    98][I][WiFiProv.cpp:153] beginProvision(): Attempting connect to AP: Stark
01:46:06.013 -> 
01:46:06.089 -> [   195][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 2 - STA_START
01:46:06.127 -> [   196][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 34 - PROV_DEINIT
01:46:06.127 -> [   212][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Living Room TV, Param Name : Power, Val : false
01:46:06.127 -> [   212][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Living Room Cove Light, Param Name : Power, Val : false
01:46:06.165 -> [   222][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Living Room Chandelier, Param Name : Power, Val : false
01:46:06.165 -> [   233][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Dining Room Chandelier, Param Name : Power, Val : false
01:46:06.165 -> [   243][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Kitchen Chandelier, Param Name : Power, Val : false
01:46:06.165 -> [   254][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Outside Profile Light, Param Name : Power, Val : false
01:46:06.201 -> [   264][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Curtain Open, Param Name : Power, Val : false
01:46:06.201 -> [   274][I][RMakerDevice.cpp:163] updateAndReportParam(): Device : Curtain Close, Param Name : Power, Val : false
01:46:06.201 -> [   279][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 4 - STA_CONNECTED
01:46:06.201 -> 
01:46:06.201 -> Connected to Wi-Fi!
01:46:06.745 -> [   846][D][WiFiGeneric.cpp:929] _eventCallback(): Arduino Event: 7 - STA_GOT_IP
01:46:06.783 -> [   846][D][WiFiGeneric.cpp:991] _eventCallback(): STA IP: 192.168.68.109, MASK: 255.255.255.0, GW: 192.168.68.1
maxakash commented 1 year ago

This is the error I got after lot of trying

02:35:05.748 -> E (51329) wifi_prov_mgr: STA Disconnected
02:35:05.781 -> E (51329) esp-tls-mbedtls: mbedtls_ssl_handshake returned -0x2880
02:35:05.781 -> E (51329) wifi_prov_mgr: Disconnect reason : 200
02:35:05.781 -> E (51329) esp-tls: Failed to open new connection
02:35:05.781 -> E (51336) TRANSPORT_BASE: Failed to open a new connection
02:35:05.781 -> E (51351) MQTT_CLIENT: Error transport connect
02:35:05.781 -> E (51352) esp_mqtt_glue: MQTT_EVENT_ERROR
02:35:05.781 -> E (51352) wifi:sta is connecting, return error
02:35:08.820 -> E (54403) wifi_prov_mgr: STA Disconnected
02:35:08.820 -> E (54403) wifi_prov_mgr: Disconnect reason : 15
02:35:08.856 -> E (54403) wifi_prov_mgr: STA Auth Error
02:35:20.801 -> E (66353) esp-tls: [sock=48] connect() error: Host is unreachable
02:35:20.801 -> E (66353) esp-tls: Failed to open new connection
02:35:20.801 -> E (66353) TRANSPORT_BASE: Failed to open a new connection
02:35:20.801 -> E (66357) MQTT_CLIENT: Error transport connect
02:35:20.801 -> E (66361) esp_mqtt_glue: MQTT_EVENT_ERROR
02:35:35.806 -> E (81365) esp-tls: [sock=48] connect() error: Host is unreachable
02:35:35.806 -> E (81366) esp-tls: Failed to open new connection
02:35:35.806 -> E (81366) TRANSPORT_BASE: Failed to open a new connection
02:35:35.806 -> E (81370) MQTT_CLIENT: Error transport connect
02:35:35.806 -> E (81374) esp_mqtt_glue: MQTT_EVENT_ERROR
maxakash commented 1 year ago

It worked after 20-30 tries.