espressif / esp-rainmaker

ESP RainMaker Agent for firmware development
Apache License 2.0
452 stars 152 forks source link

ESP32-S3 Error 261. Failed to get PoP from NVS, Please perform Claiming (MEGH-3185) #112

Open eos1d3 opened 2 years ago

eos1d3 commented 2 years ago

ESP-IDF version: Release 4.4 ESP device: ESP32-S3 LED_Light example

There are errors after Assisted Claiming:

I (742) esp_claim: Initialising Assisted Claiming. This may take time.
W (752) esp_claim: Generating the private key. This may take time.
I (18292) esp_rmaker_node: Node ID ----- 7CDFA1E121C4
I (18302) esp_rmaker_ota: OTA state = 2
I (18302) esp_rmaker_ota_using_params: OTA enabled with Params
I (18302) esp_rmaker_time_service: Time service enabled
I (18302) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
I (18322) app_insights: Enable CONFIG_ESP_INSIGHTS_ENABLED to get Insights.
I (18322) esp_rmaker_core: Starting RainMaker Work Queue task
I (18332) esp_rmaker_work_queue: RainMaker Work Queue task started.
W (18332) BT_INIT: esp_bt_mem_release not implemented, return OK
I (18332) esp_claim: Waiting for assisted claim to finish.
I (18342) wifi_prov_scheme_ble: BT memory released
I (18352) app_wifi: Starting provisioning
E (18362) app_wifi: Error: 261. Failed to get PoP from NVS, Please perform Claiming.
E (18362) app_main: Could not start Wifi. Aborting!!!

BTW, there are some warnings during compilation:

warning: 'portENTER_CRITICAL_NESTED' is deprecated 
warning: 'portEXIT_CRITICAL_NESTED' is deprecated
warning: 'vPortCPUInitializeMutex' is deprecated 
warning: passing argument 2 of 'esp_rmaker_post_event' discards 'const' qualifier from pointer target type 

PS: Try using rainmaker.py claim to write claiming dat to the chip, it seems the data is ignored and problem is still the same.

shahpiyushv commented 2 years ago

@eos1d3 , I just tried this with esp idf v4.4 release and esp-rainmaker master branch on an esp32s3. Erased the flashed and then used idf.py flash monitor. I get this output

I (697) esp_claim: Initialising Assisted Claiming. This may take time.
I (1007) esp_claim: Private key already exists. No need to re-initialise it.
I (1057) esp_rmaker_node: Node ID ----- 84F7038005F4
I (1057) esp_rmaker_ota: OTA state = 2
I (1057) esp_rmaker_ota_using_params: OTA enabled with Params
I (1057) esp_rmaker_time_service: Time service enabled
I (1067) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
I (1077) app_insights: Enable CONFIG_ESP_INSIGHTS_ENABLED to get Insights.
I (1077) esp_rmaker_core: Starting RainMaker Work Queue task
I (1087) esp_rmaker_work_queue: RainMaker Work Queue task started.
W (1087) BT_INIT: esp_bt_mem_release not implemented, return OK
I (1097) esp_claim: Waiting for assisted claim to finish.
I (1107) wifi_prov_scheme_ble: BT memory released
I (1107) app_wifi: Starting provisioning
I (1117) phy_init: phy_version 302,3ddfab3,Dec  3 2021,14:39:12
I (1167) wifi:mode : sta (84:f7:03:80:05:f4)
I (1177) wifi:enable tsf
W (1177) BT_INIT: esp_bt_controller_mem_release not implemented, return OK
I (1177) BT_INIT: BT controller compile version [6881869]
I (1177) BT_INIT: Bluetooth MAC: 84:f7:03:80:05:f6

I (1187) protocomm_nimble: BLE Host Task Started
I (1197) NimBLE: GAP procedure initiated: stop advertising.

I (1197) NimBLE: GAP procedure initiated: advertise; 
I (1207) NimBLE: disc_mode=2
I (1207) NimBLE:  adv_channel_map=0 own_addr_type=0 adv_filter_policy=0 adv_itvl_min=256 adv_itvl_max=256
I (1217) NimBLE: 

I (1227) wifi_prov_mgr: Provisioning started with service name : PROV_77d8bb 
I (1227) app_wifi: Provisioning started
I (1237) esp_rmaker_local: Event 1
I (1237) app_wifi: Scan this QR code from the ESP RainMaker phone app for Provisioning.

  █▀▀▀▀▀█ ▄▄█   ▄█▄▄█▀▄▄▀█▄ █▀▀▀▀▀█   
  █ ███ █ ▀▄  ▄  ██▀█▄  ▀▄▄ █ ███ █   
  █ ▀▀▀ █ █▀█ █▀███ █▄ █▀▀█ █ ▀▀▀ █   
  ▀▀▀▀▀▀▀ █ █▄▀ ▀ ▀▄▀ █▄█ █ ▀▀▀▀▀▀▀   
  █▀ ▀ ▄▀▀▄▄ ██▀▄▀█▄  ▄█ ▀ ▄█▀▀▄▀▀▄   
  ▀██▀▄▀▀█▀▄▄██▄█▄ ▀██▀█ ▄▄ ▄█    █   
   ▄▀ █ ▀█▄▄▀█ ▀▀  ▀█▄ █▄█▄▀█ ▄▄ ▀█   
  █▄██▀ ▀ ▄▀▀█ █   █▀  █▀▀█▀  ▄█ █▄   
   █▄▀▄█▀ ▄▄▄ █▄▄ █▀█▀██  ▄█▀ ▀▀▄ ▀   
  ▀▄█▄██▀ █  ▀█▀▀ ▀█▄▄▀██ ▄ █▄▄▄ ▀█   
   ▄▄█▀█▀▀▄ █▄ ▀▀▀█▄▀▀▀▀▀▄█ ▄▄ █ ▄▄   
  ▀██▀▄▄▀ ▀▄▀  █▄▄▀▀▀▀█▄▀▄▀█  ▄▄ ▀▀   
  ▀  ▀ ▀▀ ██ ▄█▀  ▀▀▀▄▀██ █▀▀▀█▀ ▄▄   
  █▀▀▀▀▀█ ▀█▄ █▄█ ▀█ ▄ █▀▀█ ▀ ██ █    
  █ ███ █ ▄█▄▀▀▄█ █▀▀▀ ██ ▀████▀ ▄█   
  █ ▀▀▀ █ ▄█ ▄▄▀▀▄▀█▀▄▄▄█ ▀  ▄▀█▀▀▀   
  ▀▀▀▀▀▀▀ ▀    ▀▀    ▀ ▀  ▀ ▀ ▀▀ ▀    

I (1437) app_wifi: If QR code is not visible, copy paste the below URL in a browser.
https://rainmaker.espressif.com/qrcode.html?data={"ver":"v1","name":"PROV_77d8bb","pop":"4eaddc87","transport":"ble"}
I (1457) app_wifi: Provisioning Started. Name : PROV_77d8bb, POP : 4eaddc87

So, it is hard to tell what the problem could be. Can you double check that your flash was erased before you flashed the firmware. Can you double check that your partition table is right? It is printed on boot-up

I (46) boot: Partition Table:
I (49) boot: ## Label            Usage          Type ST Offset   Length
I (57) boot:  0 sec_cert         unknown          3f 06 0000d000 00003000
I (64) boot:  1 nvs              WiFi data        01 02 00010000 00006000
I (72) boot:  2 otadata          OTA data         01 00 00016000 00002000
I (79) boot:  3 phy_init         RF data          01 01 00018000 00001000
I (87) boot:  4 ota_0            OTA app          00 10 00020000 00190000
I (94) boot:  5 ota_1            OTA app          00 11 001b0000 00190000
I (101) boot:  6 fctry            WiFi data        01 02 00340000 00006000
I (109) boot: End of partition table
eos1d3 commented 2 years ago

The board I am using is ESP32-S3-DevKitC-1, ordered from Espressif China directly.

This is my partition table:

I (55) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 sec_cert         unknown          3f 06 0000d000 00003000
I (74) boot:  1 nvs              WiFi data        01 02 00010000 00006000
I (81) boot:  2 otadata          OTA data         01 00 00016000 00002000
I (89) boot:  3 phy_init         RF data          01 01 00018000 00001000
I (96) boot:  4 ota_0            OTA app          00 10 00020000 00190000
I (104) boot:  5 ota_1            OTA app          00 11 001b0000 00190000
I (111) boot:  6 fctry            WiFi data        01 02 00340000 00006000
I (119) boot: End of partition table

I do erase-flash not just once, but the problem is the same. Just tried again with new setup and still got the same problem.

I (692) wifi_init: rx ba win: 6
I (702) wifi_init: tcpip mbox: 32
I (702) wifi_init: udp mbox: 6
I (702) wifi_init: tcp mbox: 6
I (712) wifi_init: tcp tx win: 5744
I (712) wifi_init: tcp rx win: 5744
I (722) wifi_init: tcp mss: 1440
I (722) wifi_init: WiFi IRAM OP enabled
I (722) wifi_init: WiFi RX IRAM OP enabled
I (742) esp_rmaker_work_queue: Work Queue created.
I (742) esp_claim: Initialising Assisted Claiming. This may take time.
W (752) esp_claim: Generating the private key. This may take time.
I (4772) esp_rmaker_node: Node ID ----- 7CDFA1E121C4
I (4782) esp_rmaker_ota: OTA state = 2
I (4782) esp_rmaker_ota_using_params: OTA enabled with Params
I (4782) esp_rmaker_time_service: Time service enabled
I (4782) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
I (4792) app_insights: Enable CONFIG_ESP_INSIGHTS_ENABLED to get Insights.
I (4802) esp_rmaker_core: Starting RainMaker Work Queue task
I (4802) esp_rmaker_work_queue: RainMaker Work Queue task started.
W (4802) BT_INIT: esp_bt_mem_release not implemented, return OK
I (4812) esp_claim: Waiting for assisted claim to finish.
I (4822) wifi_prov_scheme_ble: BT memory released
I (4832) app_wifi: Starting provisioning
E (4842) app_wifi: Error: 261. Failed to get PoP from NVS, Please perform Claiming.
E (4842) app_main: Could not start Wifi. Aborting!!!

I found other has the same problem from ESP32.com: https://www.esp32.com/viewtopic.php?f=25&t=25649

eos1d3 commented 2 years ago

My board shall be ESP32-S3-DevKitC-1-N32R8V (32MB Flash, 8MB PSRAM)

Can the large flash size cause the problem? See the two warnings below:

I (491) heap_init: Initializing. RAM available for dynamic allocation:
I (498) heap_init: At 3FCA1B38 len 0003E4C8 (249 KiB): D/IRAM
I (505) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (511) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (517) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (525) spi_flash: detected chip: mxic
W (528) spi_flash: Detected flash size > 16 MB, but access beyond 16 MB is not supported for this flash model yet.
I (539) spi_flash: flash io: dio
W (543) spi_flash: Detected size(32768k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (557) sleep: Configure to isolate all GPIO pins in sleep state
I (563) sleep: Enable automatic switching of GPIO sleep configuration``

PS: The page size of this flash may be different from normal 4-8MB flash as it is much larger. I do not know if this can be the problem.

shahpiyushv commented 2 years ago

@eos1d3 The flash related warning just says "access beyond 16 MB is not supported for this flash model" which I suppose should be fine since the partition table is for 4MB. Can you enable debug logs and see what additional information it gives? You can do so using: idf.py menuconfig -> Component config -> Log output -> Default log verbosity -> Debug

eos1d3 commented 2 years ago

Please check if the log is enough. Thanks!

Executing action: monitor
Serial port /dev/cu.usbserial-14130
Connecting....
Detecting chip type... ESP32-S3
Running idf_monitor in directory /Users/andy/esp/esp-rainmaker/examples/led_light
Executing "/Users/andy/.espressif/python_env/idf4.4_py3.9_env/bin/python /Users/andy/esp/esp-idf/tools/idf_monitor.py -p /dev/cu.usbserial-14130 -b 115200 --toolchain-prefix xtensa-esp32s3-elf- --target esp32s3 /Users/andy/esp/esp-rainmaker/examples/led_light/build/led_light.elf -m '/Users/andy/.espressif/python_env/idf4.4_py3.9_env/bin/python' '/Users/andy/esp/esp-idf/tools/idf.py'"...
--- idf_monitor on /dev/cu.usbserial-14130 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x18 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
Octal Flash Mode Enabled
For OPI Flash, Use Default Flash Boot Mode
mode:SLOW_RD, clock div:1
load:0x3fcd0108,len:0x1658
load:0x403b6000,len:0xb7c
load:0x403ba000,len:0x2f58
entry 0x403b6248
I (32) boot: ESP-IDF v4.4-172-g730ca0ea43 2nd stage bootloader
I (32) boot: compile time 17:23:14
I (32) boot: chip revision: 0
I (35) boot.esp32s3: Boot SPI Speed : 80MHz
I (40) boot.esp32s3: SPI Mode       : SLOW READ
I (45) boot.esp32s3: SPI Flash Size : 4MB
I (50) boot: Enabling RNG early entropy source...
I (55) boot: Partition Table:
I (59) boot: ## Label            Usage          Type ST Offset   Length
I (66) boot:  0 sec_cert         unknown          3f 06 0000d000 00003000
I (74) boot:  1 nvs              WiFi data        01 02 00010000 00006000
I (81) boot:  2 otadata          OTA data         01 00 00016000 00002000
I (89) boot:  3 phy_init         RF data          01 01 00018000 00001000
I (96) boot:  4 ota_0            OTA app          00 10 00020000 00190000
I (104) boot:  5 ota_1            OTA app          00 11 001b0000 00190000
I (111) boot:  6 fctry            WiFi data        01 02 00340000 00006000
I (119) boot: End of partition table
I (123) boot: No factory image, trying OTA 0
I (128) esp_image: segment 0: paddr=00020020 vaddr=3c0f0020 size=3fa0ch (260620) map
I (198) esp_image: segment 1: paddr=0005fa34 vaddr=3fc97650 size=005e4h (  1508) load
I (198) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=e1560h (922976) map
I (420) esp_image: segment 3: paddr=00141588 vaddr=3fc97c34 size=04400h ( 17408) load
I (425) esp_image: segment 4: paddr=00145990 vaddr=40374000 size=13650h ( 79440) load
I (448) esp_image: segment 5: paddr=00158fe8 vaddr=50000000 size=00010h (    16) load
I (456) boot: Loaded app from partition at offset 0x20000
I (481) boot: Set actual ota_seq=1 in otadata[0]
I (481) boot: Disabling RNG early entropy source...
I (492) cpu_start: Pro cpu up.
I (492) cpu_start: Starting app cpu, entry point is 0x403753e4
0x403753e4: call_start_cpu1 at /Users/andy/esp/esp-idf/components/esp_system/port/cpu_start.c:160

I (0) cpu_start:(4Ap) efuu :pInS
_BLK2__DATA4_REG is used 2 bits starting with 0 bit
D (500) efuse: In EFUSE_BLK2__DATA4_REG is used 8 bits starting with 13 bit
D (515) clk: RTC_SLOW_CLK calibration value: 3991040
I (523) cpu_start: Pro cpu start user code
I (524) cpu_start: cpu freq: 160000000
I (524) cpu_start: Application information:
I (526) cpu_start: Project name:     led_light
I (531) cpu_start: App version:      1.0
I (536) cpu_start: Compile time:     Feb 17 2022 17:23:19
I (542) cpu_start: ELF file SHA256:  ea58a1bd70274bca...
I (548) cpu_start: ESP-IDF:          v4.4-172-g730ca0ea43
D (554) memory_layout: Checking 5 reserved memory ranges:
D (560) memory_layout: Reserved memory range 0x3fc84000 - 0x3fc97650
D (566) memory_layout: Reserved memory range 0x3fc97650 - 0x3fca1d48
D (572) memory_layout: Reserved memory range 0x3fceee34 - 0x3fcf0000
D (579) memory_layout: Reserved memory range 0x40374000 - 0x40387650
0x40374000: _WindowOverflow4 at /Users/andy/esp/esp-idf/components/freertos/port/xtensa/xtensa_vectors.S:1736

D (585) memory_layout: Reserved memory range 0x600fe000 - 0x600fe000
D (592) memory_layout: Building list of available memory regions:
D (598) memory_layout: Available memory region 0x3fca1d48 - 0x3fcb0000
D (604) memory_layout: Available memory region 0x3fcb0000 - 0x3fcc0000
D (611) memory_layout: Available memory region 0x3fcc0000 - 0x3fcd0000
D (618) memory_layout: Available memory region 0x3fcd0000 - 0x3fce0000
D (624) memory_layout: Available memory region 0x3fce0000 - 0x3fceee34
D (631) memory_layout: Available memory region 0x3fcf0000 - 0x3fcf8000
D (637) memory_layout: Available memory region 0x600fe000 - 0x60100000
I (644) heap_init: Initializing. RAM available for dynamic allocation:
D (651) heap_init: New heap initialised at 0x3fca1d48
I (656) heap_init: At 3FCA1D48 len 0003E2B8 (248 KiB): D/IRAM
I (663) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
D (670) heap_init: New heap initialised at 0x3fcf0000
I (675) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
D (681) heap_init: New heap initialised at 0x600fe000
I (686) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
D (693) FLASH_HAL: extra_dummy: 0
D (696) spi_flash: trying chip: issi
D (699) spi_flash: trying chip: gd
D (703) spi_flash: trying chip: mxic
I (706) spi_flash: detected chip: mxic
W (711) spi_flash: Detected flash size > 16 MB, but access beyond 16 MB is not supported for this flash model yet.
I (722) spi_flash: flash io: dio
W (726) spi_flash: Detected size(32768k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
D (739) cpu_start: calling init function: 0x420c4a00
0x420c4a00: _GLOBAL__sub_I___cxa_get_globals_fast at /builds/idf/crosstool-NG/.build/HOST-x86_64-apple-darwin12/xtensa-esp32s3-elf/src/gcc/libstdc++-v3/libsupc++/eh_globals.cc:145

D (744) cpu_start: calling init function: 0x4208e01c
0x4208e01c: esp_ds_conn_lock at /Users/andy/esp/esp-idf/components/mbedtls/port/esp_ds/esp_rsa_sign_alt.c:59

D (749) cpu_start: calling init function: 0x420539fc
0x420539fc: s_set_default_wifi_log_level at /Users/andy/esp/esp-idf/components/esp_wifi/src/wifi_init.c:65

D (754) cpu_start: calling init function: 0x42050714
0x42050714: esp_reset_reason_init at /Users/andy/esp/esp-idf/components/esp_system/port/soc/esp32s3/reset_reason.c:67

D (759) cpu_start: calling init function: 0x42046624
0x42046624: esp_ipc_init at /Users/andy/esp/esp-idf/components/esp_ipc/src/esp_ipc.c:105

D (765) cpu_start: calling init function: 0x42002de0
0x42002de0: esp_ota_init_app_elf_sha256 at /Users/andy/esp/esp-idf/components/app_update/esp_app_desc.c:68

D (769) intr_alloc: Connected src 59 to int 2 (cpu 0)
I (774) sleep: Configure to isolate all GPIO pins in sleep state
I (781) sleep: Enable automatic switching of GPIO sleep configuration
I (789) coexist: coexist rom version e7ae62f
D (794) intr_alloc: Connected src 79 to int 3 (cpu 0)
I (798) cpu_start: Starting scheduler on PRO CPU.
D (804) intr_alloc: Connected src 57 to int 9 (cpu 0)
D (804) intr_alloc: Connected src 80 to int 2 (cpu 1)
I (814) cpu_start: Starting scheduler on APP CPU.
D (814) intr_alloc: Connected src 58 to int 3 (cpu 1)
D (824) heap_init: New heap initialised at 0x3fce0000
D (824) intr_alloc: Connected src 52 to int 12 (cpu 0)
D (834) rmt: rmt_source_clk_hz: 80000000

D (834) rmt: Rmt Tx Channel 0|Gpio 48|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33
D (844) intr_alloc: Connected src 40 to int 13 (cpu 0)
D (844) rmt: RMT translator init done
D (854) intr_alloc: Connected src 16 to int 17 (cpu 0)
I (854) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 
D (864) partition: Loading the partition table
D (874) partition: Partition table MD5 verified
D (884) esp_netif_lwip: LwIP stack has been initialized
D (884) esp_netif_lwip: esp-netif has been successfully initialized
D (884) event: running task for loop 0x3fce262c
D (894) event: created task for loop 0x3fce262c
D (894) event: created event loop 0x3fce262c
D (904) esp_netif_objects: esp_netif_add_to_list 0x3fce363c
D (904) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 1)
I (914) pp: pp rom version: e7ae62f
I (914) net80211: net80211 rom version: e7ae62f
D (924) nvs: nvs_open_from_partition misc 1
I (944) wifi:wifi driver task: 3fce60b4, prio:23, stack:6656, core=0
I (944) system_api: Base MAC address is not set
I (944) system_api: read default base MAC address from EFUSE
D (944) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit
D (954) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit
D (964) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit
D (964) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit
D (974) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit
D (984) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit
D (984) nvs: nvs_open_from_partition nvs.net80211 1
D (994) nvs: nvs_get opmode 1
D (994) nvs: nvs_get_str_or_blob sta.ssid
D (1004) nvs: nvs_get sta.authmode 1
D (1004) nvs: nvs_get_str_or_blob sta.pswd
D (1004) nvs: nvs_get_str_or_blob sta.pmk
D (1014) nvs: nvs_get sta.chan 1
D (1014) nvs: nvs_get auto.conn 1
D (1014) nvs: nvs_get bssid.set 1
D (1024) nvs: nvs_get_str_or_blob sta.bssid
D (1024) nvs: nvs_get sta.lis_intval 2
D (1034) nvs: nvs_get sta.phym 1
D (1034) nvs: nvs_get sta.phybw 1
D (1034) nvs: nvs_get_str_or_blob sta.apsw
D (1044) nvs: nvs_get_str_or_blob sta.apinfo
D (1044) nvs: nvs_get sta.scan_method 1
D (1054) nvs: nvs_get sta.sort_method 1
D (1054) nvs: nvs_get sta.minrssi 1
D (1054) nvs: nvs_get sta.minauth 1
D (1064) nvs: nvs_get sta.pmf_e 1
D (1064) nvs: nvs_get sta.pmf_r 1
D (1064) nvs: nvs_get sta.btm_e 1
D (1074) nvs: nvs_get sta.rrm_e 1
D (1074) nvs: nvs_get sta.mbo_e 1
D (1074) nvs: nvs_get_str_or_blob ap.ssid
D (1084) nvs: nvs_get_str_or_blob ap.passwd
D (1084) nvs: nvs_get_str_or_blob ap.pmk
D (1094) nvs: nvs_get ap.chan 1
D (1094) nvs: nvs_get ap.authmode 1
D (1094) nvs: nvs_get ap.hidden 1
D (1104) nvs: nvs_get ap.max.conn 1
D (1104) nvs: nvs_get bcn.interval 2
D (1104) nvs: nvs_get ap.phym 1
D (1114) nvs: nvs_get ap.phybw 1
D (1114) nvs: nvs_get ap.sndchan 1
D (1114) nvs: nvs_get ap.pmf_e 1
D (1124) nvs: nvs_get ap.pmf_r 1
D (1124) nvs: nvs_get ap.p_cipher 1
D (1124) nvs: nvs_get lorate 1
D (1134) nvs: nvs_get_str_or_blob country
D (1134) nvs: nvs_get ap.ftm_r 1
D (1134) nvs: nvs_set ap.sndchan 1 1
I (1144) wifi:wifi firmware version: 7679c42
I (1144) wifi:wifi certification version: v7.0
I (1154) wifi:config NVS flash: enabled
I (1154) wifi:config nano formating: disabled
I (1154) wifi:Init data frame dynamic rx buffer num: 32
I (1164) wifi:Init management frame dynamic rx buffer num: 32
I (1164) wifi:Init management short buffer num: 32
I (1174) wifi:Init dynamic tx buffer num: 32
I (1174) wifi:Init static tx FG buffer num: 2
I (1184) wifi:Init static rx buffer size: 1600
I (1184) wifi:Init static rx buffer num: 10
I (1184) wifi:Init dynamic rx buffer num: 32
I (1194) wifi_init: rx ba win: 6
I (1194) wifi_init: tcpip mbox: 32
I (1204) wifi_init: udp mbox: 6
I (1204) wifi_init: tcp mbox: 6
I (1204) wifi_init: tcp tx win: 5744
I (1214) wifi_init: tcp rx win: 5744
I (1214) wifi_init: tcp mss: 1440
I (1224) wifi_init: WiFi IRAM OP enabled
I (1224) wifi_init: WiFi RX IRAM OP enabled
D (1244) nvs: nvs_open_from_partition rmaker_creds 0
D (1244) esp_rmaker_fctry: NVS open for fctry rmaker_creds node_id failed with error 4354
I (1244) esp_rmaker_work_queue: Work Queue created.
D (1244) nvs: nvs_open_from_partition rmaker_creds 0
D (1254) esp_rmaker_fctry: NVS open for fctry rmaker_creds client_key failed with error 4354
I (1264) esp_claim: Initialising Assisted Claiming. This may take time.
D (1284) nvs: nvs_open_from_partition rmaker_creds 0
D (1284) esp_rmaker_fctry: NVS open for fctry rmaker_creds client_key failed with error 4354
D (1284) esp_claim: Seeding the random number generator.
D (1294) gdma: new group (0) at 0x3fcee098
D (1294) gdma: new pair (0,0) at 0x3fcee0d4
D (1294) gdma: new tx channel (0,0) at 0x3fcee070
D (1304) gdma: new rx channel (0,0) at 0x3fcee0f4
D (1314) gdma: tx channel (0,0), (1:16) bytes aligned, burst enabled
D (1314) gdma: rx channel (0,0), (1:16) bytes aligned, burst disabled
W (1324) esp_claim: Generating the private key. This may take time.
D (4404) esp_claim: Converting Private Key to PEM...
D (4414) nvs: nvs_open_from_partition rmaker_creds 1
D (4434) nvs: nvs_set_blob client_key 1675
D (4564) nvs: nvs_close 3
D (4564) nvs: nvs_open_from_partition rmaker_creds 0
D (4564) nvs: nvs_get_str_or_blob random
D (4564) esp_rmaker_fctry: Failed to read key random with error 4354 size 0
D (4564) nvs: nvs_close 4
D (4574) nvs: nvs_open_from_partition rmaker_creds 1
D (4574) nvs: nvs_set_blob random 64
D (4644) nvs: nvs_close 5
D (4644) nvs: nvs_open_from_partition user_mapping 0
D (4644) event: no handlers have been registered for event RMAKER_EVENT:1 posted to loop 0x3fce262c
I (4644) esp_rmaker_node: Node ID ----- 7CDFA1E121C4
D (4654) nvs: nvs_open_from_partition Light 0
D (4654) nvs: nvs_open_from_partition Light 1
D (4664) nvs: nvs_set_blob Name 5
D (4664) nvs: nvs_close 6
D (4664) esp_rmaker_device: Param Name added in Light
D (4674) esp_rmaker_device: Param Power added in Light
D (4674) esp_rmaker_device: Param Brightness added in Light
D (4684) esp_rmaker_device: Param Hue added in Light
D (4684) esp_rmaker_device: Param Saturation added in Light
I (4694) esp_rmaker_ota: OTA state = 2
D (4694) esp_rmaker_device: Param Status added in OTA
D (4704) esp_rmaker_device: Param Info added in OTA
D (4704) esp_rmaker_device: Param URL added in OTA
I (4714) esp_rmaker_ota_using_params: OTA enabled with Params
D (4714) nvs: nvs_open_from_partition rmaker_time 0
D (4724) nvs: nvs_open_from_partition rmaker_time 0
D (4724) esp_rmaker_device: Param TZ added in Time
D (4734) esp_rmaker_device: Param TZ-POSIX added in Time
I (4734) esp_rmaker_time_service: Time service enabled
I (4744) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
D (4754) nvs: nvs_open_from_partition rmaker_time 0
D (4754) nvs: nvs_open_from_partition Schedule 0
D (4764) nvs: nvs_open_from_partition Schedule 1
D (4764) nvs: nvs_set_blob Schedules 2
D (4774) nvs: nvs_close 7
D (4774) esp_rmaker_device: Param Schedules added in Schedule
D (4774) esp_rmaker_schedule: Scheduling Service Enabled
I (4784) app_insights: Enable CONFIG_ESP_INSIGHTS_ENABLED to get Insights.
I (4794) esp_rmaker_core: Starting RainMaker Work Queue task
I (4794) esp_rmaker_work_queue: RainMaker Work Queue task started.
D (4794) wifi_prov_mgr: execute_event_cb : 0
D (4804) event: no handlers have been registered for event RMAKER_EVENT:2 posted to loop 0x3fce262c
I (4804) esp_claim: Waiting for assisted claim to finish.
W (4814) BT_INIT: esp_bt_mem_release not implemented, return OK
I (4834) wifi_prov_scheme_ble: BT memory released
D (4834) event: running post WIFI_PROV_EVENT:0 with handler 0x420100fc and context 0x3fce35a4 on loop 0x3fce262c
0x420100fc: event_handler at /Users/andy/esp/esp-rainmaker/examples/common/app_wifi/app_wifi.c:115

D (4844) event: running post WIFI_PROV_EVENT:0 with handler 0x4200bfc8 and context 0x3fceb640 on loop 0x3fce262c
0x4200bfc8: esp_rmaker_user_mapping_event_handler at /Users/andy/esp/esp-rainmaker/components/esp_rainmaker/src/core/esp_rmaker_user_mapping.c:61

D (4854) event: running post WIFI_PROV_EVENT:0 with handler 0x4200dc44 and context 0x3fceb690 on loop 0x3fce262c
0x4200dc44: event_handler at /Users/andy/esp/esp-rainmaker/components/esp_rainmaker/src/core/esp_rmaker_claim.c:769

I (4864) app_wifi: Starting provisioning
D (4874) esp_netif_objects: esp_netif_add_to_list 0x3fcecdf8
D (4874) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
D (4884) nvs: nvs_open_from_partition rmaker_creds 0
D (4894) nvs: nvs_get_str_or_blob random
D (4894) app_wifi: Error 4354. Failed to read key random.
D (4904) nvs: nvs_close 8
D (4904) nvs: nvs_open_from_partition rmaker_creds 0
D (4904) nvs: nvs_get_str_or_blob random
D (4914) app_wifi: Error 4354. Failed to read key random.
D (4914) nvs: nvs_close 9
E (4924) app_wifi: Error: 261. Failed to get PoP from NVS, Please perform Claiming.
E (4924) app_main: Could not start Wifi. Aborting!!!

abort() was called at PC 0x42008ad0 on core 0
0x42008ad0: app_main at /Users/andy/esp/esp-rainmaker/examples/led_light/main/app_main.c:139 (discriminator 3)

Backtrace:0x40375ce6:0x3fcf47d00x4037e159:0x3fcf47f0 0x4038533a:0x3fcf4810 0x42008ad0:0x3fcf4880 0x420e1259:0x3fcf48c0 0x40381c0e:0x3fcf48e0 
0x40375ce6: panic_abort at /Users/andy/esp/esp-idf/components/esp_system/panic.c:402

0x4037e159: esp_system_abort at /Users/andy/esp/esp-idf/components/esp_system/esp_system.c:128

0x4038533a: abort at /Users/andy/esp/esp-idf/components/newlib/abort.c:46

0x42008ad0: app_main at /Users/andy/esp/esp-rainmaker/examples/led_light/main/app_main.c:139 (discriminator 3)

0x420e1259: main_task at /Users/andy/esp/esp-idf/components/freertos/port/port_common.c:129 (discriminator 2)

0x40381c0e: vPortTaskWrapper at /Users/andy/esp/esp-idf/components/freertos/port/xtensa/port.c:131

ELF file SHA256: ea58a1bd70274bca

Rebooting...
shahpiyushv commented 2 years ago

@eos1d3 , can you pull the latest esp-idf and esp-rainmaker and retry? This commit in esp-idf should help resolve this issue.

eos1d3 commented 2 years ago

@shahpiyushv I just made clean installation of IDF master and esp-rainmaker. Tested with led_light example and erase flash before flashing new binary. It gives the same problem. But I am seeing other warnings:

W (460) flash HPM: Enter HPM by reconfiguring dummy has not been fully tested
E (460) flash HPM: Flash high performance mode hasn't been supported

Warning: checksum mismatch between flashed and built applications. Checksum of built application is 01496fd2958f649a7881bca3d5fbca78d4e441c08c3b99d397610b2bce5ec171

And the same HPM error happens in blink example too. Does my board (ESP32-S3-DevKitC-1-N32R8V, 32MB Flash, 8MB PSRAM) has new EEPROM which is not yet supported?

The full log here:

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x18 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
Octal Flash Mode Enabled
For OPI Flash, Use Default Flash Boot Mode
mode:SLOW_RD, clock div:1
load:0x3fcd0110,len:0x18d0
load:0x403b6000,len:0xb70
load:0x403b9000,len:0x319c
entry 0x403b6240
I (33) boot: ESP-IDF v5.0-dev-2046-g5963de1caf 2nd stage bootloader
I (33) boot: compile time 11:40:55
I (33) boot: chip revision: 0
I (36) boot.esp32s3: Boot SPI Speed : 80MHz
I (41) boot.esp32s3: SPI Mode       : SLOW READ
I (47) boot.esp32s3: SPI Flash Size : 4MB
I (51) boot: Enabling RNG early entropy source...
I (57) boot: Partition Table:
I (60) boot: ## Label            Usage          Type ST Offset   Length
I (68) boot:  0 sec_cert         unknown          3f 06 0000d000 00003000
I (75) boot:  1 nvs              WiFi data        01 02 00010000 00006000
I (82) boot:  2 otadata          OTA data         01 00 00016000 00002000
I (90) boot:  3 phy_init         RF data          01 01 00018000 00001000
I (97) boot:  4 ota_0            OTA app          00 10 00020000 00190000
I (105) boot:  5 ota_1            OTA app          00 11 001b0000 00190000
I (112) boot:  6 fctry            WiFi data        01 02 00340000 00006000
I (120) boot: End of partition table
I (124) boot: No factory image, trying OTA 0
I (129) esp_image: segment 0: paddr=00020020 vaddr=3c0e0020 size=3ed6ch (257388) map
I (198) esp_image: segment 1: paddr=0005ed94 vaddr=3fc979d0 size=01284h (  4740) load
I (200) esp_image: segment 2: paddr=00060020 vaddr=42000020 size=dce00h (904704) map
I (417) esp_image: segment 3: paddr=0013ce28 vaddr=3fc98c54 size=03b90h ( 15248) load
I (421) esp_image: segment 4: paddr=001409c0 vaddr=40374000 size=139c4h ( 80324) load
I (444) esp_image: segment 5: paddr=0015438c vaddr=50000000 size=00010h (    16) load
I (453) boot: Loaded app from partition at offset 0x20000
I (481) boot: Set actual ota_seq=1 in otadata[0]
I (481) boot: Disabling RNG early entropy source...
W (492) flash HPM: Enter HPM by reconfiguring dummy has not been fully tested
E (492) flash HPM: Flash high performance mode hasn't been supported
I (495) cpu_start: Pro cpu up.
I (499) cpu_start: Starting app cpu, entry point is 0x40375428
0x40375428: call_start_cpu1 at /Users/andy/esp/esp-idf/components/esp_system/port/cpu_start.c:152

I (0) cpu_start: App cpu up.
I (521) cpu_start: Pro cpu start user code
I (521) cpu_start: cpu freq: 160000000 Hz
I (521) cpu_start: Application information:
I (524) cpu_start: Project name:     led_light
I (529) cpu_start: App version:      1.0
I (534) cpu_start: Compile time:     Mar 17 2022 11:40:47
I (540) cpu_start: ELF file SHA256:  1a73b8f421cba5f9...
I (546) cpu_start: ESP-IDF:          v5.0-dev-2046-g5963de1caf
I (552) heap_init: Initializing. RAM available for dynamic allocation:
I (559) heap_init: At 3FCA2588 len 0003DA78 (246 KiB): D/IRAM
I (566) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (572) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (579) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (586) spi_flash: detected chip: mxic
W (589) spi_flash: Detected flash size > 16 MB, but access beyond 16 MB is not supported for this flash model yet.
I (601) spi_flash: flash io: dio
W (604) spi_flash: Detected size(32768k) larger than the size in the binary image header(4096k). Using the size in the binary image header.
I (618) sleep: Configure to isolate all GPIO pins in sleep state
I (625) sleep: Enable automatic switching of GPIO sleep configuration
I (632) coexist: coexist rom version e7ae62f
I (637) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (659) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3 
I (679) pp: pp rom version: e7ae62f
I (679) net80211: net80211 rom version: e7ae62f
I (699) wifi:wifi driver task: 3fce60b8, prio:23, stack:6656, core=0
I (699) system_api: Base MAC address is not set
I (699) system_api: read default base MAC address from EFUSE
I (709) wifi:wifi firmware version: 1948a1c
I (709) wifi:wifi certification version: v7.0
I (709) wifi:config NVS flash: enabled
I (709) wifi:config nano formating: disabled
I (719) wifi:Init data frame dynamic rx buffer num: 32
I (719) wifi:Init management frame dynamic rx buffer num: 32
I (729) wifi:Init management short buffer num: 32
I (729) wifi:Init dynamic tx buffer num: 32
I (739) wifi:Init static tx FG buffer num: 2
I (739) wifi:Init static rx buffer size: 1600
I (739) wifi:Init static rx buffer num: 10
I (749) wifi:Init dynamic rx buffer num: 32
I (749) wifi_init: rx ba win: 6
I (759) wifi_init: tcpip mbox: 32
I (759) wifi_init: udp mbox: 6
I (759) wifi_init: tcp mbox: 6
I (769) wifi_init: tcp tx win: 5744
I (769) wifi_init: tcp rx win: 5744
I (779) wifi_init: tcp mss: 1440
I (779) wifi_init: WiFi IRAM OP enabled
I (779) wifi_init: WiFi RX IRAM OP enabled
I (799) esp_rmaker_work_queue: Work Queue created.
I (799) esp_claim: Initialising Assisted Claiming. This may take time.
W (809) esp_claim: Generating the private key. This may take time.
I (10319) esp_rmaker_node: Node ID ----- 7CDFA1E121C4
I (10329) esp_rmaker_ota: OTA state = 2
I (10329) esp_rmaker_ota_using_params: OTA enabled with Params
I (10329) esp_rmaker_time_service: Time service enabled
I (10329) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
I (10349) app_insights: Enable CONFIG_ESP_INSIGHTS_ENABLED to get Insights.
I (10349) esp_rmaker_core: Starting RainMaker Work Queue task
I (10359) esp_rmaker_work_queue: RainMaker Work Queue task started.
W (10359) BT_INIT: esp_bt_mem_release not implemented, return OK
I (10359) esp_claim: Waiting for assisted claim to finish.
I (10369) wifi_prov_scheme_ble: BT memory released
I (10379) app_wifi: Starting provisioning
E (10389) app_wifi: Error: 261. Failed to get PoP from NVS, Please perform Claiming.
E (10389) app_main: Could not start Wifi. Aborting!!!

abort() was called at PC 0x4200863c on core 0
0x4200863c: app_main at /Users/andy/esp/esp-rainmaker/examples/led_light/main/app_main.c:139 (discriminator 3)

Backtrace:0x40375d9a:0x3fcf39100x4037e245:0x3fcf3930 0x40385412:0x3fcf3950 0x4200863c:0x3fcf39c0 0x420dcaf9:0x3fcf3a00 0x40381cbe:0x3fcf3a20 
0x40375d9a: panic_abort at /Users/andy/esp/esp-idf/components/esp_system/panic.c:403

0x4037e245: esp_system_abort at /Users/andy/esp/esp-idf/components/esp_system/esp_system.c:135

0x40385412: abort at /Users/andy/esp/esp-idf/components/newlib/abort.c:46

0x4200863c: app_main at /Users/andy/esp/esp-rainmaker/examples/led_light/main/app_main.c:139 (discriminator 3)

0x420dcaf9: main_task at /Users/andy/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/port_common.c:127 (discriminator 2)

0x40381cbe: vPortTaskWrapper at /Users/andy/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:141

ELF file SHA256: 1a73b8f421cba5f9

Rebooting...
?ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0x18 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40375a40
0x40375a40: esp_restart_noos at /Users/andy/esp/esp-idf/components/esp_system/port/soc/esp32s3/system_internal.c:151 (discriminator 1)

SPIWP:0xee
Octal Flash Mode Enabled
For OPI Flash, Use Default Flash Boot Mode
mode:SLOW_RD, clock div:1
load:0x3fcd0110,len:0x18d0
load:0x403b6000,len:0xb70
load:0x403b9000,len:0x319c
entry 0x403b6240
shahpiyushv commented 2 years ago

@eos1d3 , have you checked if the nvs and wifi provisioning examples from esp-idf work fine on your board? Here are the pointers:

https://github.com/espressif/esp-idf/tree/master/examples/storage/nvs_rw_blob

https://github.com/espressif/esp-idf/tree/master/examples/storage/nvs_rw_value

https://github.com/espressif/esp-idf/tree/master/examples/provisioning/wifi_prov_mgr : try reboot after this and check if device reconnects.

eos1d3 commented 2 years ago

For nvs_rw_blob, after pressing boot button, the restart counter is always 0. Log is here:

I (33) boot: ESP-IDF v5.0-dev-2046-g5963de1caf 2nd stage bootloader
I (33) boot: compile time 15:27:14
I (33) boot: chip revision: 0
I (36) boot.esp32s3: Boot SPI Speed : 80MHz
I (41) boot.esp32s3: SPI Mode       : SLOW READ
I (47) boot.esp32s3: SPI Flash Size : 2MB
I (51) boot: Enabling RNG early entropy source...
I (57) boot: Partition Table:
I (60) boot: ## Label            Usage          Type ST Offset   Length
I (68) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (75) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (82) boot:  2 factory          factory app      00 00 00010000 00100000
I (90) boot: End of partition table
I (94) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=0915ch ( 37212) map
I (111) esp_image: segment 1: paddr=00019184 vaddr=3fc90f00 size=02b60h ( 11104) load
I (115) esp_image: segment 2: paddr=0001bcec vaddr=40374000 size=0432ch ( 17196) load
I (124) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=1bd70h (114032) map
I (155) esp_image: segment 4: paddr=0003bd98 vaddr=4037832c size=08bcch ( 35788) load
I (165) esp_image: segment 5: paddr=0004496c vaddr=50000000 size=00010h (    16) load
I (170) boot: Loaded app from partition at offset 0x10000
I (171) boot: Disabling RNG early entropy source...
W (185) flash HPM: Enter HPM by reconfiguring dummy has not been fully tested
E (185) flash HPM: Flash high performance mode hasn't been supported
I (189) cpu_start: Pro cpu up.
I (192) cpu_start: Starting app cpu, entry point is 0x40375124
0x40375124: call_start_cpu1 at /Users/andy/esp/esp-idf/components/esp_system/port/cpu_start.c:152

I (0) cpu_start: App cpu up.
I (214) cpu_start: Pro cpu start user code
I (214) cpu_start: cpu freq: 160000000 Hz
I (214) cpu_start: Application information:
I (217) cpu_start: Project name:     nvs_rw_blob
I (222) cpu_start: App version:      v5.0-dev-2046-g5963de1caf
I (229) cpu_start: Compile time:     Mar 18 2022 15:27:06
I (235) cpu_start: ELF file SHA256:  7d24392957dd1ab8...
I (241) cpu_start: ESP-IDF:          v5.0-dev-2046-g5963de1caf
I (248) heap_init: Initializing. RAM available for dynamic allocation:
I (255) heap_init: At 3FC94480 len 0004BB80 (302 KiB): D/IRAM
I (261) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (268) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (274) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (281) spi_flash: detected chip: mxic
W (285) spi_flash: Detected flash size > 16 MB, but access beyond 16 MB is not supported for this flash model yet.
I (296) spi_flash: flash io: dio
W (300) spi_flash: Detected size(32768k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (314) sleep: Configure to isolate all GPIO pins in sleep state
I (320) sleep: Enable automatic switching of GPIO sleep configuration
I (327) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
Restart counter = 0
Run time:
Nothing saved yet!
I (390) gpio: GPIO[0]| InputEn: 0| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 

For nvs_rw_value, it is the same. The counter is not increased and I never see "Restart counter = 1".

For wifi_prov_mgr, after scanning QR Code, it failed at this screen:

https://i.postimg.cc/tRtVjDN7/2022-03-18-15-52-15.jpg

eos1d3 commented 2 years ago

@shahpiyushv

Please see https://github.com/espressif/esp-idf/issues/8547#issuecomment-1072302537

My board is ESP32-S3 N32R8V, with a V which uses 1.8V SPI flash, compared to 3.3V SPI in other N8R8 SoC. This can be the compatibility problem. And I suspect the board has some other design issue as the RGB LED is not working as well.

MahendraDnkTech commented 1 year ago

Hi.. Guys Hi.. @shahpiyushv I'm also facing a similar issue As my board is ESP32-S3-DevKitC-1 N32R8V with 32MB Flash & 8MB of the PSRAM For the instance, it's not generating the QRCode for the provisioning

I'm using a switch example from the rainmaker SDK IDF version is V4.4

What will be the solution?

Thanks Mahendra