Failed at "confirming node association" (IDFGH-8955) (MEGH-4102)

[FlynnMa]

Answers checklist.

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

IDF version.

v4.4

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-C3-DevKitM-1

Power Supply used.

USB

What is the expected behavior?

confirming user-node associate success

What is the actual behavior?

On my android app, I can see it failed with message

1. "Failed to confirm node assocation"
2. "Reset your board to factory defaults and retry"

Steps to reproduce.

1. checkout esp-idf tag version v4.4
2. build esp-idf
3. find an example code from esp-rainmaker
4. build and run the app
5. start android app to add the device

Debug Logs.

I (2610) app_wifi: * 1 - Starting provisioning
D (2615) esp_netif_objects: esp_netif_add_to_list 0x3fcafb90
D (2621) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
D (2630) nvs: nvs_open_from_partition rmaker_creds 0
D (2635) nvs: nvs_get_str_or_blob random
D (2639) nvs: nvs_get_str_or_blob random
D (2643) nvs: nvs_close 9
I (2645) app_wifi: * 1 - pop 40c78602

D (2650) nvs: nvs_set opmode 1 1
I (2654) phy_init: phy_version 907,3369105-dirty,Dec  3 2021,14:55:12
D (2660) phy_init: loading PHY init data from application binary
D (2666) nvs: nvs_open_from_partition phy 0
D (2671) phy_init: esp_phy_load_cal_data_from_nvs: failed to open NVS namespace (0x1102)
W (2679) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
D (2688) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (2695) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (2702) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (2709) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (2716) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (2723) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit

More Information.

No response

[sanketwadekar]

HI @FlynnMa, Can you include the device side "Error logs" that you get when "user node association" fails. I've tried the switch example on idf v4.4 tag (8153bfe4125e6a608abccf1561fd10285016c90a) and did not see any errors while provisioning. Have you tried provisioning after erasing your flash using idf.py erase-flash ?

[FlynnMa]

Hi @sanketwadekar,

As you can see, I already attached all logs with level at debug.

I tried with erase-flash and everything I can imagion

[shahpiyushv]

@FlynnMa , considering that the process has reached step 4 of provisioning, there should be some prints indicating that some user id and secret key was received from the phone app, followed by SSID and passphrase and then wifi connection success. Thereafter there should be messages indicating claiming/mqtt error or some crash, because of which the step 4 failed. The full logs can help understand that, but we do not see any of this in the logs you shared.

[FlynnMa]

@shahpiyushv ,

I don't see that kind of error, but do you think bellow warnning might related?

W (2679) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration

[shahpiyushv]

@FlynnMa , these logs surely are incomplete. Even the timestamps are till 2723, which means 2.7 seconds since bootup. There must be some QR code you scanned, right? I do not see that in the logs here. The phy_init warning you mentioned may result in failure of Wi-Fi connection itself, but we see that your node has gone beyond the "Confirming Wi-Fi Connection" step, which means that the connection itself went through fine.

[FlynnMa]

@shahpiyushv please check this,

As you mentioned QR code, I checked my QR setting by idf.py menuconfig, it is enabled. Don't know why it is not showing up.

Most features was fine until my recent upgrade, All I have done is just checkout v4.4, changed #include <include/esp_wifi.h> to #include <esp_wifi.h>

[shahpiyushv]

@FlynnMa , where exactly did you do the change from #include <include/esp_wifi.h> to #include <esp_wifi.h>?

When you captured the above log, did you do a manual provisioning (i.e. without QR code) and provided the pop (a0df7e8b) as mentioned in your log? Did it still proceed till step 4 and yet not print any logs after the efuse logs above?

Using git status command, can you ensure that you have no custom changes? Moreover, can you ensure that all the submodules in esp-idf and esp-rainmaker are in sync using git submodule update --init --recursive?

[FlynnMa]

Today I see this error. it is replicable by my side

[shahpiyushv]

@FlynnMa , did this eventually work for you? The latest logs point to some hardware issue rather than a software issue since the device itself has disconnected from the serial terminal. Also, we never really got any logs for the original issue which talks about failure at step 4 of provisioning.