ock] 1279 19005 [OTA Agent Task] [prvIngestDataBlock] Received file block 345, size 4096 1280 19006 [OTA Agent Task] [prvIngestDataBlock] Remaining: 2 1281 19006 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 1282 19008 [OTA Agent Task] [prvIngestDataBlock] Received file block 346, size 2768 1283 19009 [OTA Agent Task] [prvIngestDataBlock] Remaining: 1 1284 19009 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 1285 19012 [OTA Agent Task] [prvIngestDataBlock] Received file block 344, size 4096 I (190277) ota_pal: No such certificate file: /device/certs. Using aws_ota_codesigner_certificate.h. 1286 19013 [OTA Agent Task] [prvIngestDataBlock] Received final expected block of file. 1287 19013 [OTA Agent Task] [prvStopRequestTimer] Stopping request timer. 1288 19144 [OTA Agent Task] [prvIngestDataBlock] File receive complete and signature is valid. 1289 19144 [OTA Agent Task] [prvStopRequestTimer] Stopping request timer. 1290 19144 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] Msg: {"status":"IN_PROGRESS","statusDetails":{"self_test":"ready","updatedBy":"0x1000000"}} 1291 19144 [OTA Agent Task] [INFO ][MQTT][191440] (MQTT connection 0x3ffba3d0) MQTT PUBLISH operation queued. 1292 19144 [OTA Agent Task] [INFO ][MQTT][191440] (MQTT connection 0x3ffba3d0, PUBLISH operation 0x3ffd77e8) Waiting for operation completion. 1293 19177 [OTA Agent Task] [INFO ][MQTT][191770] (MQTT connection 0x3ffba3d0, PUBLISH operation 0x3ffd77e8) Wait complete with result SUCCESS. 1294 19177 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] 'IN_PROGRESS' to $aws/things/FW_246F2824E888/jobs/AFR_OTA-sb-test6_/update 1295 19178 [OTA Agent Task] Received eOTA_JobEvent_Activate callback from OTA Agent. I (191927) boot_comm: chip revision: 1, min. application chip revision: 0 I (191947) esp_image: segment 0: paddr=0x00180020 vaddr=0x3f400020 size=0x42b14 (273172) map I (192097) esp_image: segment 1: paddr=0x001c2b3c vaddr=0x3ffbdb60 size=0x03cd4 ( 15572) I (192107) esp_image: segment 2: paddr=0x001c6818 vaddr=0x40080000 size=0x00400 ( 1024) 0x40080000: _WindowOverflow4 at /home/horsemann/Desktop/WorkSpace/SecureBoot2/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685 I (192107) esp_image: segment 3: paddr=0x001c6c20 vaddr=0x40080400 size=0x093f0 ( 37872) I (192137) esp_image: segment 4: paddr=0x001d0018 vaddr=0x400d0018 size=0xf54d4 (1004756) map 0x400d0018: _flash_cache_start at ??:? I (192637) esp_image: segment 5: paddr=0x002c54f4 vaddr=0x400897f0 size=0x155b4 ( 87476) 0x400897f0: r_lld_evt_restart at ??:? I (192677) esp_image: Verifying image signature... I (192817) boot_comm: chip revision: 1, min. application chip revision: 0 I (192817) esp_image: segment 0: paddr=0x00180020 vaddr=0x3f400020 size=0x42b14 (273172) map I (192967) esp_image: segment 1: paddr=0x001c2b3c vaddr=0x3ffbdb60 size=0x03cd4 ( 15572) I (192977) esp_image: segment 2: paddr=0x001c6818 vaddr=0x40080000 size=0x00400 ( 1024) 0x40080000: _WindowOverflow4 at /home/horsemann/Desktop/WorkSpace/SecureBoot2/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685 I (192977) esp_image: segment 3: paddr=0x001c6c20 vaddr=0x40080400 size=0x093f0 ( 37872) I (192997) esp_image: segment 4: paddr=0x001d0018 vaddr=0x400d0018 size=0xf54d4 (1004756) map 0x400d0018: _flash_cache_start at ??:? I (193507) esp_image: segment 5: paddr=0x002c54f4 vaddr=0x400897f0 size=0x155b4 ( 87476) 0x400897f0: r_lld_evt_restart at ??:? I (193547) esp_image: Verifying image signature... I (194247) wifi: state: run -> init (0) I (194247) wifi: pm stop, total sleep time: 153684577 us / 192739724 us I (194247) wifi: new:<1,0>, old:<1,1>, ap:<255,255>, sta:<1,1>, prof:1 I (194247) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8 ASSOC_LEAVE I (194257) BTDM_INIT: BT controller compile version [9891bc6] I (194257) wifi: flush txq I (194267) wifi: stop sw txq I (194267) wifi: lmac stop hw txq I (194267) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE ets Jun 8 2016 00:22:57 rst:0xc (SW_CPU_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:10496 ho 0 tail 12 room 4 load:0x40078000,len:20228 load:0x40080400,len:6592 entry 0x40080748 I (94) boot: Chip Revision: 1 I (95) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (44) boot: ESP-IDF 2nd stage bootloader I (44) boot: compile time 18:57:22 I (44) boot: Enabling RNG early entropy source... I (48) boot: SPI Speed : 80MHz I (52) boot: SPI Mode : DIO I (56) boot: SPI Flash Size : 4MB I (60) boot: Partition Table: I (64) boot: ## Label Usage Type ST Offset Length I (71) boot: 0 nvs WiFi data 01 02 00014000 00006000 I (78) boot: 1 otadata OTA data 01 00 0001a000 00002000 I (86) boot: 2 phy_init RF data 01 01 0001c000 00001000 I (93) boot: 3 factory factory app 00 00 00020000 0015e000 I (101) boot: 4 ota_0 OTA app 00 10 00180000 0015e000 I (108) boot: 5 ota_1 OTA app 00 11 002e0000 00032000 I (116) boot: 6 file Unknown data 01 82 00312000 00006000 I (123) boot: 7 storage WiFi data 01 02 00318000 00010000 I (131) boot: End of partition table I (135) boot: otadata[0] is selected as new and marked PENDING_VERIFY state I (190) boot: ota rollback check done I (190) boot_comm: chip revision: 1, min. application chip revision: 0 I (191) esp_image: segment 0: paddr=0x00180020 vaddr=0x3f400020 size=0x42b14 (273172) map I (283) esp_image: segment 1: paddr=0x001c2b3c vaddr=0x3ffbdb60 size=0x03cd4 ( 15572) load I (288) esp_image: segment 2: paddr=0x001c6818 vaddr=0x40080000 size=0x00400 ( 1024) load 0x40080000: _WindowOverflow4 at /home/horsemann/Desktop/WorkSpace/SecureBoot2/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685 I (290) esp_image: segment 3: paddr=0x001c6c20 vaddr=0x40080400 size=0x093f0 ( 37872) load I (312) esp_image: segment 4: paddr=0x001d0018 vaddr=0x400d0018 size=0xf54d4 (1004756) map 0x400d0018: _flash_cache_start at ??:? I (617) esp_image: segment 5: paddr=0x002c54f4 vaddr=0x400897f0 size=0x155b4 ( 87476) load 0x400897f0: r_lld_evt_restart at ??:? I (650) esp_image: Verifying image signature... I (1075) boot: Loaded app from partition at offset 0x180000 I (1075) secure_boot: bootloader secure boot is already enabled. No need to generate digest. continuing.. I (1080) boot: Checking flash encryption... I (1085) flash_encrypt: flash encryption is enabled (0 plaintext flashes left) I (1093) boot: Checking secure boot... I (1097) secure_boot: bootloader secure boot is already enabled, continuing.. I (1105) boot: Disabling RNG early entropy source... I (1111) cpu_start: Pro cpu up. I (1115) cpu_start: Application information: I (1120) cpu_start: Project name: esp-idf I (1125) cpu_start: App version: ba32100d I (1130) cpu_start: Compile time: Jul 13 2021 23:10:29 I (1136) cpu_start: ELF file SHA256: db411ddd835b8165... I (1142) cpu_start: ESP-IDF: ba32100d I (1147) cpu_start: Single core mode I (1152) heap_init: Initializing. RAM available for dynamic allocation: I (1159) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM I (1165) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM I (1171) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM I (1177) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM I (1184) heap_init: At 3FFD4880 len 0000B780 (45 KiB): DRAM I (1190) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM I (1196) heap_init: At 40078000 len 00008000 (32 KiB): IRAM I (1203) heap_init: At 4009EDA4 len 0000125C (4 KiB): IRAM I (1209) cpu_start: Pro cpu start user code I (109) cpu_start: Starting scheduler on PRO CPU. assertion "it != NULL" failed: file "../freertos/vendors/espressif/esp-idf/components/app_update/esp_ota_ops.c", line 507, function: esp_ota_get_running_partition abort() was called at PC 0x400f5797 on core 0 0x400f5797: RC_GetBlockAckTime at ??:? ELF file SHA256: db411ddd835b8165 Backtrace: 0x4008e0fc:0x3ffba8c0 0x4008e32d:0x3ffba8e0 0x400f5797:0x3ffba900 0x400df507:0x3ffba930 0x400e38ca:0x3ffba950 0x4008e0fc: ppCalTxAMPDULength at ??:? 0x4008e32d: ppCalTxAMPDULength at ??:? 0x400f5797: RC_GetBlockAckTime at ??:? 0x400df507: wifi_nvs_cfg_init at ??:? 0x400e38ca: ieee80211_add_countryie at ??:? ================================================================================================= 1162 18405 [OTA Agent Task] [prvIngestDataBlock] Remaining: 1 1163 18405 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [ReceivedFileBlock] New state [WaitingForFileBlock] 1164 18405 [OTA Agent Task] [INFO ][MQTT][184050] (MQTT connection 0x3ffb9dfc) MQTT PUBLISH operation queued. 1165 18405 [OTA Agent Task] [prvRequestFileBlock_Mqtt] OK: $aws/things/FW_246F2824E888/streams/AFR_OTA-2114d5b7-aeb3-41ea-9aa1-abd9571a010d/get/cbor 1166 18405 [OTA Agent Task] [prvOTAAgentTask] Called handler. Current State [WaitingForFileBlock] Event [RequestFileBlock] New state [WaitingForFileBlock] I (184248) ota_pal: No such certificate file: /device/certs. Using aws_ota_codesigner_certificate.h. 1167 18410 [OTA Agent Task] [prvIngestDataBlock] Received file block 312, size 160 1168 18410 [OTA Agent Task] [prvIngestDataBlock] Received final expected block of file. 1169 18410 [OTA Agent Task] [prvStopRequestTimer] Stopping request timer. 1170 18535 [OTA Agent Task] [prvIngestDataBlock] File receive complete and signature is valid. 1171 18535 [OTA Agent Task] [prvStopRequestTimer] Stopping request timer. 1172 18535 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] Msg: {"status":"IN_PROGRESS","statusDetails":{"self_test":"ready","updatedBy":"0x1000000"}} 1173 18535 [OTA Agent Task] [INFO ][MQTT][185350] (MQTT connection 0x3ffb9dfc) MQTT PUBLISH operation queued. 1174 18535 [OTA Agent Task] [INFO ][MQTT][185350] (MQTT connection 0x3ffb9dfc, PUBLISH operation 0x3ffd7514) Waiting for operation completion. I (185538) boot_comm: chip revision: 1, min. application chip revision: 0 I (185548) esp_image: segment 0: paddr=0x00180020 vaddr=0x3f400020 size=0x3ae70 (241264) map 1175 18539 [OTA Agent Task] [INFO ][MQTT][185390] (MQTT connection 0x3ffb9dfc, PUBLISH operation 0x3ffd7514) Wait complete with result SUCCESS. 1176 18539 [OTA Agent Task] [prvUpdateJobStatus_Mqtt] 'IN_PROGRESS' to $aws/things/FW_246F2824E888/jobs/AFR_OTA-sb-test7/update 1177 18539 [OTA Agent Task] Received eOTA_JobEvent_Activate callback from OTA Agent. I (185688) esp_image: segment 1: paddr=0x001bae98 vaddr=0x3ffbdb60 size=0x03398 ( 13208) I (185698) esp_image: segment 2: paddr=0x001be238 vaddr=0x40080000 size=0x00400 ( 1024) 0x40080000: _WindowOverflow4 at /home/horsemann/Desktop/WorkSpace/SecureBoot2/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685 I (185698) esp_image: segment 3: paddr=0x001be640 vaddr=0x40080400 size=0x019d0 ( 6608) I (185708) esp_image: segment 4: paddr=0x001c0018 vaddr=0x400d0018 size=0xe2994 (928148) map 0x400d0018: _flash_cache_start at ??:? I (186178) esp_image: segment 5: paddr=0x002a29b4 vaddr=0x40081dd0 size=0x156c8 ( 87752) 0x40081dd0: ipc_task at /home/horsemann/Desktop/WorkSpace/SecureBoot2/vendors/espressif/esp-idf/components/esp32/ipc.c:59 I (186218) esp_image: Verifying image signature... I (186358) boot_comm: chip revision: 1, min. application chip revision: 0 I (186358) esp_image: segment 0: paddr=0x00180020 vaddr=0x3f400020 size=0x3ae70 (241264) map I (186488) esp_image: segment 1: paddr=0x001bae98 vaddr=0x3ffbdb60 size=0x03398 ( 13208) I (186488) esp_image: segment 2: paddr=0x001be238 vaddr=0x40080000 size=0x00400 ( 1024) 0x40080000: _WindowOverflow4 at /home/horsemann/Desktop/WorkSpace/SecureBoot2/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685 I (186488) esp_image: segment 3: paddr=0x001be640 vaddr=0x40080400 size=0x019d0 ( 6608) I (186508) esp_image: segment 4: paddr=0x001c0018 vaddr=0x400d0018 size=0xe2994 (928148) map 0x400d0018: _flash_cache_start at ??:? I (186978) esp_image: segment 5: paddr=0x002a29b4 vaddr=0x40081dd0 size=0x156c8 ( 87752) 0x40081dd0: ipc_task at /home/horsemann/Desktop/WorkSpace/SecureBoot2/vendors/espressif/esp-idf/components/esp32/ipc.c:59 I (187018) esp_image: Verifying image signature... I (187718) wifi: state: run -> init (0) I (187718) wifi: pm stop, total sleep time: 140525959 us / 186258320 us I (187718) wifi: new:<1,0>, old:<1,1>, ap:<255,255>, sta:<1,1>, prof:1 I (187718) WIFI: SYSTEM_EVENT_STA_DISCONNECTED: 8 ASSOC_LEAVE I (187728) BTDM_INIT: BT controller compile version [9891bc6] I (187728) wifi: flush txq I (187738) wifi: stop sw txq I (187738) wifi: lmac stop hw txq I (187738) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE ets Jun 8 2016 00:22:57 rst:0xc (SW_CPU_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:10496 ho 0 tail 12 room 4 load:0x40078000,len:20228 load:0x40080400,len:6592 entry 0x40080748 I (94) boot: Chip Revision: 1 I (95) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (44) boot: ESP-IDF 2nd stage bootloader I (44) boot: compile time 18:57:22 I (44) boot: Enabling RNG early entropy source... I (48) boot: SPI Speed : 80MHz I (52) boot: SPI Mode : DIO I (56) boot: SPI Flash Size : 4MB I (60) boot: Partition Table: I (64) boot: ## Label Usage Type ST Offset Length I (71) boot: 0 nvs WiFi data 01 02 00014000 00006000 I (78) boot: 1 otadata OTA data 01 00 0001a000 00002000 I (86) boot: 2 phy_init RF data 01 01 0001c000 00001000 I (93) boot: 3 factory factory app 00 00 00020000 0015e000 I (101) boot: 4 ota_0 OTA app 00 10 00180000 0015e000 I (108) boot: 5 ota_1 OTA app 00 11 002e0000 00032000 I (116) boot: 6 file Unknown data 01 82 00312000 00006000 I (123) boot: 7 storage WiFi data 01 02 00318000 00010000 I (131) boot: End of partition table I (135) boot: otadata[0] is selected as new and marked PENDING_VERIFY state I (190) boot: ota rollback check done I (190) boot_comm: chip revision: 1, min. application chip revision: 0 I (191) esp_image: segment 0: paddr=0x00180020 vaddr=0x3f400020 size=0x3ae70 (241264) map I (273) esp_image: segment 1: paddr=0x001bae98 vaddr=0x3ffbdb60 size=0x03398 ( 13208) load I (278) esp_image: segment 2: paddr=0x001be238 vaddr=0x40080000 size=0x00400 ( 1024) load 0x40080000: _WindowOverflow4 at /home/horsemann/Desktop/WorkSpace/SecureBoot2/freertos_kernel/portable/ThirdParty/GCC/Xtensa_ESP32/xtensa_vectors.S:1685 I (280) esp_image: segment 3: paddr=0x001be640 vaddr=0x40080400 size=0x019d0 ( 6608) load I (291) esp_image: segment 4: paddr=0x001c0018 vaddr=0x400d0018 size=0xe2994 (928148) map 0x400d0018: _flash_cache_start at ??:? I (579) esp_image: segment 5: paddr=0x002a29b4 vaddr=0x40081dd0 size=0x156c8 ( 87752) load 0x40081dd0: ipc_task at /home/horsemann/Desktop/WorkSpace/SecureBoot2/vendors/espressif/esp-idf/components/esp32/ipc.c:59 I (612) esp_image: Verifying image signature... I (1020) boot: Loaded app from partition at offset 0x180000 I (1020) secure_boot: bootloader secure boot is already enabled. No need to generate digest. continuing.. I (1025) boot: Checking flash encryption... I (1030) flash_encrypt: flash encryption is enabled (0 plaintext flashes left) I (1038) boot: Checking secure boot... I (1042) secure_boot: bootloader secure boot is already enabled, continuing.. I (1050) boot: Disabling RNG early entropy source... I (1056) cpu_start: Pro cpu up. I (1059) cpu_start: Application information: I (1064) cpu_start: Project name: aws_demos I (1070) cpu_start: App version: 5bb1582de-dirty I (1075) cpu_start: Compile time: Aug 27 2021 18:35:27 I (1082) cpu_start: ELF file SHA256: f8c1ef78e8ee803b... I (1088) cpu_start: ESP-IDF: I (1092) cpu_start: Single core mode I (1097) heap_init: Initializing. RAM available for dynamic allocation: I (1104) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM I (1110) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM I (1116) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM I (1122) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM I (1128) heap_init: At 3FFD4218 len 0000BDE8 (47 KiB): DRAM I (1135) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM I (1141) heap_init: At 40078000 len 00008000 (32 KiB): IRAM I (1147) heap_init: At 40097498 len 00008B68 (34 KiB): IRAM I (1154) cpu_start: Pro cpu start user code I (54) cpu_start: Starting scheduler on PRO CPU. abort() was called at PC 0x4013e2ae on core 0 0x4013e2ae: r_nvds_init at ??:? ELF file SHA256: f8c1ef78e8ee803bdb7e5985f191cd7874576a91d132e05c1a80a92865451710 Backtrace: 0x4008cd94:0x3ffbaaa0 0x4008cf65:0x3ffbaac0 0x4013e2ae:0x3ffbaae0 0x400d063a:0x3ffbab00 0x4008cd94: bt_bb_init_cmplx_reg at /home/qgu/git_tree/chip7.1_rtc/board_code/app_test/pp/rtc/bt_bb.c:288 0x4008cf65: coex_bt_high_prio at /home/qgu/git_tree/chip7.1_rtc/board_code/app_test/pp/rtc/bt_bb.c:387 0x4013e2ae: r_nvds_init at ??:? 0x400d063a: DPORT_READ_PERI_REG at /home/horsemann/Desktop/WorkSpace/SecureBoot2/vendors/espressif/esp-idf/components/soc/esp32/include/soc/dport_access.h:170 (inlined by) esp_perip_clk_init at /home/horsemann/Desktop/WorkSpace/SecureBoot2/vendors/espressif/esp-idf/components/esp32/clk.c:249 Rebooting...