espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.56k stars 7.27k forks source link

ESP32 gets hanged in Cache_Flush() when partition API's called (IDFGH-6272) #7941

Open m-sawant opened 2 years ago

m-sawant commented 2 years ago

Environment

Problem Description

IF app_main() task running with the default priority=1, then NO partition API works and the crash appears at Cache_Flush(0); in the file flash_mmap.c -> spi_flash_mmap_pages() If WDT is enabled then WDT resets the device with reset reason as TG1WDT_SYS_RESET and repeats this in a continuous reset loop

Expected Behavior

The esp32 should not get crash while doing Cache flush

Actual Behavior

The device goes in the hanged mode or resest if WDT enabled when Cache_Flush is called while calling partition API from App layer

Code to reproduce this issue

Simple code in blinky app,just before blinky app's while 1 loop starts, added partition usage API's. This will work in the espidf scenario, However, I am using the Bazel build system to simulate exactly same steps as Cmake does, Able to debug and pinpoint the issue at the file flash_mmap.c ----> spi_flash_mmap_pages() --> Cache_Flush() Also in the debug window nothing can be seen about the esp internals, debugging control goes missing, Program counter doesn't show up in the call stack

// the code should be wrapped in the ```cpp tag so that it will be displayed better.

ESP_LOGE(TAG, "Partition table API");
const esp_partition_t* partition = esp_ota_get_running_partition();   -----> Inside this when CachE_Flush(0) is called from spi_mmap_pages() crash/reset occurs
  if (NULL != partition) {
    ESP_LOGE(TAG, "load partition table entry 0x%x", (intptr_t)partition);
  }
   esp_err_t next_update_partition = esp_ota_set_boot_partition(esp_ota_get_next_update_partition(NULL));
   if (ESP_OK == next_update_partition) {
     ESP_LOGE(TAG, "Set Boot Partition table entry 0x%x", (intptr_t)update_partition);
  }
While(true){
  blinkLeds(); 
}

Debug Logs

rst:0x8 (TG1WDT_SYS_RESET),boot:0x1e (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:7288␍␊
load:0x40078000,len:14308␍␊
load:0x40080400,len:3716␍␊
entry 0x40080680␍␊
boot: ESP-IDF v4.3.1-1-g45dda1d282-dirty 2nd stage bootloader<0x1b>[0m␍␊
boot: compile time 11:44:46<0x1b>[0m␍␊
boot: chip revision: 3<0x1b>[0m␍␊
boot_comm: chip revision: 3, min. bootloader chip revision: 0<0x1b>[0m␍␊
boot.esp32: SPI Speed      : 40MHz<0x1b>[0m␍␊
boot.esp32: SPI Mode       : DIO<0x1b>[0m␍␊
boot.esp32: SPI Flash Size : 4MB<0x1b>[0m␍␊
) boot.esp32: PRO CPU has been reset by WDT.<0x1b>[0m␍␊
) boot.esp32: WDT reset info: PRO CPU PC=0x40080200<0x1b>[0m␍␊
) boot.esp32: WDT reset info: APP CPU PC=0x40080200<0x1b>[0m␍␊
boot: Enabling RNG early entropy source...<0x1b>[0m␍␊
boot: Partition Table:<0x1b>[0m␍␊
boot: ## Label            Usage          Type ST Offset   Length<0x1b>[0m␍␊
boot:  0 nvs              WiFi data        01 02 00009000 00004000<0x1b>[0m␍␊
boot:  1 otadata          OTA data         01 00 0000d000 00002000<0x1b>[0m␍␊
boot:  2 phy_init         RF data          01 01 0000f000 00001000<0x1b>[0m␍␊
boot:  3 factory          factory app      00 00 00010000 00100000<0x1b>[0m␍␊
boot:  4 ota_0            OTA app          00 10 00110000 00100000<0x1b>[0m␍␊
boot:  5 ota_1            OTA app          00 11 00210000 00100000<0x1b>[0m␍␊
boot: End of partition table<0x1b>[0m␍␊
boot_comm: chip revision: 3, min. application chip revision: 0<0x1b>[0m␍␊
esp_image: segment 0: paddr=00110020 vaddr=3f400020 size=09354h ( 37716) map<0x1b>[0m␍␊
esp_image: segment 1: paddr=0011937c vaddr=3ffb0000 size=02864h ( 10340) load<0x1b>[0m␍␊
esp_image: segment 2: paddr=0011bbe8 vaddr=40080000 size=04430h ( 17456) load<0x1b>[0m␍␊
esp_image: segment 3: paddr=00120020 vaddr=400d0020 size=160c8h ( 90312) map<0x1b>[0m␍␊
esp_image: segment 4: paddr=001360f0 vaddr=40084430 size=060f0h ( 24816) load<0x1b>[0m␍␊
esp_image: segment 5: paddr=0013c1e8 vaddr=50000000 size=00010h (    16) load<0x1b>[0m␍␊
boot: Loaded app from partition at offset 0x110000<0x1b>[0m␍␊
boot: Disabling RNG early entropy source...<0x1b>[0m␍␊
cpu_start: Pro cpu up.<0x1b>[0m␍␊
cpu_start: Starting app cpu, entry point is 0x40080f78<0x1b>[0m␍␊
u_start: App cpu up.<0x1b>[0m␍␊
cpu_start: Pro cpu start user code<0x1b>[0m␍␊
cpu_start: cpu freq: 240000000<0x1b>[0m␍␊
cpu_start: Application information:<0x1b>[0m␍␊
cpu_start: Project name:     libesp32<0x1b>[0m␍␊
cpu_start: App version:      1<0x1b>[0m␍␊
cpu_start: ELF file SHA256:  45e8a711fc61d482...<0x1b>[0m␍␊
cpu_start: ESP-IDF:          <0x1b>[0m␍␊
heap_init: Initializing. RAM available for dynamic allocation:<0x1b>[0m␍␊
heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM<0x1b>[0m␍␊
heap_init: At 3FFB3150 len 0002CEB0 (179 KiB): DRAM<0x1b>[0m␍␊
heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM<0x1b>[0m␍␊
heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM<0x1b>[0m␍␊
heap_init: At 4008A520 len 00015AE0 (86 KiB): IRAM<0x1b>[0m␍␊
spi_flash: detected chip: generic<0x1b>[0m␍␊
spi_flash: flash io: dio<0x1b>[0m␍␊
sleep: Configure to isolate all GPIO pins in sleep state<0x1b>[0m␍␊
sleep: Enable automatic switching of GPIO sleep configuration<0x1b>[0m␍␊
cpu_start: Starting scheduler on PRO CPU.<0x1b>[0m␍␊
u_start: Starting scheduler on APP CPU.<0x1b>[0m␍␊
gpio: GPIO[0]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 <0x1b>[0m␍␊
gpio: GPIO[2]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 <0x1b>[0m␍␊
gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 <0x1b>[0m␍␊
main: Partition table API's <0x1b>[0m␍␊
 ts Jul 29 2019 12:21:46␍␊
␍␊
rst:0x8 (TG1WDT_SYS_RESET),boot:0x1e (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:7288␍␊
load:0x40078000,len:14308␍␊
load:0x40080400,len:3716␍␊
entry 0x40080680␍␊
boot: ESP-IDF v4.3.1-1-g45dda1d282-dirty 2nd stage bootloader<0x1b>[0m␍␊
boot: compile time 11:44:46<0x1b>[0m␍␊
boot: chip revision: 3<0x1b>[0m␍␊
boot_comm: chip revision: 3, min. bootloader chip revision: 0<0x1b>[0m␍␊
boot.esp32: SPI Speed      : 40MHz<0x1b>[0m␍␊
boot.esp32: SPI Mode       : DIO<0x1b>[0m␍␊
boot.esp32: SPI Flash Size : 4MB<0x1b>[0m␍␊
) boot.esp32: PRO CPU has been reset by WDT.<0x1b>[0m␍␊
) boot.esp32: WDT reset info: PRO CPU PC=0x40080203<0x1b>[0m␍␊
) boot.esp32: WDT reset info: APP CPU PC=0x40080200<0x1b>[0m␍␊
boot: Enabling RNG early entropy source...<0x1b>[0m␍␊
boot: Partition Table:<0x1b>[0m␍␊
boot: ## Label            Usage          Type ST Offset   Length<0x1b>[0m␍␊
boot:  0 nvs              WiFi data        01 02 00009000 00004000<0x1b>[0m␍␊
boot:  1 otadata          OTA data         01 00 0000d000 00002000<0x1b>[0m␍␊
boot:  2 phy_init         RF data          01 01 0000f000 00001000<0x1b>[0m␍␊
boot:  3 factory          factory app      00 00 00010000 00100000<0x1b>[0m␍␊
boot:  4 ota_0            OTA app          00 10 00110000 00100000<0x1b>[0m␍␊
boot:  5 ota_1            OTA app          00 11 00210000 00100000<0x1b>[0m␍␊
boot: End of partition table<0x1b>[0m␍␊

Other items if possible

partition-table-.csv sdkconfig.txt

m-sawant commented 2 years ago

One more observation is the device does not come out of the Cache_Flush(0); Execution and breaks while trying to stall othercpu(), Can anyone answer why the esp32 doesn't come out of the following loop from the dport_access.c file, I am not able to find anything in the user manual. while (!dport_access_start[cpu_id]) {};