Skip to content

Guru Meditation Error trigger by nvs_flash_init when activated SystemView Tracing (IDFGH-7571) #9131

@nikidimitrow

Description

@nikidimitrow

Hello support team,

Environment

  • Development Kit: ESP32-DevKitC
  • Kit version: v4
  • Module or chip used: ESP32-S3-WROOM-1
  • IDF version: v5.0-dev-3290-g01d014c42d
  • Build System: idf.py
  • Compiler version: xtensa-esp32-elf-gcc.exe (crosstool-NG esp-2021r2-patch3) 8.4.0
  • Operating System: Windows
  • (Windows only) environment type: ESP Command Prompt
  • Using an IDE: No
  • Power Supply: USB

Problem Description

In our project we would like to do system Behavior Analysis with SEGGER SystemView. For this purpose from idf.py menuconfig I'm activated:

Component config --> Application Level Tracing --> Data Destomatopm 1 --> (JTAG)
FreeRTOS SystemView Tracing --> SystemView Tracing Enable.

Before activated this option in idf.py menuconfig the system is working fine.

Once the above options in menuconfig are save and the project is build and flash system start to enter in the critical error:

Guru Meditation Error: Core 0 panic'ed (Cache disabled but cached memory region accessed).

From the trace I can see that nvs_flash_init is trigger this panic error. In the project we are using custom partition table.

If NvS component is not used the panic error is not any more present and I'm able to drop me .SVDat from the JTAG.

See the log file below. Sdconfig file, partition table and .elf file are upload here: https://github.com/nikidimitrow/idf-report-crash

In this peace of code is where Init of partition happen:

void NVWrapper_Init(void)
{
 
	/* Initialize Partitions */
	if (NVWrapper_InitPartitions() == ESP_OK) {
	    NVWrapper_PartitionsInit_ValidityFlag = true;
	} else {
	  NVWrapper_Log(E, "Partitions initialization: FAILED !");
	}
	/* Open  Partitions */
	if (NVWrapper_OpenPartitions()  == ESP_OK) {
	    NVWrapper_PartitionsOpen_ValidityFlag = true;
	} else {
	  NVWrapper_Log(E, "Partitions opening: FAILED !");
	}

	if ((true == NVWrapper_PartitionsInit_ValidityFlag) &&
	    (true == NVWrapper_PartitionsOpen_ValidityFlag))
	{
	    /* Set state to initialized */
	    NVWrapperInitialized = true;
	    NVWrapper_Log(I, "NVWrapper initialization: OK !");
	} else {
	    NVWrapper_Log(E, "NVWrapper initialization: FAILED !");
	}
}

NVWrapper_InitPartitions function

static esp_err_t NVWrapper_InitPartitions(void)
{
	esp_err_t retVal = ESP_FAIL;
	NVWrapper_PartitionsId count = 0;

	NVWrapper_Log(I, "Start Partition Initialization...");
	for (count = 0; count < PartitionsCount; count++) {
		retVal = nvs_flash_init_partition(Partitions[count]);

#if (PARTITION_REINITIALIZATION == E_ON)
		if (retVal == ESP_ERR_NVS_NO_FREE_PAGES || retVal == ESP_ERR_NVS_NEW_VERSION_FOUND) {
			NVWrapper_Log(W, "Init of '%s' partition failed, it will be erased and re-initted ! [Error: 0x%X]", Partitions[count], retVal);
			if (ESP_OK != nvs_flash_erase_partition(Partitions[count])) {
			    NVWrapper_Log(W, "Failed to erase the partition with Id %d [Error: 0x%X]", Partitions[count], retVal);
			}
			retVal = nvs_flash_init_partition(Partitions[count]);
		}
#endif
		if (ESP_OK == retVal) {
			NVWrapper_Log(I, "Initialization of partition '%s' with id %d : OK !", Partitions[count], count);
		} else {
			NVWrapper_Log(E, "Initialization of partition '%s' with id %d : FAILED ! [error: 0x%X]", Partitions[count], count, retVal);
		}
	}
	NVWrapper_Log(I, "... Partition Initialization Done !");

	return retVal;
}

This are the argument that are passed to nvs_flash_init_partition(Partitions[count]);

static const tChar Partitions[PartitionsCount][NVS_NAMES_MAX_SYMBOLS] = {
		"prod",     /* ProductionPartition  */
        "safe",     /* SafeNVPartition      */
        "nvs",      /* NVSPartition         */
        "appl",     /* ApplicationPartition */
		"shared"    /* SharedPartition      */
};

Log file:

I (48) boot: ESP-IDF v5.0-dev-3290-g01d014c42d 2nd stage bootloader
I (48) boot: compile time 10:59:45
I (48) boot: chip revision: 0
I (51) boot.esp32s3: Boot SPI Speed : 80MHz
I (56) boot.esp32s3: SPI Mode       : DIO
I (61) boot.esp32s3: SPI Flash Size : 8MB
I (66) boot: Enabling RNG early entropy source...
I (71) boot: Partition Table:
I (75) boot: ## Label            Usage          Type ST Offset   Length
I (82) boot:  0 otadata          OTA data         01 00 0000d000 00002000
I (89) boot:  1 prod             WiFi data        01 02 0000f000 00001000
I (97) boot:  2 ota_0            OTA app          00 10 00010000 00280000
I (104) boot:  3 ota_1            OTA app          00 11 00290000 00280000
I (112) boot:  4 safe             WiFi data        01 02 00610000 00003000
I (119) boot:  5 config           WiFi data        01 02 00613000 00046000
I (127) boot:  6 appl             WiFi data        01 02 00659000 00004000
I (135) boot:  7 shared           WiFi data        01 02 0065d000 00003000
W (142) efuse: Loading virtual efuse blocks from flash
EFUSE_BLKx:
0) 0x01800301 0x000f0c02 0x49c40000 0x00500000 0x80000022 0x00000000
1) 0x03c0296c 0x000084f7 0x00000000 0x02040000 0x54991400 0x5005d47c
2) 0xfbecd701 0x24072709 0x50b01efb 0xcc734f00 0x70cb5271 0xd0d12edb 0xbed0d4e1 0x324cbcc8
3) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4) 0x7e68a2e3 0x08fe1124 0x53ed80b5 0xa7d5faa7 0x1b37941e 0x0b3d3af1 0x7e3e1a92 0x7dee2768
5) 0x0c115a96 0xe46eab50 0x87476dcd 0xc4ee6f86 0xa09cab43 0x8b2b625e 0xeabfd528 0x125e8ae2
6) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
7) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
8) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
9) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
10) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000

I (234) boot:  8 efuse_em         efuse            01 05 00660000 00002000
I (242) boot:  9 nvs              WiFi data        01 02 00662000 00004000
I (249) boot: 10 nvs_key          NVS keys         01 04 00666000 00001000
I (257) boot: 11 spiffs           Unknown data     01 82 00667000 00199000
I (265) boot: End of partition table
I (269) boot: No factory image, trying OTA 0
[boot] Custom bootloader message defined in the KConfig file.
I (279) boot: Loading Image: 0!
I (283) esp_image: segment 0: paddr=00010020 vaddr=3c0e0020 size=45b90h (285584) map
I (343) esp_image: segment 1: paddr=00055bb8 vaddr=3fc979b0 size=053c0h ( 21440) load
I (348) esp_image: segment 2: paddr=0005af80 vaddr=40374000 size=05098h ( 20632) load
I (353) esp_image: segment 3: paddr=00060020 vaddr=42000020 size=d70e8h (880872) map
I (515) esp_image: segment 4: paddr=00137110 vaddr=40379098 size=0e910h ( 59664) load
I (528) esp_image: segment 5: paddr=00145a28 vaddr=50000000 size=00010h (    16) load
I (529) esp_image: segment 6: paddr=00145a40 vaddr=00000000 size=0a590h ( 42384)
I (542) esp_image: Verifying image signature...
I (542) secure_boot_v2: Verifying with RSA-PSS...
I (547) secure_boot_v2: Signature verified successfully!
I (559) boot: Loaded app from partition at offset 0x10000
I (587) boot: Set actual ota_seq=1 in otadata[0]
I (587) secure_boot_v2: enabling secure boot v2...
I (587) secure_boot_v2: secure boot v2 is already enabled, continuing..
I (594) boot: Checking flash encryption...
I (598) flash_encrypt: flash encryption is enabled (1 plaintext flashes left)
I (606) boot: Disabling RNG early entropy source...
I (623) cpu_start: Pro cpu up.
I (623) cpu_start: Starting app cpu, entry point is 0x403754ec
0x403754ec: call_start_cpu1 at C:/Users/xxxxxxx/Documents/esp-idf/components/esp_system/port/cpu_start.c:152

I (0) cpu_start: App cpu up.
I (636) cpu_start: Pro cpu start user code
I (636) cpu_start: cpu freq: 160000000 Hz
I (637) cpu_start: Application information:
I (639) cpu_start: Project name:     ksc2n_A_Sample
I (645) cpu_start: App version:      esp-idf_v4.4-5-g309aa6f-dirty
I (652) cpu_start: Compile time:     Jun  9 2022 07:33:51
I (658) cpu_start: ELF file SHA256:  2e568e4c6cac14f4...
I (664) cpu_start: ESP-IDF:          v5.0-dev-3290-g01d014c42d
I (671) heap_init: Initializing. RAM available for dynamic allocation:
I (678) heap_init: At 3FCAFB40 len 000204C0 (129 KiB): D/IRAM
I (684) heap_init: At 3FCD8000 len 00008000 (32 KiB): D/IRAM
I (690) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (697) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (703) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
I (710) spi_flash: detected chip: gd
I (714) spi_flash: flash io: dio
W (718) cpu_start: eFuse virtual mode is enabled. If Secure boot or Flash encryption is enabled then it does not provide any security. FOR TESTING ONLY!
W (733) efuse: Loading virtual efuse blocks from flash
EFUSE_BLKx:
0) 0x01800301 0x000f0c02 0x49c40000 0x00500000 0x80000022 0x00000000
1) 0x03c0296c 0x000084f7 0x00000000 0x02040000 0x54991400 0x5005d47c
2) 0xfbecd701 0x24072709 0x50b01efb 0xcc734f00 0x70cb5271 0xd0d12edb 0xbed0d4e1 0x324cbcc8
3) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
4) 0x7e68a2e3 0x08fe1124 0x53ed80b5 0xa7d5faa7 0x1b37941e 0x0b3d3af1 0x7e3e1a92 0x7dee2768
5) 0x0c115a96 0xe46eab50 0x87476dcd 0xc4ee6f86 0xa09cab43 0x8b2b625e 0xeabfd528 0x125e8ae2
6) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
7) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
8) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
9) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000
10) 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000 0x00000000

W (824) flash_encrypt: Flash encryption mode is DEVELOPMENT (not secure)
DoIP-Stack constructed
I (834) DoIP_Port: Instance created !
I (840) sleep: Configure to isolate all GPIO pins in sleep state
I (845) sleep: Enable automatic switching of GPIO sleep configuration
I (852) esp_apptrace: Initialized TRAX on CPU0
I (857) cpu_start: Starting scheduler on PRO CPU.
I (232) esp_apptrace: Initialized TRAX on CPU1
I (0) cpu_start: Starting scheduler on APP CPU.
I (883) NvsKsc2: Initializing default NVS partition 'nvs' ...
Guru Meditation Error: Core  0 panic'ed (Cache disabled but cached memory region accessed).


Core  0 register dump:
PC      : 0x42007536  PS      : 0x00060d34  A0      : 0x8037b3a8  A1      : 0x3fc97f30
0x42007536: esp_apptrace_trax_down_buffer_get at C:/Users/xxxxxxx/Documents/esp-idf/components/app_trace/port/xtensa/port.c:386

A2      : 0x00000001  A3      : 0x3fc97fa0  A4      : 0x3fc97f70  A5      : 0x3fc9d498
A6      : 0x3fc9a39c  A7      : 0x3fce0eb4  A8      : 0x8037c33e  A9      : 0x00000000
A10     : 0x3fc97f48  A11     : 0x3fc97f48  A12     : 0x3fc97f30  A13     : 0x3fcf4150
A14     : 0x4038322c  A15     : 0x3fcf4184  SAR     : 0x0000001f  EXCCAUSE: 0x00000007
0x4038322c: spi_flash_hal_poll_cmd_done at C:/Users/xxxxxxx/Documents/esp-idf/components/hal/spi_flash_hal_common.inc:37

EXCVADDR: 0x00000000  LBEG    : 0x400570e8  LEND    : 0x400570f3  LCOUNT  : 0x00000000


Backtrace:0x42007533:0x3fc97f300x4037b3a5:0x3fc97f70 0x4037b69d:0x3fc97fa0 0x4037b819:0x3fc97fd0 0x4037bc22:0x3fc97ff0 0x40376409:0x3fc98010 0x40376d52:0x3fc98030 0x40383233:0x3fcf4130 0x40382e16:0x3fcf4150 0x40387329:0x3fcf4180 0x4037881f:0x3fcf4200 0x420283db:0x3fcf4240 0x4202cdba:0x3fcf4260 0x4202e30e:0x3fcf4280 0x4202e6da:0x3fcf42c0 0x4202bfbb:0x3fcf4330 0x4202cfa5:0x3fcf4390 0x4202d0ae:0x3fcf43b0 0x4202b181:0x3fcf43e0 0x4202b7a6:0x3fcf4400 0x42014c01:0x3fcf4470 0x4200a142:0x3fcf4490 0x4200a00b:0x3fcf44b0 0x420d6de0:0x3fcf44d0 0x40381b21:0x3fcf4500
0x42007533: esp_apptrace_trax_down_buffer_put at port.c:?

0x4037b3a5: SEGGER_RTT_ReadNoLock at C:/Users/xxxxxxx/Documents/esp-idf/components/app_trace/sys_view/esp/SEGGER_RTT_esp.c:124

0x4037b69d: _HandleIncomingPacket at C:/Users/xxxxxxx/Documents/esp-idf/components/app_trace/sys_view/SEGGER/SEGGER_SYSVIEW.c:466

0x4037b819: _SendPacket at C:/Users/xxxxxxx/Documents/esp-idf/components/app_trace/sys_view/SEGGER/SEGGER_SYSVIEW.c:744

0x4037bc22: SEGGER_SYSVIEW_RecordEnterISR at C:/Users/xxxxxxx/Documents/esp-idf/components/app_trace/sys_view/SEGGER/SEGGER_SYSVIEW.c:1846 (discriminator 4)

0x40376409: non_shared_intr_isr at C:/Users/xxxxxxx/Documents/esp-idf/components/esp_hw_support/intr_alloc.c:425

0x40376d52: _xt_lowint1 at C:/Users/xxxxxxx/Documents/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/xtensa_vectors.S:1117

0x40383233: spimem_flash_ll_cmd_is_done at C:/Users/xxxxxxx/Documents/esp-idf/components/hal/esp32s3/include/hal/spimem_flash_ll.h:60 (discriminator 1)
 (inlined by) spi_flash_hal_poll_cmd_done at C:/Users/xxxxxxx/Documents/esp-idf/components/hal/spi_flash_hal_common.inc:38 (discriminator 1)

0x40382e16: spi_flash_hal_read at C:/Users/xxxxxxx/Documents/esp-idf/components/hal/spi_flash_hal_common.inc:179

0x40387329: spi_flash_chip_winbond_read at C:/Users/xxxxxxx/Documents/esp-idf/components/spi_flash/spi_flash_chip_winbond.c:69

0x4037881f: esp_flash_read at C:/Users/xxxxxxx/Documents/esp-idf/components/spi_flash/esp_flash_api.c:821 (discriminator 4)

0x420283db: esp_partition_read_raw at C:/Users/xxxxxxx/Documents/esp-idf/components/spi_flash/partition_target.c:113

0x4202cdba: nvs::NVSPartition::read_raw(unsigned int, void*, unsigned int) at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_partition.cpp:36

0x4202e30e: nvs::Page::load(nvs::Partition*, unsigned int) at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_page.cpp:51

0x4202e6da: nvs::PageManager::load(nvs::Partition*, unsigned int, unsigned int) at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_pagemanager.cpp:25

0x4202bfbb: nvs::Storage::init(unsigned int, unsigned int) at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_storage.cpp:91

0x4202cfa5: nvs::NVSPartitionManager::init_custom(nvs::Partition*, unsigned int, unsigned int) at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_partition_manager.cpp:92

0x4202d0ae: nvs::NVSPartitionManager::secure_init_partition(char const*, nvs_sec_cfg_t*) at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_partition_manager.cpp:132

0x4202b181: nvs_flash_secure_init_partition at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_api.cpp:177

0x4202b7a6: nvs_flash_init at C:/Users/xxxxxxx/Documents/esp-idf/components/nvs_flash/src/nvs_api.cpp:156

0x42014c01: NvsKsc2_Init at C:/Users/xxxxxxx/Documents/ksc-2n/src/SERVICES/NVS_Wrapper/NvsKsc2.c:47

0x4200a142: initServices() at C:/Users/xxxxxxx/Documents/ksc-2n/src/OS/os_wrapper/cfg/TaskCfg.cpp:81

0x4200a00b: app_main at C:/Users/xxxxxxx/Documents/ksc-2n/main/main.cpp:6

0x420d6de0: main_task at C:/Users/xxxxxxx/Documents/esp-idf/components/freertos/FreeRTOS-Kernel/portable/port_common.c:124 (discriminator 2)

0x40381b21: vPortTaskWrapper at C:/Users/xxxxxxx/Documents/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:141

ELF file SHA256: 2e568e4c6cac14f4

Rebooting...
�ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0x8 (SPI_FAST_FLASH_BOOT)
Saved PC:0x40375b90
0x40375b90: esp_restart_noos at C:/Users/xxxxxxx/Documents/esp-idf/components/esp_system/port/soc/esp32s3/system_internal.c:151 (discriminator 1)

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fcd03e0,len:0x39b0
load:0x403b6000,len:0xbb8
load:0x403b9000,len:0x5184
entry 0x403b6260

Metadata

Metadata

Assignees

Labels

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions